Tools for capturing EF Core logging

Tools for capturing EF Core logging

EF Core 5 introduced the LogTo method that makes logging in unit tests and demos really easy. I have therefore converted my database option builders (SQLite in-memory, SQL Server and Cosmos DB) to use the LogTo approach.

Example of writing the logs to the xUnit window

Here is a simple example taken from the TestOptionsWithLogTo unit test class in the EfCore.TestSupport library.

public class TestOptionsWithLogTo
{
    private readonly ITestOutputHelper _output;

    public TestOptionsWithLogTo(ITestOutputHelper output) 
    {
        _output = output;
    }

    [Fact]
    public void TestEfCoreLoggingExampleOfOutputToConsole()
    {
        //SETUP
        var options = SqliteInMemory.CreateOptionsWithLogTo<BookContext>
            (_output.WriteLine);
        using var context = new BookContext(options);
    
        //... rest of the unit test left out           
    }
          
}

The LogToOptions features

The LogTo method has LOTS of options, allowing to to filter by

• The LogLevel: for instance, LogLevel.Information
• A series of EF Core's log message names: for instance, new[] { DbLoggerCategory.Database.Command.Name }.
• A series of EF Core's event names: for instance, new[] { CoreEventId.ContextInitialized }.
• Adding your own filter func: The signature is Func<EventId, LogLevel, bool>.
• Change the format of log output: for instance the DefaultWithUtcTime option will add a header containing various information and the time in UTC that the log was created.

NOTE: Read the EF Core docs on filtering which gives you a more detailed information on the filter types.

To handle all of these I created a LogToOptions class where you could set the logTo options. At the same time I changed some of the default settings and added a feature I use a lot. The changes are:

• I changed ehe default LogLevel to Information (I only really find debug logs useful if I am trying to find a bug).
• I turned of the default header because I don’t want a DataTime in a log because that makes comparing logs more difficult. No you only get the log, with no headers.
• Most times I don’t want to see logs of the //SETUP part of the unit test, so I added a bool ShowLog property (defaults to true) to allow you to control when the Action<string> parameter is called.

The following unit test shows how you might use the LogToOptions to control what logs you get. It:

• Controls when logs will be returned via the ShowLog boolean
• Filters the log to only return DbLoggerCategory.Database.Command, that is the command that captures sending commands to the database.

[Fact]
public void TestEfCoreLoggingCheckSqlOutputShowLog()
{
    //SETUP
    var logs = new List<string>();
    var logToOptions = new LogToOptions
    {
        ShowLog = false,
        OnlyShowTheseCategories = new[] 
        {
            DbLoggerCategory.Database.Command.Name
        }
    };
    var options = SqliteInMemory.CreateOptionsWithLogTo<BookContext>
        (log => logs.Add(log), logToOptions);

    using var context = new BookContext(options);
    context.Database.EnsureCreated(); //no logs from these
    context.SeedDatabaseFourBooks();  //no logs from these

    //ATTEMPT 
    logToOptions.ShowLog = true; //Turn on log output
    var book = context.Books
        .Single(x => x.Reviews.Count() > 1); //Get log from this

    //VERIFY
    logs.Count.ShouldEqual(1);
    logs.Single().Should...
}

The LogToOptions class has class has good comments, so suggest you look at that, and the TestOptionsWithLogTo unit test class in the EfCore.TestSupport library.