Console target logging does not work for methods called within NUnit test case source provider-CodePudding

I've spent several hours debugging the issue when log messages are not shown in console output from the class method, which is called via NUnit TestCaseSource.

So I have a class, where I perform logging for debugging purposes.

public class TestHelper
{
    private readonly Logger logger;

    public TestHelper()
    {
        logger = LogManager.GetCurrentClassLogger();
    }

    public IEnumerable<int> GetTestData()
    {
        List<int> testData = new();

        for (var i = 0; i < 10; i  )
        {
            logger.Info("This message is ignored when is called from NUnit test data provider {i}", i);
            testData.Add(i);
        }

        return testData;
    }
}

I have a test fixture:

public class DemoTestFixture
{
    private static readonly ClassWithLoggingInside ClassWithLoggingInside = new();

    private static readonly TestHelper TestHelper = new();

    private readonly Logger logger = LogManager.GetCurrentClassLogger();

    [Test]
    [TestCaseSource(nameof(GetTestData))]
    public void LoggingFromTestDataSourceIsIgnored(int i)
    {
        Assert.DoesNotThrow(() => ClassWithLoggingInside.Log());
        logger.Debug("Message from test fixture {i}", i);
    }

    [Test]
    public void LoggingIsShown()
    {
        Assert.DoesNotThrow(() => TestHelper.GetTestData());
    }

    private static IEnumerable<int> GetTestData()
    {
        IEnumerable<int> testData = TestHelper.GetTestData();

        foreach (int i in testData) yield return i;
    }
}

And when the TestHelper.GetTestData() is called from the parameterized test - console output from the method is NOT shown, however, the messages are logged into the file. When the method is called not as a part of the test data provider - the messages are perfectly logged into the console target.

I'm using latest NLog logger, .NET5, latest NUnit. Tried the following with log4net logger - same result. Tests were run using Resharper/dotnet test command.

I suspect that the issue lies somewhere in the static initialization, but can't understand why file target logging works fine and there are problems with console output. Do you have any explanation?

The demo project can be found here.

CodePudding user response：

The answer is relatively simple but probably not helpful to you. :-(

The reason any logging you do do the console appears in the NUnit output is that NUnit captures console output while it is running tests.

However, execution of your test case source doesn't take place while NUnit is running the tests, but while it is discovering tests. Discovery happens ages (in computer time) before it ever begins test execution.

I suspect that this is made more confusing because we allow you to place the data source in the same class as the tests themselves, although it may also be in a separate class. Nevertheless, the execution of that static method is not part of running the test. In fact, it's only after that method is run that NUnit even knows how many tests there are.

If you need to your logged output to be captured and displayed by NUnit, it must be done in the test method itself or in one of the setup or teardown methods.