Why doesn't tracing behavior appear to work when added to Autofixture Fixture.Behaviors in an AutoDataAttribute implementation?

Question

When I add a new TracingBehavior to an AutoFixture Fixture instance using

fixture.Behaviors.Add(new TracingBehavior());

I get tracing output in my R# Unit Test Sessions window.

However, when I inherit AutoDataAttribute and add the behavior inside my attribute's constructor like this

I get no tracing output, even though the tests would indicate that the TracingBehavior has been added to the Fixture.Behaviors in both scenarios. Below are two simple tests and the attribute implementation to reproduce.

public class TracingBehaviorTests
{
    [Theory, AutoData]
    public void TracingOutputDisplayedWhenManuallyAddedToFixture(Fixture fixture)
    {
        fixture.Behaviors.Add(new TracingBehavior());
        var actual = fixture.Behaviors.OfType<TracingBehavior>().Any();
        Assert.Equal(true, actual); // Passes
        fixture.Create<string>();   // Tracing output displayed
    }

    [Theory, TracingFixtureConventions]
    public void TracingOutputDisplayedWhenUsingTracingFixtureConventionsAttribute(Fixture fixture)
    {
        var actual = fixture.Behaviors.OfType<TracingBehavior>().Any();
        Assert.Equal(true, actual); // Passes
        fixture.Create<string>();   // No tracing output displayed
    }
}

public class TracingFixtureConventionsAttribute : AutoDataAttribute
{
    public TracingFixtureConventionsAttribute()
        : base(new Fixture())
    {
        this.Fixture.Behaviors.Add(new TracingBehavior());
    }
}

Answer 1

I had to do a little digging to figure out why this is happening.

The reason you're seeing this behaviour is that when you use the default constructor of TracingBehavior, Console.Out is the destination.

When executing a test case, the xUnit.net test runner assigns another TextWriter to Console.Out.

This happens before the code block in the test method is executed, which explains why the first test in the OP displays the trace: when the TracingBehavior instance is created, Console.Out is already the captured TextWriter.

However, in the second test (using the [TracingFixtureConventions] attribute), Console.Out has not yet been replaced when the attribute's constructor runs. So, when this test runs, it actually traces to the original Console.Out, but since there's no console present, it traces into a void.

You can verify that both test cases actually do log by logging to a file instead:

public class TracingBehaviorTests
{
    [Theory, AutoData]
    public void TracingOutputDisplayedWhenManuallyAddedToFixture(Fixture fixture)
    {
        using (var tw = File.AppendText(Path.Combine(Environment.CurrentDirectory, "log.txt")))
        {
            tw.AutoFlush = true;
            fixture.Behaviors.Add(new TracingBehavior(tw));
            var actual = fixture.Behaviors.OfType<TracingBehavior>().Any();
            Assert.Equal(true, actual); // Passes
            fixture.Create<string>();   // Tracing output logged to file
        }
    }

    [Theory, TracingFixtureConventions]
    public void TracingOutputDisplayedWhenUsingTracingFixtureConventionsAttribute(Fixture fixture)
    {
        var actual = fixture.Behaviors.OfType<TracingBehavior>().Any();
        Assert.Equal(true, actual); // Passes
        fixture.Create<string>();   // Tracing output logged to file
    }
}

public class TracingFixtureConventionsAttribute : AutoDataAttribute
{
    public TracingFixtureConventionsAttribute()
        : base(new Fixture())
    {
        var tw = File.AppendText(Path.Combine(Environment.CurrentDirectory, "log.txt"));
        tw.AutoFlush = true;
        this.Fixture.Behaviors.Add(new TracingBehavior(tw));
    }
}

The above 'fix' is rather fragile, because (as written here) the [TracingFixtureConventions] attribute doesn't dispose of tw, so if the test adorned with the [TracingFixtureConventions] attribute runs first, the log file is in use, and the other test will not be able to write to it.

For now, I'll leave it as an exercise to the reader to figure out how to make file logging more robust, if that's something anyone cares about. Personally, I only use AutoFixture tracing to troubleshoot, and always turn it off again once I'm done troubleshooting.