Search code examples
c#.net-coresequencexunitserilog

Only first logging shows unless forcefully disposing


I'm using vs 2017, writing a netcoreapp2.0 library, and testing it with a UnitTest project (XUnit and NUnit give same results).
I've noticed that unless I'm forcefully Disposing of my Serilog logger, only the first line will end up in Seq.

Here are my 2 classes. The library one:

public class Class1
{
    public static Logger _log;

    public Class1(Logger log)
    {
        _log = log;
        _log.Verbose("Class 1 constructor finished");
    }

    public void LogMessage(string s)
    {
        _log.Debug("Got message: {Message}", s);
    }
}

And the Unit test:

public class UnitTest1
{
    public static Logger _log = new LoggerConfiguration()
                                          .WriteTo.Seq("http://localhost:5341", Serilog.Events.LogEventLevel.Verbose)
                                          .MinimumLevel.Verbose()
                                          .CreateLogger();
    [Fact]
    public void Test1()
    {
        _log.Debug("Test 1 logging");
        var c = new Class1(_log);
        c.LogMessage("Logging from test");

        _log.Information("Test finished");

        _log.Dispose(); // Without this, only "Test 1 logging" is logged.
    }
}

Referenced assemblies (from unit test project):

<PackageReference Include="Microsoft.NET.Test.Sdk" Version="15.3.0-preview-20170628-02" />
<PackageReference Include="serilog" Version="2.5.0" />
<PackageReference Include="serilog.sinks.seq" Version="3.3.3" />
<PackageReference Include="xunit" Version="2.2.0" />
<PackageReference Include="xunit.runner.visualstudio" Version="2.2.0" />

Any suggestions?

(Here's a link to a demo project, open with vs 2017 restore the packages and run the test : demo project )


Solution

  • As per Stephen suggestions, the problem was the life scope of the logger.

    Since I'm logging from a unit test class, I feel like disposing of the logger was wrong, but the solution was to change from using a class variable logger to using the static global logger.
    That allows me to set it up once on test creation, and dispose of it once after all tests run :

    [SetUpFixture]
    public class TestsSetup
    {
        [OneTimeSetUp]
        public void RunBeforeAnyTests()
        {
            Log.Logger = new LoggerConfiguration().Enrich.WithExceptionDetails()
                                                  .WriteTo.Seq("http://localhost:5341")
                                                  .MinimumLevel.Verbose()
                                                  .CreateLogger();
        }
    
        [OneTimeTearDown]
        public void RunAfterAnyTests()
        {
            Log.CloseAndFlush();
        }
    }
    

    The main confusion I had was that the CloseAndFlush exists on the static one, but not on the ILogger you get when creating one with

    Logger _log = new LoggerConfiguration()....
    

    hence why i wasn't able to close and flush my variable one.