NLog 不会在进程退出时刷新所有日志条目

Question

在此线程中 - Should NLog flush all queued messages in the AsyncTargetWrapper when Flush() is called? - I am reading that „LogManager sets the config to null on domain unload or process exit“ (see the Edit section in the 1st answer). In my understanding, this should cause all the pending log entries be written to registered targets. However, after testing with FileTarget wrapped with AsyncTargetWrapper, this does not hold true. I have created a minimal repro on GitHub - https://github.com/PaloMraz/NLogMultiProcessTargetsSample，其工作方式如下：

LogLib 是一个 .netstandard2.0 库引用 NLog 4.6.8 NuGet 包并公开一个 CompositeLogger class 以编程方式配置 NLog 目标：

public class CompositeLogger
{
  private readonly ILogger _logger;

  public CompositeLogger(string logFilePath)
  {
    var fileTarget = new FileTarget("file")
    {
      FileName = logFilePath,
      AutoFlush = true
    };
    var asyncTargetWrapper = new AsyncTargetWrapper("async", fileTarget)
    {
      OverflowAction = AsyncTargetWrapperOverflowAction.Discard
    };

    var config = new LoggingConfiguration();
    config.AddTarget(asyncTargetWrapper);
    config.AddRuleForAllLevels(asyncTargetWrapper);
    LogManager.Configuration = config;

    this._logger = LogManager.GetLogger("Default");
  }

  public void Log(string message) => this._logger.Trace(message);
}

LogConsoleRunner 是一个 .NET Framework 4.8 控制台应用程序，它使用 LogLib.CompositeLogger 将指定数量的日志消息写入文件（指定为命令行参数），写入之间有很短的延迟：

public static class Program
{
  public const int LogWritesCount = 10;
  public static readonly TimeSpan DelayBetweenLogWrites = TimeSpan.FromMilliseconds(25);

  static async Task Main(string[] args)
  {
    string logFilePath = args.FirstOrDefault();
    if (string.IsNullOrWhiteSpace(logFilePath))
    {
      throw new InvalidOperationException("Must specify logging file path as an argument.");
    }

    logFilePath = Path.GetFullPath(logFilePath);
    Process currentProcess = Process.GetCurrentProcess();
    var logger = new CompositeLogger(logFilePath);
    for(int i = 0; i < LogWritesCount; i++)
    {
      logger.Log($"Message from {currentProcess.ProcessName}#{currentProcess.Id} at {DateTimeOffset.Now:O}");
      await Task.Delay(DelayBetweenLogWrites);
    }
  }
}

最后，LogTest 是一个 XUnit 测试程序集，其中一个测试启动十个 LogConsoleRunner 实例写入同一个日志文件：

[Fact]
public async Task LaunchMultipleRunners()
{
  string logFilePath = Path.GetTempFileName();
  using var ensureLogFileDisposed = new Nito.Disposables.AnonymousDisposable(() => File.Delete(logFilePath));

  string logConsoleRunnerAppExePath = Path.GetFullPath(
    Path.Combine(
      Path.GetDirectoryName(this.GetType().Assembly.Location),
      @"..\..\..\..\LogConsoleRunner\bin\Debug\LogConsoleRunner.exe"));      
  var startInfo = new ProcessStartInfo(logConsoleRunnerAppExePath)
  {
    Arguments = logFilePath,
    UseShellExecute = false
  };
  const int LaunchProcessCount = 10;
  Process[] processes = Enumerable
    .Range(0, LaunchProcessCount)
    .Select(i => Process.Start(startInfo))
    .ToArray();
  while (!processes.All(p => p.HasExited))
  {
    await Task.Delay(LogConsoleRunner.Program.DelayBetweenLogWrites);
  }

  string[] lines = File.ReadAllLines(logFilePath);
  Assert.Equal(LaunchProcessCount * LogConsoleRunner.Program.LogWritesCount, lines.Length);
}

最后一行的Assert.Equal总是失败，因为目标文件写入的行数总是少于预期的计数，即100。在我的机器上，它随着每个运行之间的变化而变化96 – 99，但它从未包含全部 100 行。

我的问题：我应该如何配置NLog以确保在所有进程退出后，所有挂起的日志条目都写入目标日志文件？

Answer 1

直接打电话LogManager.Shutdown() 在你的 Main 结束时。它将刷新所有未决的日志事件。 Read more.

旁注：如果您在刷新后需要 NLog，那么您可以使用 LogManager.Flush() 而不是关闭。

Answer 2

查看了您的示例代码，您有多个进程写入同一个文件名。

认为您是性能和正确性之间妥协的受害者。

当多个进程同时写入同一个文件时，需要一些锁定来协调。默认情况下，NLog 使用最兼容的模式 (KeepFileOpen=false)，这是来自操作系统的文件锁（适用于大多数平台）。

来自操作系统的文件锁定是不公平的，并且当超过 2 个进程写入同一文件时无法扩展。当一个进程试图打开另一个进程当前正在使用的文件时，将抛出异常。

NLog 尝试通过重试错误 (concurrentWriteAttempts=10) 以及随机化重试前等待的时间来处理这些异常。这适用于 2 个进程，但是当您开始增加进程的数量时，它会增加一个进程连续 10 次成为不幸进程的机会。在最后一次重试之后，NLog 丢弃了 LogEvent（可能是您所看到的）。

KeepFileOpen=false 很慢 (300 writes/sec)，当与重试逻辑结合使用时，它会变得非常慢。但是通过在允许批处理时使用 AsyncWrapper，它几乎可以消除性能影响。但现在当重试次数用完时，可能会丢失整批。

您可以不依赖操作系统文件锁，而是依赖 NLog 使用全局互斥锁进行进程间通信。此模式通过 KeepFileOpen=True 和 ConcurrentWrites=true 启用。而不是 300 writes/sec 然后变成 100.000 writes/sec 并且锁定机制更公平，所以不需要重试。并非所有平台都支持此模式，但在 Windows 上的 .NET 4.8（以及 Linux 上的 NetCore2）上应该可以很好地工作。

另请参阅：https://github.com/NLog/NLog/wiki/File-target#Multi-processes-writing-same-file

NLog 不会在进程退出时刷新所有日志条目

NLog does not flush all log entries upon process exit

.net

c#

logging

nlog

multiprocessing