NLog does not flush all log entries upon process exit(进程退出时,NLog不会刷新所有日志条目)
问题描述
在这个线程中--Should NLog flush all queued messages in the AsyncTargetWrapper when Flush() is called?--我读到"LogManager
在域卸载或进程退出时将配置设置为空"(请参阅第一个答案中的编辑部分)。在我的理解中,这应该会导致将所有挂起的日志条目写入已注册的目标。然而,在用AsyncTargetWrapper
包装的FileTarget
进行测试后,这并不成立。我已经在giHub-https://github.com/PaloMraz/NLogMultiProcessTargetsSample上创建了一个最小的repros,它的工作方式如下:
LogLib
是引用NLog
4.6.8 NuGet包并公开以编程方式配置NLog
目标的CompositeLogger
类的.netstandard2.0
库:
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 Framework4.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),
@"........LogConsoleRunnerinDebugLogConsoleRunner.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
以确保在所有进程退出后,所有挂起的日志条目都写入目标日志文件?
推荐答案
我已经查看了您的示例代码,并且您有多个进程写入相同的文件名。
认为您是性能和正确性之间妥协的受害者。
当多个进程同时写入同一文件时,则需要一些锁定以进行协调。默认情况下,NLog使用最兼容的模式(KeepFileOpen=False),即从操作系统锁定文件(适用于大多数平台)。
来自操作系统的文件锁定是不公平的,当有两个以上的进程写入同一文件时也不能扩展。当一个进程尝试打开另一个进程当前正在使用的文件时,将引发异常。
NLog尝试通过在出错时重试(concurentWriteAttempt=10)以及随机地在重试前等待多长时间来处理这些异常。这对两个进程都有效,但是当您开始增加进程的数量时,它会增加一个进程连续10次成为不吉利进程的可能性。在最后一次重试后,NLog将丢弃LogEvent(可能是您看到的)。 KeepFileOpen=False很慢(300次写入/秒),当与重试逻辑结合使用时,它会变得非常慢。但是在允许批处理的情况下使用AsyncWrapper,这基本上消除了对性能的影响。但现在,当重试计数用完时,可能会丢失一整批。不依赖于操作系统文件锁,而是可以依赖NLog使用全局互斥锁进行进程间通信。此模式通过KeepFileOpen=True
和ConcurrentWrites=true
启用。不再是每秒300次写入,而是每秒100.000次写入,锁定机制更加公平,因此无需重试。并非所有平台都支持此模式,但在Windows上的.NET 4.8(以及Linux上的NetCore2)上应该可以很好地工作。
另见:https://github.com/NLog/NLog/wiki/File-target#Multi-processes-writing-same-file
这篇关于进程退出时,NLog不会刷新所有日志条目的文章就介绍到这了,希望我们推荐的答案对大家有所帮助,也希望大家多多支持编程学习网!