Timestamps in msbuild logger

[peli]

It would be great if the default msbuild logger would log timestamp
and elapsed times for each target. With this information, the xslt
transform could be upgraded to display the time spent in each
target... and decide what is slowing the build down.

[Ruben Willems]

Hi


indeed, this would be a good enhancemen :
created an issue about it
http://jira.public.thoughtworks.org/browse/CCNET-1776


with kind regards
Ruben Willems

[Jonathan de Halleux]

We have used this logging in our team to track places in the build that could be speed up.

 

If the XML file contains the elapsed duration formatted as a floating point, it makes the XSLT processing much easier. For instance, the MSBuild details view could show a table of the 10 slowest task in the build on the top of the page.

--
This posting is provided "AS IS" with no warranties, and confers no rights.

[Ruben Willems]

Hi

I updated the msbuild logger that is standard included in CCNet 1.5
it now shows the startime and elapsedtime on each target

if you set the verbosity to detailed (/v:d) you also see the Tasks with these attributes

if you set the verbosity to diagnostics, (/v:diag) you also see these attributes on message level
(do not know if that is usefull)


the code was already present, but the attributes where only set when verbosity was detailed or diagnostic,
I just removed those if statements :-)


Hope this is what you wanted ...

it sure helps to get this information.
Take the Latest build.

with kind regards
Ruben Willems

[Jonathan de Halleux]

Could you add a elapsedSeconds attribute in the output? This would make XSLT transformation much easier (xslt does not understand timestamps out of the box).

 

Also, I've noticed that the logger uses XmlDocument as a backing store. This is ineficient in terms of memory (and performance). Any plans to migrate it to a lean and mean XmlWriter based implementation? (sorry for sounding like I only ask and don't give).

[Ruben Willems]

Hi

Ok, will have a look, adding that seconds should not be hard :-)
Looking into the speedup to.

with kind regards
Ruben Willems

[Ruben Willems]

Hi

the elapsedSeconds are added, so you can tweak the xslt's
the speedup will take more time ;-)

with kind regards
Ruben Willems

[Jonathan de Halleux]

The speedup will require a change in the XML schema. Currently, you emit the elapse time as an attribute of the task/target node. Obvisouly this won't work using an XmlWriter, which is forward only. The way I handled this in my logger was to write a simple result node before closing the outtag

 

   <result time="the time" elapsed="214" />

</target>

 

then it is just a matter of tweaking the xslt to pick it up correctly. XmlWriter will help with speedup and memory consumption (= speedup).