OdeToCode IC Logo

Avoiding the Debugger with Better Logging

Sunday, January 19, 2020

There's actually two reasons why I tend to avoid using debuggers. The first reason is a genuine belief that debuggers encourage short term thinking and quick fixes in software. The second reason is the terrible sights and sounds I witness when I launch a debugger like the VS debugger. It is the noise of combustion and heavy gears engaging. My window arrangement shatters and the work space transforms into a day-trading app with real time graphs and event tickers. A modal dialog pops up and tells me a thread was caught inside the reverse flux capacitor and allowed to execute freely with side-effects. I don't know what any of this means or has to do with finding my off-by-one error, which only adds to my sense of fear and confusion.

One way I avoid the debugger is by adding better logging to my software. The best time to think about what you need to log is when the software is misbehaving, and ideally before the software misbehaves in front of strangers. Sometimes the logging becomes verbose.

for (var index = ABBRSTART; index <= ABBREND; index++)
    for (var number = 0; number < NUMABBR; number++)
        var offset = (NUMABBR * (index - 1)) + (WORDSIZE * 2);
        logger.Verbose($"For [{index}][{number}] the offset is {offset}");

        var ppAbbreviation = machine.Memory.WordAt(Header.ABBREVIATIONS);
        logger.Verbose($"For [{index}][{number}] the ppointer is {ppAbbreviation:X}");

        var pAbbreviation = machine.Memory.WordAddressAt(ppAbbreviation + offset);
        logger.Verbose($"For [{index}][{number}] the pointer is {pAbbreviation:X}");

        var location = machine.Memory.SpanAt(pAbbreviation);
        var result = decoder.Decode(location).Text;

        logger.Verbose($"Abbreviation [{index}][{number}] : {result}");

Verbosity works well if you categorize correctly. Again, the best proving ground for a logging strategy is when the software is misbehaving. You can learn what knobs you need to tweak and what categories work well. With Serilog, which I still prefer, you can set the category to match type names in your software, then configure the log messages you want to see using code or configuration files.

public ILogger CreateLogger()
    var logger = new LoggerConfiguration()
        .MinimumLevel.Override(typeof(FrameCollection).FullName, LogEventLevel.Verbose)
        .MinimumLevel.Override(typeof(Machine).FullName, LogEventLevel.Verbose)
        .MinimumLevel.Override(typeof(DebugOutputStream).FullName, LogEventLevel.Verbose)
        .MinimumLevel.Override(typeof(Instruction).FullName, LogEventLevel.Verbose)
        .MinimumLevel.Override(typeof(ZStringDecoder).FullName, LogEventLevel.Verbose)
                      outputTemplate: "{SourceContext:lj}\n{Message:lj}{NewLine}{Exception}")
    return logger;

When is Visual Studio Not an Editor?

To use logs during test runs you need to sink log events into XUnit's ITestOutputHelper. The logs are available from the VS test runner by clicking on an "Open additional output for this result" link.

For one particular integration style test I have, the logs can get lengthy, which leads to an amusing message from VS.

Open an editor

An editor like Notepad? Am I not already in a piece of software that can edit text? It's like having the GPS in a Tesla tell me I'll need to use a 1988 Oldsmobile to reach my destination.