自 MinimalLock 设置以来，Log4net 多次记录同一行答案

【问题标题】：Log4net logs several times same line since MinimalLock setup自 MinimalLock 设置以来，Log4net 多次记录同一行
【发布时间】：2016-11-18 10:09:12
【问题描述】：

我最近不得不面对我的 C# 程序的一些性能问题，并发现 log4net 是这些问题的根源。我更改了配置，添加了MinimalLock，它确实有很大帮助。

这就是我现在配置 log4net 的方式：

var hierarchy = (Hierarchy)log4net.LogManager.GetRepository();

var patternLayout = new PatternLayout();
patternLayout.ConversionPattern = "%date [%thread] %-5level %logger - %message%newline";
patternLayout.ActivateOptions();

var roller = new RollingFileAppender();

roller.LockingModel = new FileAppender.MinimalLock();
roller.LockingModel.ActivateOptions();

roller.Encoding = System.Text.Encoding.UTF8;
roller.AppendToFile = true;
roller.File = Path.Combine(Logger.LogPath, "log.txt");
roller.Layout = patternLayout;
roller.MaxSizeRollBackups = 5;
roller.MaximumFileSize = "100MB";
roller.RollingStyle = RollingFileAppender.RollingMode.Size;
roller.StaticLogFileName = true;
roller.ActivateOptions();

hierarchy.Root.AddAppender(roller);
hierarchy.Root.Level = Level.Debug;
hierarchy.Configured = true;

这样做的缺点是，现在我的日志包含重复多次的相同日志行。

我怀疑我误解了 log4net 配置中的某些内容，现在我要输出的每个日志行发送的次数与应用程序所具有的进程一样多（甚至，显然，创建的其余进程没有记录任何内容，或者至少不是同一行！）

这里是日志行的示例：

2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,495 [1] 调试 MetryViewModel - 读取数据：manuel.dat，配置：无 2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] INFO ViewModel - 操作模式：大声笑
2016-11-18 10:35:34,512 [1] 信息视图模型-操作模式：大声笑

【问题讨论】：

你是否多次运行上面的代码？另外，与应用程序的进程一样多是什么意思？.
我只运行了一次代码。 与应用程序的进程一样多我的意思是应用程序正在创建多个进程，这可能有某种关联吗？
真的没有意义。要获取多个条目，您要么需要添加多个记录器，要么需要多次记录事件。如果是后者，事件会在不需要 MininalLock 的情况下显示，并且时间戳会不同，所以看起来你正在初始化 log4net 几次。要排除这种情况，您是否可以在致电 hierarchy.Configured = true; 后立即尝试记录某些内容（可能是 LogManager.GetRepository().GetAppenders().Length），并查看此消息是否立即添加多次，或者是否添加一次、两次、然后三次，等等
也许问题是这样的。您正在多个线程中调用您的日志记录语句。当您没有激活 MinimalLock 时，写入文件的第一个线程将锁定它。所以所有其他线程都不能写入文件。一旦你激活了 MinimalLock，Appender 就会锁定文件并再次释放它。所以现在每个线程都可以写入文件

标签： log4net log4net-configuration log4net-appender

【解决方案1】：

在你的情况下：
如果消息都在同一时间和同一线程上，则您的组件之一可能正在添加跟踪侦听器。检查System.Diagnostics.Trace.Listeners 属性。
就我而言，是 Owin Server 在启动时添加了它们。： OWIN interferes with log4net

对于其他人：
消除由多个 appender 引起的可能性。
您可以使用LogManager.GetRepository().GetAppenders().Length;
请记住，您的记录器将继承根记录器的附加程序。

确保您的代码只被调用一次（您可以通过在您的 conversationPattern 中添加 [%thread] 来打印线程 ID。

<layout type="log4net.Layout.PatternLayout">
    <param name="ConversionPattern" value="%date [%thread] %message%newline" />
  </layout>

【讨论】：

对我来说它打印的是同一个线程，所以该函数只被调用一次，我只有一个 appender，但是同一行日志被记录了好几次，你知道为什么吗？请注意，我使用的是 .net core