Entity Framework Core 3.1 - Log Information About Both Commands and Transactions

Question

I am working on an application that uses .NET Core 3.1 and Entity Framework Core 3.1. I have a MSTest unit test project that tests the data access layer built on EF Core. The database is SQL Server 2019 Express Edition.

appsettings.json


    {
       "EnableSensitiveDataLogging": "False",
       "Logging": {
          "LogLevel": {
             "Default": "Information",
             "System": "Debug",
             "Microsoft": "Debug",
             "Microsoft.EntityFrameworkCore": "Debug"
          }
       }
    }

Creating DbContextOptionsBuilder


       Configuration = new ConfigurationBuilder()
          .AddJsonFile("appsettings.json", false)
          .AddJsonFile("secrets.json", true)
          .Build();

       var loggerFactory = LoggerFactory.Create(configure => {
          configure.AddConsole();
       });

       bool.TryParse(Configuration["EnableSensitiveDataLogging"] ?? "false",
                      out bool enableSensitiveDataLogging);

       Builder = new DbContextOptionsBuilder()
             .UseLoggerFactory(loggerFactory)
             .EnableSensitiveDataLogging(enableSensitiveDataLogging);

When I run the test that verifies creation of a new entity in the database, the test output only shows me information related to commands executed by EF Core. There are no details about the implicit transactions. Below is the output log:


    info: Microsoft.EntityFrameworkCore.Infrastructure[10403]
          Entity Framework Core 3.1.3 initialized 'CustomerDbContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer' with options: None
    info: Microsoft.EntityFrameworkCore.Database.Command[20101]
          Executed DbCommand (42ms) [Parameters=[@p0='?' (DbType = Int32), @p1='?' (Size = 100), @p2='?' (Size = 100), @p3='?' (Size = 100), @p4='?' (Size = 30), @p5='?' (Size = 100), @p6='?' (DbType = DateTimeOffset), @p7='?' (DbType = DateTimeOffset)], CommandType='Text', CommandTimeout='30']
          SET NOCOUNT ON;
          INSERT INTO [customer].[addresses] ([country_id], [line_1], [line_2], [line_3], [zip_postalcode], [county_province], [creation_date], [last_modified_date])
          VALUES (@p0, @p1, @p2, @p3, @p4, @p5, @p6, @p7);
          SELECT [address_id]
          FROM [customer].[addresses]
          WHERE @@ROWCOUNT = 1 AND [address_id] = scope_identity();
    ...

I modified the LoggerFactory to explicitly specify the filters as follows:


    var loggerFactory = LoggerFactory.Create(configure => {
       configure.AddConsole()
       .AddFilter((category, level) => category == DbLoggerCategory.Database.Command.Name && level == LogLevel.Debug)
       .AddFilter((category, level) => category == DbLoggerCategory.Database.Transaction.Name && level == LogLevel.Debug);
    });

This time, when I run the same unit test, I can see the transaction information in the output log but there is no information about commands issued:


    dbug: Microsoft.EntityFrameworkCore.Database.Transaction[20209]
          Beginning transaction with isolation level 'Unspecified'.
    dbug: Microsoft.EntityFrameworkCore.Database.Transaction[20200]
          Began transaction with isolation level 'ReadCommitted'.
    dbug: Microsoft.EntityFrameworkCore.Database.Transaction[20210]
          Committing transaction.
    dbug: Microsoft.EntityFrameworkCore.Database.Transaction[20202]
          Committing transaction.
    dbug: Microsoft.EntityFrameworkCore.Database.Transaction[20204]
          Disposing transaction.

Question - How can I configure the logger factory to show both the transaction and command information?

Ivan Stoev Ivan Stoev · Accepted Answer · 2020-04-27T12:27:37

The configuration you've build has no effect on the logger factory returned by the LoggerFactpry.Create call until you use AddConfigration, e.g.

configure.AddConfiguration(Configuration.GetSection("Logging"));

Configuring the logger factory to show the transaction log explicitly (without configuration files) is like this

configure.AddFilter(DbLoggerCategory.Database.Transaction.Name, LogLevel.Debug);

The same for connection it is like this

configure.AddFilter(DbLoggerCategory.Database.Connection.Name, LogLevel.Information);

but usually is not needed because Information is the default minimum level (that's why you see it with your original code).

Entity Framework Core 3.1 - Log Information About Both Commands and Transactions

1 Answers