Attempt at reproducing https://github.com/adams85/filelogger/issues/11

appsettings.json

{
  "Logging": {
    "LogLevel": {
      "Default": "Trace",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information",
      "NHibernate": "Debug"
    },

    //"File": {
    //  "BasePath": "logs",
    //  "FileAccessMode": "KeepOpenAndAutoFlush",
    //  "MaxFileSize": 10485760,
    //  "CounterFormat": "000",
    //  "IncludeScopes": true,
    //  "MaxQueueSize": 1000,
    //  "Files": [
    //    {
    //      "Path": "app-persistence-<counter>.log",
    //      "MinLevel": {
    //        "Default": "None", // we don't want anything in this log which is not listed here explicitly
    //        "NHibernate": "Debug",
    //        "NHibernate.Type": "Information",
    //        "NHibernate.Cfg.XmlHbmBinding": "Warning",
    //        "NHibernate.Cfg.XmlHbmBinding.Binder": "Information",
    //        "Itg.Persistence": "Trace"
    //      }
    //    },
    //    {
    //      "Path": "app-<counter>.log",
    //      "MinLevel": {
    //        "Default": "Debug",
    //        "Microsoft": "Warning",
    //        "Microsoft.AspNetCore.Authentication": "Debug",
    //        "Microsoft.AspNetCore.Authorization": "Debug",
    //        "Microsoft.AspNetCore.Server": "Debug",
    //        "NHibernate": "None",
    //        "Itg.Persistence": "None",
    //        "Itg.Services": "Debug",
    //        "Itg.Services.Shop": "Information",
    //        "Itg.Mailing": "Information"
    //      }
    //    }
    //  ]
    //}

    "File": {
      "BasePath": "logs",
      "FileAccessMode": "KeepOpen",
      "MaxFileSize": 10485760,
      "CounterFormat": "000",
      "IncludeScopes": true,
      "MaxQueueSize": 10000,
      "Files": [
        {
          "Path": "integra-persistence-<counter>.log",
          "MinLevel": {
            "Default": "None",
            "NHibernate": "Information",
            "NHibernate.Type": "Information",
            "NHibernate.Cfg.XmlHbmBinding": "Warning",
            "NHibernate.Cfg.XmlHbmBinding.Binder": "Information",
            "Itg.Persistence": "Trace"
          }
        },
        {
          "Path": "integra-<counter>.log",
          "MinLevel": {
            "Default": "Debug",
            "Microsoft": "Warning",
            "Microsoft.AspNetCore.Authentication": "Debug",
            "Microsoft.AspNetCore.Authorization": "Debug",
            "Microsoft.AspNetCore.Server": "Debug",
            "NHibernate": "None",
            "Itg.Persistence": "None",
            "Itg.Mailing": "Information"
          }
        }
      ]
    }
  }
}

FileLoggerIssue11.csproj

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>netcoreapp3.1</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Karambolo.Extensions.Logging.File" Version="3.1.1" />
    <PackageReference Include="Microsoft.Extensions.Configuration.Json" Version="3.1.3" />
    <PackageReference Include="Microsoft.Extensions.Logging.Console" Version="3.1.3" />
  </ItemGroup>

  <ItemGroup>
    <None Update="appsettings.json">
      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
    </None>
  </ItemGroup>

</Project>

Program.cs

using System;
using System.Diagnostics;
using System.Threading;
using System.Threading.Tasks;
using Itg.Persistence;
using Itg.Persistence.Secondary;
using Karambolo.Extensions.Logging.File;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;
using NHibernate;

namespace FileLoggerIssue11
{
    class Program
    {
        static async Task Main(string[] args)
        {
            var configuration = new ConfigurationBuilder()
                .AddJsonFile("appsettings.json", optional: false, reloadOnChange: false)
                .Build();

            var loggerContext = new FileLoggerContext(default,
                // disable timeout for entries still in queue at shutdown (that is, make sure all entries are written in any circumstances)
                completionTimeout: Timeout.InfiniteTimeSpan);

            var services = new ServiceCollection()
                .AddLogging(builder =>
                {
                    builder.AddConfiguration(configuration.GetSection("Logging"));
                    builder.ClearProviders();
                    // disable console logging as it'd distort our measurements
                    //builder.AddConsole();
                    builder.AddFile(loggerContext, o => o.RootPath = AppContext.BaseDirectory);
                })
                .AddSingleton<SomeNHibernateComponent>()
                .AddSingleton<SomeItgPersistenceComponent>()
                .AddSingleton<FileKeyValueStore>()
                .AddScoped<BackgroundWork>();

            var stopwatch = new Stopwatch();

            await using (var sp = services.BuildServiceProvider())
            {
                // start a background worker which logs occasionally
                var backgroundWork = sp.GetRequiredService<BackgroundWork>();
                var backgroundWorkTask = Task.Run(backgroundWork.RunAsync);

                // simulates a request
                using (var scope = sp.CreateScope())
                {
                    stopwatch.Start();

                    Console.WriteLine("Request started.");

                    var nHibernateComponent = scope.ServiceProvider.GetRequiredService<SomeNHibernateComponent>();
                    // do some heavy logging
                    for (int i = 0; i < 10000; i++)
                    {
                        await Task.Yield(); // kind of a no-op simulating async control flow

                        nHibernateComponent.DoSomeLogging();
                    }

                    Console.WriteLine($"Request ended in {stopwatch.Elapsed}.");
                }

                await backgroundWorkTask;
            }

            Console.WriteLine($"Log queues completed in {stopwatch.Elapsed}.");
        }
    }

    class BackgroundWork
    {
        private readonly SomeNHibernateComponent _someNHibernateComponent;
        private readonly SomeItgPersistenceComponent _someItgPersistenceComponent;
        private readonly FileKeyValueStore _fileKeyValueStore;

        public BackgroundWork(SomeNHibernateComponent someNHibernateComponent, SomeItgPersistenceComponent someItgPersistenceComponent, FileKeyValueStore fileKeyValueStore)
        {
            _someNHibernateComponent = someNHibernateComponent;
            _someItgPersistenceComponent = someItgPersistenceComponent;
            _fileKeyValueStore = fileKeyValueStore;
        }

        public async Task RunAsync()
        {
            await Task.Delay(50);

            _someItgPersistenceComponent.DoSomeLogging();

            await Task.Delay(100);

            _fileKeyValueStore.DoSomeLogging();

            await Task.Delay(50);

            _someItgPersistenceComponent.DoSomeLogging();
        }
    }
}

namespace NHibernate
{
    public class SomeNHibernateComponent
    {
        private readonly ILogger<SomeNHibernateComponent> _logger;

        public SomeNHibernateComponent(ILogger<SomeNHibernateComponent> logger)
        {
            _logger = logger;
        }

        public void DoSomeLogging() => _logger.LogInformation("This is an info message from {TYPE}.", typeof(SomeNHibernateComponent));
    }
}

namespace Itg.Persistence
{
    public class SomeItgPersistenceComponent
    {
        private readonly ILogger<SomeItgPersistenceComponent> _logger;

        public SomeItgPersistenceComponent(ILogger<SomeItgPersistenceComponent> logger)
        {
            _logger = logger;
        }

        public void DoSomeLogging() => _logger.LogTrace("This is a trace message from {TYPE}.", typeof(SomeItgPersistenceComponent));
    }

    namespace Secondary
    {
        public class FileKeyValueStore
        {
            private readonly ILogger<FileKeyValueStore> _logger;

            public FileKeyValueStore(ILogger<FileKeyValueStore> logger)
            {
                _logger = logger;
            }

            public void DoSomeLogging() => _logger.LogCritical(new EventId(0, "LoadFailed"), "This is a critical message from {TYPE}.", typeof(FileKeyValueStore));
        }
    }
}