Testing the Output of a Logger - xUnit .NET Core 3.1

Question

I'm trying to work out how to test that a message and log level are correct in my Serilog logging library.

I am using the Serilog.Sinks.TextWriter which gives me the output from Serilog as a string and when I print to the console I get these lines:

[16:44:03 INF] hello // actual log
2020-09-08 16:44:03.117 +01:00 [Information] hello // from StringWriter

I have this incomplete method:

[Fact]
public void LogInfo_InfoOutputCorrect()
{
    var logger = new Logger();

    const string message = "Test Info Log Output";
    const string level = "[Information]";

    logger.LogInfo(message); // log info method
    string returnMessage = logger.LogMessages(); // string from StringWriter
}

The message from the second line above I was thinking I could use the Contains string method to see if the message and log level match.

returnMessage.Contains(level) && returnMessage.Contains(message)

But not sure how to do this.

It looks as though you're trying to test the behaviour of the Serilog library, as opposed to any of your own code. Is this what you're trying to do? Or do you have a separate piece of code which uses Serilog which you wish to test? — Khior, Sep 08 '20 at 16:20
Yes sorry, I want to be able to test that whatever my code passes to serilog is indeed correct if that makes sense. — user1574598, Sep 08 '20 at 16:34
You might find https://github.com/MitchBodmer/serilog-sinks-testcorrelator useful - HTH! — Nicholas Blumhardt, Sep 10 '20 at 21:13
Does this answer your question? [Unit Test - How to test a \`void\` method that just inserts a log message (Serilog)](https://stackoverflow.com/questions/52908380/unit-test-how-to-test-a-void-method-that-just-inserts-a-log-message-serilog) — Michael Freidgeim, Aug 28 '22 at 01:25

Khior · Accepted Answer · 2020-09-08T16:43:23.887

Here's a fairly quick and dirty solution for checking Serilog output. Of course you can develop this solution far beyond what I've presented here, but this should get you up and going.

    // The system under test
    public class MyImportantBehaviour
    {
        public void Run(Serilog.ILogger logger)
        {
            logger.Information("My important log message");
        }
    }

    // The test
    public class MyImportantBehaviourTests
    {
        [Fact]
        public void ExampleTest()
        {
            Queue<LogEvent> logEvents = new Queue<LogEvent>();

            Serilog.ILogger logger = new LoggerConfiguration()
                .MinimumLevel.Verbose()
                .WriteTo.InMemorySink(logEvents)
                .CreateLogger();

            new MyImportantBehaviour().Run(logger);

            logEvents.First().Level.Should().Be(LogEventLevel.Information);
            logEvents.First().MessageTemplate.Should().Be("My important log message");
        }
    }

    public sealed class InMemorySink : ILogEventSink
    {
        public Queue<LogEvent> LogEvents { get; }

        public InMemorySink(Queue<LogEvent> logEvents)
        {
            LogEvents = logEvents;
        }

        public void Emit(LogEvent logEvent)
        {
            LogEvents.Enqueue(logEvent);
        }
    }


    public static class InMemorySinkExtensions
    {
        public static LoggerConfiguration InMemorySink(this LoggerSinkConfiguration loggerConfiguration, Queue<LogEvent> logEvents)
        {
            return loggerConfiguration.Sink(new InMemorySink(logEvents));
        }
    }

If you're using the static logger (i.e. Log.Logger) then it becomes a bit more tricky. You can accomplish something similar by using the following, but you will likely run into issues if tests are run on multiple threads. Best to use dependency injection for your logger where you need this kind of testing.

    Log.Logger = new LoggerConfiguration()
                .MinimumLevel.Verbose()
                .WriteTo.InMemorySink(logLines)
                .CreateLogger();

The assertion logic (i.e. `.Should().Be(...)` is from the fluentassertions library, which I very much encourage you to check out if you haven't used anything similar before :) — Khior, Sep 08 '20 at 16:45
Thank you, its certainty a much different approach to what I had in mind. I've actually got something passing a test now using the above code with the `Assert.Contains()` but I will certainly look into your solution. You brought up an interesting point that I didnt understand in the docs - whats the difference between the `static` logger and newing up a logger. What are the advantages and should I be using one within a wrapper class library? — user1574598, Sep 08 '20 at 17:55
The difference is really just in the access pattern; if you're using the static logger then once you've set it up, you can access it from anywhere in your code without having to pass an instance around. This can be very convenient, but it does not allow for inversion of control and tightly couples your code to that specific logging library. Passing an `ILogger` into the constructor makes it much easier to mock and, therefore, test! — Khior, Sep 21 '20 at 08:24

Testing the Output of a Logger - xUnit .NET Core 3.1

1 Answers1

Linked