Can't force Serilog.Sinks.File wrapped in Serilog.Sinks.Async to work in two-stage initialization approach

Question

Serilog doesn't log to the File sink wrapped in Async sink when using two-step initialization with appSettings configuration. I'm using the following Serilog NuGet packages:

Serilog - 2.10.0
Serilog.Settings.Configuration - 3.1.0
Serilog.AspNetCore - 4.1.0
Serilog.Sinks.Console - 4.0.0
Serilog.Sinks.File - 5.0.0
Serilog.Sinks.Async - 1.5.0
Serilog.Enrichers.Environment - 2.1.3
Serilog.Enrichers.Thread - 3.1.0

I want to use appSettings.json configuration with two-stage initialization. Entry point to my app below:

using Microsoft.AspNetCore.Hosting;
using Microsoft.Extensions.Hosting;
using Serilog;
using Serilog.Events;
using System;

namespace FooApi
{
    public class Program
    {
        public static int Main(string[] args)
        {
            Log.Logger = new LoggerConfiguration()
                .MinimumLevel.Information()
                .MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Warning)
                .MinimumLevel.Override("Microsoft.Hosting.Lifetime", LogEventLevel.Information)
                .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
                .Enrich.FromLogContext()
                .Enrich.WithMachineName()
                .Enrich.WithThreadId()
                .WriteTo.Console(
                    outputTemplate: "[{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} {Level:u3}] {Message:lj} <s:{SourceContext}>{NewLine}{Properties:j}{NewLine}{Exception}"
                )
                .WriteTo.Async(a => a.File(
                    outputTemplate: "[{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} {Level:u3}] {Message:lj} <s:{SourceContext}>{NewLine}{Properties:j}{NewLine}{Exception}",
                    path: "logs/log-.txt",
                    rollingInterval: RollingInterval.Day
                )).CreateBootstrapLogger();

            try
            {
                Log.Information("Starting up the host");
                CreateHostBuilder(args).Build().Run();
                return 0;
            }
            catch (Exception ex)
            {
                Log.Fatal(ex, "Host start-up failed");
                return 1;
            }
            finally
            {
                Log.CloseAndFlush();
            }
        }

        public static IHostBuilder CreateHostBuilder(string[] args) =>
            Host.CreateDefaultBuilder(args)
                .UseSerilog((context, services, configuration) =>
                {
                    configuration
                        .ReadFrom.Configuration(context.Configuration)
                        .ReadFrom.Services(services);
                })
                .ConfigureWebHostDefaults(webBuilder =>
                {
                    webBuilder.UseStartup<Startup>();
                });
    }
}

and my appSettings.json (I don't have .Development and .Release versions yet) is:

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Information",
      "Override": {
        "Microsoft.AspNetCore": "Warning",
        "Microsoft.Hosting.Lifetime": "Information",
        "Microsoft": "Warning"
      }
    },
    "WriteTo": [
      {
        "Name": "Async",
        "Args": {
          "configure": [
            {
              "Name": "File",
              "Args": {
                "path": "logs/log-.txt",
                "rollingInterval": "Day",
                "outputTemplate": "[{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} {Level:u3}] {Message:lj} <s:{SourceContext}>{NewLine}{Properties:j}{NewLine}{Exception}"
              }
            }
          ]
        }
      },
      {
        "Name": "Console",
        "Args": {
          "outputTemplate": "[{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} {Level:u3}] {Message:lj} <s:{SourceContext}>{NewLine}{Properties:j}{NewLine}{Exception}",
          "theme": "Serilog.Sinks.SystemConsole.Themes.AnsiConsoleTheme::Code, Serilog.Sinks.Console"
        }
      }
    ],
    "Enrich": [ "WithMachineName", "WithThreadId", "FromLogContext" ]
  },
  "AllowedHosts": "*"
}

With this configuration even after bombarding the API with 100 000 requests the log file shows only the message from initial bootstrap:

[2021-07-13 18:00:04.642 +02:00 INF] Starting up the host <s:>
{"MachineName":"FooMachine","ThreadId":1}

While the console shows (shortened for brevity):

[2021-07-13 18:00:04.642 +02:00 INF] Starting up the host <s:>
{"MachineName": "FooMachine", "ThreadId": 1}
[2021-07-13 18:00:07.059 +02:00 INF] Now listening on: https://localhost:5001 <s:Microsoft.Hosting.Lifetime>
{"MachineName": "FooMachine", "ThreadId": 1}
[2021-07-13 18:00:07.065 +02:00 INF] Now listening on: http://localhost:5000 <s:Microsoft.Hosting.Lifetime>
{"MachineName": "FooMachine", "ThreadId": 1}
[2021-07-13 18:00:07.065 +02:00 INF] Application started. Press Ctrl+C to shut down. <s:Microsoft.Hosting.Lifetime>
{"MachineName": "FooMachine", "ThreadId": 1}
[2021-07-13 18:00:07.065 +02:00 INF] Hosting environment: Development <s:Microsoft.Hosting.Lifetime>
{"MachineName": "FooMachine", "ThreadId": 1}
[2021-07-13 18:00:07.066 +02:00 INF] Content root path: C:\Rules.Api <s:Microsoft.Hosting.Lifetime>
{"MachineName": "FooMachine", "ThreadId": 1}
[2021-07-13 18:00:08.770 +02:00 INF] HTTP GET / responded 200 in 80.4108 ms <s:Serilog.AspNetCore.RequestLoggingMiddleware>
{"MachineName": "FooMachine", "ThreadId": 11, "RequestId": "0HMA62T4HESK3:00000001", "ConnectionId": "0HMA62T4HESK3"}
[2021-07-13 18:00:10.951 +02:00 INF] HTTP GET / responded 200 in 0.4243 ms <s:Serilog.AspNetCore.RequestLoggingMiddleware>
{"MachineName": "FooMachine", "ThreadId": 17, "RequestId": "0HMA62T4HESK3:00000003", "ConnectionId": "0HMA62T4HESK3"}
[2021-07-13 18:00:11.366 +02:00 INF] HTTP GET / responded 200 in 0.1562 ms <s:Serilog.AspNetCore.RequestLoggingMiddleware>
{"MachineName": "FooMachine", "ThreadId": 8, "RequestId": "0HMA62T4HESK3:00000005", "ConnectionId": "0HMA62T4HESK3"}
[2021-07-13 18:00:15.385 +02:00 INF] HTTP GET /call responded 200 in 1814.5944 ms <s:Serilog.AspNetCore.RequestLoggingMiddleware>
{"MachineName": "FooMachine", "ThreadId": 6, "RequestId": "0HMA62T4HESK3:00000007", "ConnectionId": "0HMA62T4HESK3"}

I'm unable to force Serilog to log messages to file after bootstrapping, console works just fine.

Answer 1

It turns out that with two-step initialization BootstrapLogger probably doesn't dispose its handle to the file and when the actual logger get instantiated it's not able to access the file. I ended up using only console sink in the first stage and adding file sink in the second step only.