Hi.
I have a few
questions and thoughts about the XmlLogger facility in NAnt. I'm currently been
using 11-15 nightly
but basically as
long as I've used the XmlLogger to provide data for CCNet there have been all
kinds of problems
with this logging.
As 0.85 seem to draw closer I thought I'd better brought this up before the
release rather then
after.
These are the main
problems:
1. None-functional
XML structure.
This is only
indirectly getting me into trouble as other tools relying on the Nant XML file
can not figure out what's
failing and what's
not due to the information structure (or so I've been told). I wonder what
lovely things CCNet and
other teams could do
if this worked.
2. Log file
size.
I have around 2 MB
large logs after each build. Due to item 1 above developers do often not get to
know what went wrong
from the CCNet so
they have to look at the raw log using i.e. IE (please note the rime). Over a
100 MBit connection
this takes around
15-30 seconds depending on the computer. But lots of our devs (several hundreds)
are using this
over a 512k line. It
takes ages to load the log file for them and it's also a very slow process to
find the relevant information
at
times.
3.
Verbosity
Most of the 2 MB log
file consists of spam. Empty tags denoting a task running. Worthless INFO and
DEBUG style entries.
Let me take some
examples by giving you a walkthrough of my builds.
My main build script
begins with a clean task to remove the old build artifacts. Here is the
snipplet:
<foreach item="Folder"
property="foldername">
<in>
<items>
<include name='client\**\bin'/>
<include name='client\**\obj'/>
</items>
</in>
<do>
<delete dir='${foldername}' />
</do>
</foreach>
<in>
<items>
<include name='client\**\bin'/>
<include name='client\**\obj'/>
</items>
</in>
<do>
<delete dir='${foldername}' />
</do>
</foreach>
And the log it
procuces.
<target
name="clean">
<task name="foreach">
<task name="">
<task name="delete">
<message level="Info"><![CDATA[Deleting directory 'C:\CodeModules\Test\Montgomery\modules\fndadm\client\EventAdministration\bin'.]]></message>
</task>
</task>
<task name="">
<task name="delete">
<message level="Info"><![CDATA[Deleting directory 'C:\CodeModules\Test\Montgomery\modules\fndadm\client\EventAdministration\obj'.]]></message>
</task>
</task>
....
<task name="foreach">
<task name="">
<task name="delete">
<message level="Info"><![CDATA[Deleting directory 'C:\CodeModules\Test\Montgomery\modules\fndadm\client\EventAdministration\bin'.]]></message>
</task>
</task>
<task name="">
<task name="delete">
<message level="Info"><![CDATA[Deleting directory 'C:\CodeModules\Test\Montgomery\modules\fndadm\client\EventAdministration\obj'.]]></message>
</task>
</task>
....
All of those log
entries sums up to quite a few. But what for? The only need I can see is if the
task failed, but it's not.
A programmer would
probably like to see that his delete task is finding it's target and that the
code gets ran, but as
a end user of nant
it becomes an annoyance to have to scroll through.
Next my build
fetches the latest code from cvs. This time I'm actually interested in what
comes out as that will eventually
get transformed by
CCNet into a build mail and a web page. Here's the snipplet:
<target
name="cvsup" depends="init">
<exec program="${cvsprog}" commandline="-q ${cvscompress} -d${cvsroot} update -d -P" />
</target>
<exec program="${cvsprog}" commandline="-q ${cvscompress} -d${cvsroot} update -d -P" />
</target>
When this task is
logged normal information from CVS is logged as warnings:
<message
level="Info"><![CDATA[U
Montgomery/modules/fndadm/client/ManageUsers/UserRolePicker.resx]]></message>
<message level="Warning"><![CDATA[cvs update: Montgomery/modules/fndbas/model/ImplementationModel/EntityPackages/entitypackage_ArtifactCache.xml is no longer in the repository]]></message>
<message level="Warning"><![CDATA[cvs update: Montgomery/modules/fndbas/model/ImplementationModel/EntityPackages/entitypackage_ArtifactCache.xml is no longer in the repository]]></message>
CCNet thinking it
better alert me will transform this into the Warning section of the email and
webpage. But it's an informal message.
Now it's time to do
the actual compile. I'm using the <solution> task:
<solution
configuration="Debug" solutionfile="${filename}"/>
This is the log
result for one of the project (the solution contains around 30 of
them):
<message level="Info"><![CDATA[Building 'Ifs.Fnd.Explorer.Interfaces'
[Debug]
...]]></message>
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
<task name="copy" />
This then continues
with the rest of the 70 or so solutions we have. I can understand that the
solution task needs to copy
references
local, but do the log really need to have each and every copy logged without any
info in it? To me a failure to
copy is quite
enough.
If the project contains a resx file (or several) the
resgen task logs each compile:
<task
name="resgen">
<message level="Info"><![CDATA[Read in 0 resources from 'C:\CodeModules\Test\Montgomery\modules\fndwin\framework\Controls\Ifs.Fnd.Windows.Forms.CommonControls\FndTreeView.resx']]></message>
<message level="Info"><![CDATA[Writing resource file... Done.]]></message>
<task name="delete" />
</task>
<message level="Info"><![CDATA[Read in 0 resources from 'C:\CodeModules\Test\Montgomery\modules\fndwin\framework\Controls\Ifs.Fnd.Windows.Forms.CommonControls\FndTreeView.resx']]></message>
<message level="Info"><![CDATA[Writing resource file... Done.]]></message>
<task name="delete" />
</task>
I don't see
any usage for any of this information. Once again it seems to me it's giving a
programmer good debug info but a
builder is
having a hard time sorting out the important stuff.
I'm estimating 1/3 of the file is filled with the
debug info from the solution task.
Next after the
build is complete I run FxCop. In order to do that no matter what machine I'm
reading the registry to find the key.
This snipplet
does it:
<readregistry
property="fxcop.path" key="Software\Microsoft\FxCop\InstallRoot"
hive="CurrentUser" failonerror="false"/>
Note the
failonerror="false". This is what ends up in the log when the key can not be
found (normal thing as it can be installed as Me or for
All).
<task
name="readregistry">
<message level="Error"><![CDATA[Registry Path Not Found! - key='Software\Microsoft\FxCop\';hive='Microsoft.Win32.RegistryHive[]';]]></message>
</task>
<message level="Error"><![CDATA[Registry Path Not Found! - key='Software\Microsoft\FxCop\';hive='Microsoft.Win32.RegistryHive[]';]]></message>
</task>
This needless
to say also ends up in the Error section of CCNet build mails/web
page.
Next FxCop
encounters one of our projects that hasn't got a reference set up correctly.
This is what the Exec task ends up logging:
....
<message level="Info"><![CDATA[WARNING: the following missing
references were
detected.]]></message>
<message level="Info"><![CDATA[Analysis might be compromised. Use the '/directory' switch.]]></message>
<message level="Info"><![CDATA[to specify additional assembly reference search paths.]]></message>
<message level="Info"><![CDATA[* Microsoft.Vbe.Interop Version=10.0.4504.0, used by:Microsoft.Office.Interop.Word]]></message>
<message level="Error"><![CDATA[C:\CodeModules\Test\Montgomery\modules\fndwin\packages.build(119,6):
External Program Failed: C:\Program Files\Microsoft FxCop 1.312\FxCopCmd.exe (return code was 512)]]></message>
<message level="Info"><![CDATA[Analysis might be compromised. Use the '/directory' switch.]]></message>
<message level="Info"><![CDATA[to specify additional assembly reference search paths.]]></message>
<message level="Info"><![CDATA[* Microsoft.Vbe.Interop Version=10.0.4504.0, used by:Microsoft.Office.Interop.Word]]></message>
<message level="Error"><![CDATA[C:\CodeModules\Test\Montgomery\modules\fndwin\packages.build(119,6):
External Program Failed: C:\Program Files\Microsoft FxCop 1.312\FxCopCmd.exe (return code was 512)]]></message>
I'm aware of
this problem but there isn't much I can do about it at this time. It will still
analys the rest of the code so I wan't it to run.
I figure the
only sane thing to do is setting failonerror="false". This gives the same
problem as above. Another Error in CCNet.
Is there
anything that can be done to improve the situation before the release? I think
that a lot of people would appretiate
that a lot.
With the very high quality 0.85 has a good chance of sustaining I find it very
likely lots of people will not run as much
on nightlys as
they have. And with a release cycle of around a year it seems shame that the
logging isn't in a better shape then
it is
now.
Am I way off
here?
/Nicke
