Listen Up!

I recently wrapped up TeamCity integration for the Fixie test framework. Today we’ll cover the feature itself. Next time, we’ll see how this feature drove a number of other improvements throughout the project.

##teamcity Messaging

TeamCity captures all console output during a build, mainly so that it can echo that output back to the user under the “Build Log” tab. While capturing the output, though, TeamCity also looks for any line of output that looks like this:

##teamcity[messageName key='value' otherKey='otherValue']

Like an XML tag, these specially-formatted lines have a name and potentially-many key/value pairs. They differ from XML, though, to avoid ambiguity. Some part of your build script may just happen to write some XML to the console, and we wouldn’t want TeamCity to mistakenly think we want it to treat that markup as special. By looking for this ##teamcity prefix, it’s easy to be clear when we do want TeamCity to react to our output.

When you want to tell TeamCity something during the execution of your build, your build process should output these messages. There are many message types available, but today we’re only concerned with the messages used by test runners. A typical sequence may look like this:

##teamcity[testStarted name='CalculatorTests.ShouldAdd']
##teamcity[testStdOut name='CalculatorTests.ShouldAdd' out='2+2 should equal 4']
##teamcity[testFinished name='CalculatorTests.ShouldAdd' duration='15']

##teamcity[testStarted name='CalculatorTests.ShouldSubtract']
##teamcity[testStdOut name='CalculatorTests.ShouldSubtract' out='4-2 should equal 2']
##teamcity[testFailed name='CalculatorTests.ShouldSubtract' details='Assert.AreEqual() Failure|r|nExpected: 2|r|nActual: 123|r|n at CalculatorTests.ShouldSubtract() in c:\path\to\CalculatorTests.cs:Line 38']
##teamcity[testFinished name='CalculatorTests.ShouldAdd' duration='15']

Here we have a passing test and a failing test. Both tests happen to write a little bit to the console themselves, called out by the “testStdOut” messages. Both tests have a “testStart” and “testFinished” message. The second test fails, so it also has a “testFailed” message with the complete stack trace. TeamCity now has all the information it needs to display the test results.

Note that TeamCity has its own rules about how special characters should be escaped. For instance, the Windows line ending marker (“\r\n”) needs to appear as “|r|n”, and slashes in file paths don’t need to be escaped.

Implementation Goals

My goals with the implementation were to:

  1. Decouple knowledge of output formatting from the test runner logic.
  2. Cleanly bottle up the ##teamcity message format and string escaping rules, so that writing each message would feel as simple as using String.Format(...).
  3. Automatically detect whether TeamCity kicked off the test run, switching the output style accordingly.

Decoupling Formatting from the Test Runner

We’ve got at least two output formats: regular console output and TeamCity-style output. It’s likely that Fixie will need to deal with other output formats, such as the XML format other CI tools expect from NUnit. I’d hate for the test runner logic to get all mixed up with output format details, and I’d like it to be easy to swap in other formats later, so I have a “Listener” abstraction:

public interface Listener
{
    void AssemblyStarted(Assembly assembly);
    void CasePassed(PassResult result);
    void CaseFailed(FailResult result);
    void AssemblyCompleted(Assembly assembly, AssemblyResult result);
}

The two main implementations are the regular ConsoleListener and the TeamCityListener, and both are fairly small. The test runner calls each Listener method at key moments of the run, but doesn’t care about what happens as a result.

Why “Listener” and not “Formatter”? I’ve actually got another implementation, one for integrating with TestDriven.NET, and its implementation has nothing to do with formatting output. My TestDrivenListener’s job is to echo each of the test runner’s events over to TestDriven.NET’s own similar interface. TestDriven.NET then cares about output formatting all on its own. Therefore, the abstraction really is just about listening to key events; only some implementations will react by formatting output.

The other test frameworks I’ve inspected have similar “listener” interfaces. If there’s a better pattern to follow, though, I’d like to hear about it. It feels a little weird to have an interface where some implementations end up leaving methods completely empty, but the number of methods on the interface is small enough so far that it doesn’t hurt.

Encapsulating ##teamcity Formatting

In TeamCityListener, the Listener methods focus on the specific message and key/value pairs applicable in each situation, deferring to a couple private helper methods:

static void Message(string format, params string[] args)
{
    var encodedArgs = args.Select(Encode).Cast<object>().ToArray();
    Console.WriteLine("##teamcity["+format+"]", encodedArgs);
}

static string Encode(string value)
{
    var builder = new StringBuilder();
    
    foreach (var ch in value)
    {
        switch (ch)
        {
            case '|': builder.Append("||"); break;
            case '\'': builder.Append("|'"); break;
            case '[': builder.Append("|["); break;
            case ']': builder.Append("|]"); break;
            case '\n': builder.Append("|n"); break; // Line Feed
            case '\r': builder.Append("|r"); break; // Carriage Return
            case '\u0085': builder.Append("|x"); break;  // Next Line
            case '\u2028': builder.Append("|l"); break;  // Line Separator
            case '\u2029': builder.Append("|p"); break;  // Paragraph Separator
            default: builder.Append(ch); break;
        }
    }

    return builder.ToString();
}

The public methods can use the Message(…) method as easily as String.Format(…) without being concerned about special characters.

Detecting TeamCity

When running under TeamCity, we want to replace the normal ConsoleListener with our TeamCityListener. Thankfully, it’s as simple as checking for the existence of a special environment variable, which TeamCity sets for the duration of the build:

static Listener CreateListener()
{
    var runningUnderTeamCity = Environment.GetEnvironmentVariable("TEAMCITY_PROJECT_NAME") != null;

    if (runningUnderTeamCity)
        return new TeamCityListener();

    return new ConsoleListener();
}

Feature-Driven Development

This feature motivated several design decisions. As we’ve seen, it motivated the Listener abstraction, which immediately proved useful for TestDriven.NET integration as well. Additionally, working on this feature forced me to discover new requirements and to avoid a pretty gnarly bug. We’ll cover those other improvements in my next post.