Why must I manually dispose the Serilog Logger (Sumologic sink) when the dispose option is true?

0

I have configured Serilog using (I have attempted this with the dispose option both true and false)

services.AddLogging(
    loggingBuilder =>
    {
        //Create Serilog logger from AppSettings.json properties.
        _logger = new LoggerConfiguration()
            .ReadFrom.Configuration(configuration)
            .CreateLogger();
        loggingBuilder.AddSerilog(_logger, true);
    });

Appsettings configuration

    "Logging": {
        "IncludeScopes": true,
        "LogLevel": {
            "Default": "Debug",
            "System": "Warning",
            "Microsoft": "Warning"
        },
        "Debug": {
            "LogLevel": {
                "Default": "Debug"
            }
        },
        "Console": {
            "LogLevel": {
                "Default": "Information"
            }
        }
    },
    "Serilog": {
        "Using": [
            "Serilog.Sinks.Console",
            "Serilog.Sinks.SumoLogic",
            "Serilog.Formatting.Compact"
        ],
        "MinimumLevel": {
            "Default": "Information",
            "Override": {
                "System": "Warning",
                "Microsoft": "Warning"
            }
        },
        "Filter": [
            {
                "Name": "ByExcluding",
                "Args": {
                    "expression": "RequestPath = '/api/health'"
                }
            },
            {
                "Name": "ByExcluding",
                "Args": {
                    "expression": "RequestPath = '/api/info'"
                }
            }
        ],
        "WriteTo": [
            {
                "Name": "SumoLogic",
                "Args": {
                    "endpointUrl": "todo-setSumoLogEndpointUrl",
                    "sourceName": "sourceName",
                    "sourceCategory": "sourceCategory",
                    "textFormatter": "Serilog.Formatting.Compact.CompactJsonFormatter, Serilog.Formatting.Compact"
                }
            },
            {
                "Name": "Console",
                "Args": {
                    "theme": "Serilog.Sinks.SystemConsole.Themes.AnsiConsoleTheme::Code, Serilog.Sinks.Console",
                    "outputTemplate": "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u3}] {SourceContext} {Message:lj}{NewLine}{Exception}",
                    "restrictedToMinimumLevel": "Debug"
                }
            }
        ],
        "Enrich": [
            "FromLogContext",
            "WithMachineName",
            "WithThreadId"
        ],

I am using the Sumologic sink https://www.nuget.org/packages/Serilog.Sinks.SumoLogic/

I have configured my DbContext to use Serilog as well

private void ConfigureDbContext(IServiceCollection services)
{
    ServiceProvider? provider = services.BuildServiceProvider();
    ILoggerFactory? loggerFactory = provider.GetService<ILoggerFactory>();
    services.AddDbContext<ApiDbContext>(options =>
    {
        string? connectionString = Configuration.GetConnectionString("ApiDatabase");
        // NodaTime allows the use of zoned times.
        options
            .UseNpgsql(connectionString, npgsqlOptions => npgsqlOptions.UseNodaTime())
            // Using snake case avoids the need for quoting tables and columns.
            .UseSnakeCaseNamingConvention();
        if (loggerFactory != null)
        {
            options.UseSerilog(loggerFactory);
        }
        if (!IsDevelopment)
        {
            return;
        }
        options.EnableSensitiveDataLogging()
            .EnableDetailedErrors()
            .LogTo(Console.WriteLine);
    });
}

When running database migrations, I get a fatal exception that causes application startup to fail like:

Npgsql.PostgresException (0x80004005): 23505: duplicate key value violates unique constraint \"pk_pdt_users\"
   at Npgsql.NpgsqlConnector.<ReadMessage>g__ReadMessageLong|194_0(NpgsqlConnector connector, Boolean async, DataRowLoadingMode dataRowLoadingMode, Boolean readingNotifications, Boolean isReadingPrependedMessage)
   at Npgsql.NpgsqlDataReader.NextResult(Boolean async, Boolean isConsuming, CancellationToken cancellationToken)
   at Npgsql.NpgsqlDataReader.NextResult()
   at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior, Boolean async, CancellationToken cancellationToken)
   at Npgsql.NpgsqlCommand.ExecuteReader(CommandBehavior behavior, Boolean async, CancellationToken cancellationToken)
   at Npgsql.NpgsqlCommand.ExecuteNonQuery(Boolean async, CancellationToken cancellationToken)
   at Npgsql.NpgsqlCommand.ExecuteNonQuery()
   at Microsoft.EntityFrameworkCore.Storage.RelationalCommand.ExecuteNonQuery(RelationalCommandParameterObject parameterObject)
   at Microsoft.EntityFrameworkCore.Migrations.MigrationCommand.ExecuteNonQuery(IRelationalConnection connection, IReadOnlyDictionary`2 parameterValues)
   at Microsoft.EntityFrameworkCore.Migrations.Internal.MigrationCommandExecutor.ExecuteNonQuery(IEnumerable`1 migrationCommands, IRelationalConnection connection)
   at Microsoft.EntityFrameworkCore.Migrations.Internal.Migrator.Migrate(String targetMigration)
   at Microsoft.EntityFrameworkCore.RelationalDatabaseFacadeExtensions.Migrate(DatabaseFacade databaseFacade)
   at Precisely.Pdx.Api.Web.Startup.UpdateDatabase(IApplicationBuilder app) in /Users/richardcollette/Documents/code/sdm/pdx_api/Precisely.Pdx.Api/Precisely.Pdx.Api.Web/Startup.cs:line 190
   at Precisely.Pdx.Api.Web.Startup.Configure(IApplicationBuilder app, IWebHostEnvironment env, IApiVersionDescriptionProvider apiVersionDescriptionProvider, ILogger`1 log) in /Users/richardcollette/Documents/code/sdm/pdx_api/Precisely.Pdx.Api/Precisely.Pdx.Api.Web/Startup.cs:line 121

If I do nothing else, the error logged by EF, which contains the failed SQL statement is not logged, nor is the resulting exception logged.

Instead, I must keep the Serilog Logger as a private field, catch the exception, log it and then manually dispose of the Logger.

try
{
    UpdateDatabase(app);
}
catch (Exception ex)
{
    log.LogError(ex, "Error applying migrations.");
    // This is a fatal error so we dispose the logger to ensure that it's messages are written.
    _logger?.Dispose();
    throw;
}

After doing so, the exception is logged as well as the sql error. enter image description here

Why does Serilog and/or the sink not write the logs on its own. Is the provider not disposed in a fatal error scenario?

c#
asp.net-core
.net-core
serilog

1 Answer

1

It's your responsibility to flush the logs before your application ends. See Lifecycle of Loggers.

You do that by calling Log.CloseAndFlush() or by disposing your logger.

public static int Main(string[] args)
{
    ConfigureLogging(); // set up Serilog

    try
    {
        Log.Logger.Information("Custom.API Server is starting.");
        var webHost = BuildWebHost(args);
        webHost.Run();

        Log.Logger.Information("Custom.API Server is starting.");
        return 0;
    }
    catch (Exception ex)
    {
        Log.Fatal(ex, "Host terminated unexpectedly.");
        return 1;
    }
    finally
    {
        Log.CloseAndFlush(); // <##<##<##<##<##<##
    }
}
answered on Stack Overflow Feb 10, 2021 by C. Augusto Proiete

User contributions licensed under CC BY-SA 3.0