DragoAnt.Serilog.Sinks.InMemory 3.2.1

Serilog.Sinks.InMemory

In-memory sink for Serilog to use for testing with FluentAssertions, AwesomeAssertions or Shouldly support for easy-to-write assertions.

This repository was forked from the original upstream project at serilog-contrib/SerilogSinksInMemory (earlier hosted at sandermvanvliet/SerilogSinksInMemory). It is maintained here as DragoAnt.* NuGet packages while keeping the same Serilog.Sinks.InMemory* namespaces and assembly names as upstream.

Build status

Maintainers

Stable releases and beta/prerelease publishing through GitHub Actions are documented in RELEASING.md.

Public differences from 2.0.0.0

Compared with tag 2.0.0.0, this fork currently differs in the following user-visible ways:

• NuGet package IDs are DragoAnt.Serilog.Sinks.InMemory and DragoAnt.Serilog.Sinks.InMemory.Assertions. Namespaces and assembly names remain Serilog.Sinks.InMemory*.
• Assertion framework discovery and adapter loading are now encapsulated in standalone packages DragoAnt.Assertions and DragoAnt.Assertions.Abstractions.
• Packages now target netstandard2.0 instead of netstandard2.1, widening compatibility for older test projects.
• WriteTo.InMemory(outputTemplate: ...) is no longer part of the public API. Use WriteTo.InMemory() for the default singleton sink, or WriteTo.InMemory(sink, ...) to write into an explicit InMemorySink instance.
• The sink and assertions APIs now support predicate-based filtering via InMemorySink.Snapshot(Func<LogEvent, bool>), HaveMessage(Func<LogEvent, bool>, ...), and NotHaveMessage(Func<LogEvent, bool>, ...).
• InMemorySink now uses a debugger proxy so watch windows show a friendlier view of each log event, including rendered message, template, level, properties, exception, and the original LogEvent.
• Assertion abstractions now expose Subject, and top-level assertion types provide ToAssertion() helpers for building custom assertion extensions in a framework-agnostic way.
• NuGet consumption of the assertions package is more reliable: packaged assertion adapters are exposed transitively, framework detection probes AppContext.BaseDirectory, and AwesomeAssertions is preferred when both it and FluentAssertions could otherwise match.

Usage

To just use the sink, add the DragoAnt.Serilog.Sinks.InMemory NuGet package:

dotnet CLI:

dotnet add package DragoAnt.Serilog.Sinks.InMemory

PowerShell:

Install-Package DragoAnt.Serilog.Sinks.InMemory

But it's better with assertions so you'll also want to add the DragoAnt.Serilog.Sinks.InMemory.Assertions NuGet package:

dotnet CLI:

dotnet add package DragoAnt.Serilog.Sinks.InMemory.Assertions

PowerShell:

Install-Package DragoAnt.Serilog.Sinks.InMemory.Assertions

Using DragoAnt.Assertions directly

DragoAnt.Assertions is the framework-agnostic assertion bridge used by this repository. Use it when you want to write one extension method that works across FluentAssertions, AwesomeAssertions, and Shouldly without branching per framework.

dotnet CLI:

dotnet add package DragoAnt.Assertions
dotnet add package FluentAssertions

PowerShell:

Install-Package DragoAnt.Assertions
Install-Package FluentAssertions

You can swap FluentAssertions with AwesomeAssertions or Shouldly; the same extension code keeps working.

Example

Let's say you have a class with method implementing some complicated business logic:

public class ComplicatedBusinessLogic
{
    private readonly ILogger _logger;

    public ComplicatedBusinessLogic(ILogger logger)
    {
        _logger = logger;
    }

    public string FirstTenCharacters(string input)
    {
        return input.Substring(0, 10);
    }
}

A request came in to log a message with the number of characters in the input. So to test that you can create a mock of ILogger and assert the method to log was called, however mock setups quickly become very messy (true: this is my opinion!) and assertions on mocks have the same problem when you start verifying values of arguments.

So instead let's use Serilog and a dedicated sink for testing:

public class WhenExecutingBusinessLogic
{
    public void GivenInputOfFiveCharacters_MessageIsLogged()
    {
        var logger = new LoggerConfiguration()
            .WriteTo.InMemory()
            .CreateLogger();

        var logic = new ComplicatedBusinessLogic(logger);

        logic.FirstTenCharacters("12345");

        // Use the static Instance property to access the in-memory sink
        InMemorySink.Instance
            .Should()
            .HaveMessage("Input is {count} characters long");
    }
}

The test will now fail with Expected a message to be logged with template \"Input is {count} characters long\" but didn't find any

Now change the implementation to:

public string FirstTenCharacters(string input)
{
    _logger.Information("Input is {count} characters long", input.Length);

    return input.Substring(0, 10);
}

Run the test again and it now passes. But how do we ensure this message is only logged once?

To do that, create a new test like so:

public void GivenInputOfFiveCharacters_MessageIsLoggedOnce()
{
    /* omitted for brevity */

    InMemorySink.Instance
        .Should()
        .HaveMessage("Input is {count} characters long")
        .Appearing().Once();
}

To verify if a message is logged multiple times use Appearing().Times(int numberOfTimes)

So now you'll want to verify that the property count has the expected value. This builds upon the previous test:

public void GivenInputOfFiveCharacters_CountPropertyValueIsFive()
{
    /* omitted for brevity */

    InMemorySink.Instance
        .Should()
        .HaveMessage("Input is {count} characters long")
        .Appearing().Once()
        .WithProperty("count")
        .WithValue(5);
}

Asserting a message appears more than once

Let's say you have a log message in a loop and you want to verify that:

public void GivenLoopWithFiveItems_MessageIsLoggedFiveTimes()
{
    /* omitted for brevity */

    InMemorySink.Instance
        .Should()
        .HaveMessage("Input is {count} characters long")
        .Appearing().Times(5);
}

Asserting a message has a certain level

Apart from a message being logged, you'll also want to verify it is of the right level. You can do that using the WithLevel() assertion:

public void GivenLoopWithFiveItems_MessageIsLoggedFiveTimes()
{
    /* omitted for brevity */

    InMemorySink.Instance
        .Should()
        .HaveMessage("Input is {count} characters long")
        .Appearing().Once()
        .WithLevel(LogEventLevel.Information);
}

This also works for multiple messages:

public void GivenLoopWithFiveItems_MessageIsLoggedFiveTimes()
{
    logger.Warning("Test message");
    logger.Warning("Test message");
    logger.Warning("Test message");

    InMemorySink.Instance
        .Should()
        .HaveMessage("Test message")
        .Appearing().Times(3)
        .WithLevel(LogEventLevel.Information);
}

This will fail with a message: Expected instances of log message "Hello, world!" to have level Information, but found 3 with level Warning

Asserting messages with a pattern

Instead of matching on the exact message you can also match on a certain pattern using the Containing() assertion:

InMemorySink.Instance
   .Should()
   .HaveMessage()
   .Containing("some pattern")
   .Appearing().Once();

which matches on log messages:

• this is some pattern
• some pattern in a message
• this is some pattern in a message

Asserting messages with a predicate

When matching by template or substring is not enough, you can assert using an arbitrary Func<LogEvent, bool> predicate:

InMemorySink.Instance
    .Should()
    .HaveMessage(
        logEvent => logEvent.MessageTemplate.Text.Contains("404"),
        "message containing '404'")
    .Appearing().Once();

The inverse is also available through NotHaveMessage(predicate, description).

Asserting messages have been logged at all (or not!)

When you want to assert that a message has been logged but don't care about what message you can do that with HaveMessage and Appearing:

InMemorySink.Instance
    .Should()
    .HaveMessage()
    .Appearing().Times(3); // Expect three messages to be logged

and of course the inverse is also possible when expecting no messages to be logged:

InMemorySink.Instance
    .Should()
    .NotHaveMessage();

or that a specific message is not be logged

InMemorySink.Instance
    .Should()
    .NotHaveMessage("a specific message");

Asserting properties on messages

When you want to assert that a message has a property you can do that using the WithProperty assertion:

InMemorySink.Instance
    .Should()
    .HaveMessage("Message with {Property}")
    .Appearing().Once()
    .WithProperty("Property");

To then assert that it has a certain value you would use WithValue:

InMemorySink.Instance
    .Should()
    .HaveMessage("Message with {Property}")
    .Appearing().Once()
    .WithProperty("Property")
    .WithValue("property value");

Asserting that a message has multiple properties can be accomplished using the And constraint:

InMemorySink.Instance
    .Should()
    .HaveMessage("Message with {Property1} and {Property2}")
    .Appearing().Once()
    .WithProperty("Property1")
    .WithValue("value 1")
    .And
    .WithProperty("Property2")
    .WithValue("value 2");

When you have a log message that appears a number of times and you want to assert that the value of the log property has the expected values you can do that using the WithValues assertion:

InMemorySink.Instance
    .Should()
    .HaveMessage("Message with {Property1} and {Property2}")
    .Appearing().Times(3)
    .WithProperty("Property1")
    .WithValue("value 1", "value 2", "value 3")

Note: WithValue takes an array of values.

Sometimes you might want to use assertions like BeLessThanOrEqual() or HaveLength() and in those cases WithValue is not very helpful. Instead you can use WhichValue<T>() to access the value of the log property:

InMemorySink.Instance
    .Should()
    .HaveMessage()
    .Appearing().Once()
    .WithProperty("PropertyOne")
    .WhichValue<string>()
    .Should()
    .HaveLength(3);

If the type of the value of the log property does not match the generic type parameter the WhichValue<T> method will throw an exception.

Note: This only works for scalar values. When you pass an object as the property value when logging a message Serilog converts that into a string.

Asserting a property with a destructured object

If you use object destructuring:

var someObject = new { Foo = "bar", Baz = "quux" };
logger.Information("Hello {@SomeObject}", someObject);

and want to assert on properties of the destructured object you can use the HavingADestructuredObject() assertion like so:

InMemorySink.Instance
    .Should()
    .HaveMessage("Hello {@SomeObject}")
    .Appearing().Once()
    .WithProperty("SomeObject")
    .HavingADestructuredObject()
    .WithProperty("Foo")
    .WithValue("bar");

When the property SomeObject doesn't hold a destructured object the assertion will fail with the message: "Expected message "Hello {NotDestructured}" to have a property "NotDestructured" that holds a destructured object but found a scalar value"

Building custom assertion extensions

All assertion abstraction interfaces expose a Subject property. In addition, top-level assertion types implement IAssertionsExtension, so extension authors can call ToAssertion() and reuse framework-aware failure handling.

Framework-independent extension

using System;
using System.Linq;
using DragoAnt.Assertions;
using Serilog.Sinks.InMemory.Assertions;

public static class CustomLogEventAssertions
{
    public static LogEventsAssertions HaveAtLeast(
        this LogEventsAssertions assertions,
        int count,
        string because = "",
        params object[] becauseArgs)
    {
        var extension = assertions.ToAssertion();

        extension.Assert(
            assertions.Subject.Count >= count,
            new FailMessage(
                "Expected at least {0} matching log events, but found {1}.",
                count,
                assertions.Subject.Count),
            because,
            becauseArgs);

        return assertions;
    }
}

Idempotent extension pattern

Keep custom assertions read-only and deterministic:

• do not mutate Subject
• compute result from current state only
• return the same assertion object for chaining

using System;
using System.Linq;
using DragoAnt.Assertions;
using Serilog.Sinks.InMemory.Assertions;

public static class CustomLogEventAssertions
{
    public static LogEventsAssertions HaveUniqueMessageTemplates(
        this LogEventsAssertions assertions,
        string because = "",
        params object[] becauseArgs)
    {
        var templates = assertions.Subject
            .Select(e => e.MessageTemplate.Text)
            .ToArray();

        var uniqueCount = templates
            .Distinct(StringComparer.Ordinal)
            .Count();

        assertions.ToAssertion().Assert(
            uniqueCount == templates.Length,
            new FailMessage(
                "Expected matching log events to have unique templates, but found {0} duplicates.",
                templates.Length - uniqueCount),
            because,
            becauseArgs);

        return assertions;
    }
}

These extensions are framework-idempotent: the same implementation and failure message shape are used no matter whether the runtime framework is FluentAssertions, AwesomeAssertions, or Shouldly.

Clearing log events between tests

Depending on your test framework and test setup you may want to ensure that the log events captured by the InMemorySink are cleared so tests are not interfering with eachother. To enable this, the InMemorySink implements the IDisposable interface. When Dispose() is called the LogEvents collection is cleared.

It will depend on the test framework or your test if you need this feature. With xUnit this feature is not necessary as it isolates each test in its own instance of the test class which means that they all have their own instance of the InMemorySink. MSTest however has a different approach and there you may want to use this feature as follows:

[TestClass]
public class WhenDemonstratingDisposableFeature
{
    private Logger _logger;

    [TestInitialize]
    public void Initialize()
    {
        _logger?.Dispose();

        _logger = new LoggerConfiguration()
            .WriteTo.InMemory()
            .CreateLogger();
    }

    [TestMethod]
    public void GivenAFoo_BarIsBlah()
    {
        _logger.Information("Foo");

        InMemorySink.Instance
            .Should()
            .HaveMessage("Foo");
    }

    [TestMethod]
    public void GivenABar_BazIsQuux()
    {
        _logger.Information("Bar");

        InMemorySink.Instance
            .Should()
            .HaveMessage("Bar");
    }
}

this approach ensures that the GivenABar_BazIsQuux does not see any messages logged in a previous test.

Creating a logger

Loggers are created using a LoggerConfiguration object. A default initiation would be as follows:

var logger = new LoggerConfiguration()
    .WriteTo.InMemory()
    .CreateLogger();

Using an explicit sink instance

By default WriteTo.InMemory() uses InMemorySink.Instance. When you want to isolate a specific sink instance, pass it explicitly:

var sink = new InMemorySink();
var logger = new LoggerConfiguration()
    .WriteTo.InMemory(sink)
    .CreateLogger();

Snapshots

Snapshot() creates a read-only copy of the current events so later writes do not affect the assertion target. You can also filter while taking the snapshot:

var errorsOnly = sink.Snapshot(logEvent => logEvent.Level >= LogEventLevel.Error);

Debugger experience

When inspecting InMemorySink in a debugger, a debugger proxy presents the captured events as an easy-to-read list with rendered message, template, level, properties, exception, and the original LogEvent.

Minimum level

In this example only Information level logs and higher will be written to the InMemorySink.

var logger = new LoggerConfiguration()
    .WriteTo.InMemory(restrictedToMinimumLevel: Events.LogEventLevel.Information)
    .CreateLogger();

Default Level - if no MinimumLevel is specified, then Verbose level events and higher will be processed.

Dynamic levels

If an app needs dynamic level switching, the first step is to create an instance of LoggingLevelSwitch when the logger is being configured:

var levelSwitch = new LoggingLevelSwitch();

This object defaults the current minimum level to Information, so to make logging more restricted, set its minimum level up-front:

levelSwitch.MinimumLevel = LogEventLevel.Warning;

When configuring the logger, provide the switch using MinimumLevel.ControlledBy():

var log = new LoggerConfiguration()
    .MinimumLevel.ControlledBy(levelSwitch)
    .WriteTo.InMemory()
    .CreateLogger();

Now, events written to the logger will be filtered according to the switch’s MinimumLevel property.

To turn the level up or down at runtime, perhaps in response to a command sent over the network, change the property:

levelSwitch.MinimumLevel = LogEventLevel.Verbose;
log.Verbose("This will now be logged");