MSBuild has made my life so much easier that it makes me shudder thinking back to the days of NMAKE. With very little effort, I’ve been able to automate so much of my software build and processing that I almost wonder if MSBuild will eventually start writing my code for me as well. Of course, there’s room for improvement and new features but I very much like what we have today.
As a frequent creator of MSBuild custom tasks and hand written project files one thing I have found annoying is trying to debug those files. When the team asked everyone to spend $100 on what features they want, a debugger came out right at the top. While can start playing around with Partho Das’ MSBuild debugger, realistically turning on detailed logging with the /verbose:detailed switch the current best way. For simple projects, that don’t build any .CS/VB/VC/PROJ files, it’s just fine. However, the instant you throw in a .CS/VB/VC/PROJ file into your MSBuild project, the amount of detailed output skyrockets. On one of my projects that uses numerous of my custom tasks and targets to control the overall build from versioning, to building 48 .CSPROJ files, to installation, creates nearly a megabyte of text tracing with /verbosity:detailed. At least 98% of that output is from the .CSPROJ files.
What would be nice is if MSBuild would do detailed logging, but ignore anything other than errors and warnings from a .CS/VB/VC/PROJ. That way I could concentrate on my tasks and targets which are the ones that have the problems and I’m trying to debug. The good news is that it turned out to be a bit easier than I thought to get working.
Obviously, I was going to have to look at writing MSBuild loggers. The problem is that I wanted to mimic the MSBuild output as close as possible to what normally goes to the console, as that’s what we are all used to looking at. What would be ideal is if I could use the actual MSBuild logger that does the console logging, but throw out the parts I didn’t want. With a little quality time spent in Reflector, I was able to get a custom logger that did what I wanted it to do.
Looking at what MSBuild does to create a logger, I ran into the ConsoleLogger class, which is the default logger. It would have probably been easier to just read the documentation on the ConsoleLogger. I guess I like to use Reflector as the ultimate .NET search engine.
My thought was to derive my logger from ConsoleLogger. Whipping up a quick binary, I hooked up all the IEventSource interface notifications to pass through to the base class. I told MSBuild to use my logger instead of the console logger with the /noconsolelogger /logger:test.dll parameters. Immediately I realized that deriving from ConsoleLogger probably not the right approach as the base was processing the events before my code. Looking through the wild code for ConsoleLogger with Reflector, I saw there was no way I was going to remove those events so only mine would be called.-
My next attempt was to create a logger derived directly from INodeLogger and use a private instantiated ConsoleLogger class to do the output. That works, but the output is slightly different from the default logging. Fortunately, the difference was mainly with formatting and that there was no time summary. Somewhere on the internet, I read that only ConsoleLogger only did the performance logging if it was the only logger. Another issue I ran into was that by using my logger, MSBuild no longer let me do multi-processor builds. After reading over the documentation for multi-processor-aware loggers, my eyes glazed over and I gave up. In the end, my goal was to debug my custom project files and strip out all the spew from .CS/VB/VC/PROJ. I’m willing to give up the multi-processor builds for easier debugging.
To use the logger, download it here and build Wintellect.Build.Logging Wintellect.Build.Logging.SLN. To specify the logger to MSBuild, add the following two command line options: /noconsolelogger /logger:<path>Wintellect.Build.Logging.dll. Also included in the download are various test projects I used to ensure the logger was working correctly. Each of the directories as a BuildIt.PS1 file I used automate builds so I could compare the default output with my processed output. The root directory Build.proj file builds demonstrates a bigger build. Note that I’m building some of the error samples so the whole project does not compile. The detailed logging for the project is 342,556 bytes. The same build with Wintellect.Build.Logging applies is 6,380 bytes. That just goes to show that the logging I really cared about was 1.86% of the overall total!
As always, let me know if you find any problems or have additional suggestions for Wintellect.Build.Logging. I hope you find it useful.