【问题标题】:How Thread-Safe is NLog?NLog 的线程安全性如何?
【发布时间】:2011-08-08 01:06:55
【问题描述】:

嗯,

我已经等了好几天才决定发布这个问题,因为我不知道如何陈述这一点,最终还是写了一篇很长的详细帖子。但是,我认为此时向社区寻求帮助是相关的。

基本上,我尝试使用 NLog 为数百个线程配置记录器。我认为这会非常简单,但是几十秒后我得到了这个异常: "InvalidOperationException : 集合被修改;枚举操作可能无法执行"

这里是代码。

//Launches threads that initiate loggers
class ThreadManager
{
    //(...)
    for (int i = 0; i<500; i++)
    {
        myWorker wk = new myWorker();
        wk.RunWorkerAsync();
    }

    internal class myWorker : : BackgroundWorker
    {             
       protected override void OnDoWork(DoWorkEventArgs e)
       {              
           // "Logging" is Not static - Just to eliminate this possibility 
           // as an error culprit
           Logging L = new Logging(); 
           //myRandomID is a random 12 characters sequence
           //iLog Method is detailed below
          Logger log = L.iLog(myRandomID);
          base.OnDoWork(e);
       }
    }
}

public class Logging
{   
        //ALL THis METHOD IS VERY BASIC NLOG SETTING - JUST FOR THE RECORD
        public Logger iLog(string loggerID)
        {
        LoggingConfiguration config;
        Logger logger;
        FileTarget FileTarget;            
        LoggingRule Rule; 

        FileTarget = new FileTarget();
        FileTarget.DeleteOldFileOnStartup = false;
        FileTarget.FileName =  "X:\\" + loggerID + ".log";

        AsyncTargetWrapper asyncWrapper = new AsyncTargetWrapper();
        asyncWrapper.QueueLimit = 5000;
        asyncWrapper.OverflowAction = AsyncTargetWrapperOverflowAction.Discard;
        asyncWrapper.WrappedTarget = FileTarget;

        //config = new LoggingConfiguration(); //Tried to Fool NLog by this trick - bad idea as the LogManager need to keep track of all config content (which seems to cause my problem;               
        config = LogManager.Configuration;                
        config.AddTarget("File", asyncWrapper);                
        Rule = new LoggingRule(loggerID, LogLevel.Info, FileTarget);

        lock (LogManager.Configuration.LoggingRules)
            config.LoggingRules.Add(Rule);                

        LogManager.Configuration = config;
        logger = LogManager.GetLogger(loggerID);

        return logger;
    }
}   

所以我完成了我的工作,而不仅仅是在这里发布我的问题并享受家庭时光,我花了整个周末的时间来研究这个(幸运男孩!) 我下载了 NLOG 2.0 的最新稳定版本并将其包含在我的项目中。我能够追踪到它爆炸的确切位置:

在 LogFactory.cs 中:

    internal void GetTargetsByLevelForLogger(string name, IList<LoggingRule> rules, TargetWithFilterChain[] targetsByLevel, TargetWithFilterChain[] lastTargetsByLevel)
    {
        //lock (rules)//<--Adding this does not fix it
            foreach (LoggingRule rule in rules)//<-- BLOWS HERE
            {
            }
     }

在 LoggingConfiguration.cs 中:

internal void FlushAllTargets(AsyncContinuation asyncContinuation)
    {            
        var uniqueTargets = new List<Target>();
        //lock (LoggingRules)//<--Adding this does not fix it
        foreach (var rule in this.LoggingRules)//<-- BLOWS HERE
        {
        }
     }

我的问题
因此,根据我的理解,发生的情况是 LogManager 混淆了,因为 从不同的线程调用 config.LoggingRules.Add(Rule)GetTargetsByLevelForLogger 和 FlushAllTargets 正在被调用。 我试图搞砸 foreach 并用 for 循环替换它,但记录器变成了流氓(跳过了许多日志文件的创建)

太棒了终于
到处都写着 NLOG 是线程安全的,但我通过一些帖子进一步挖掘并声称这取决于使用场景。我的情况呢? 我必须创建数以千计的记录器(不是同时创建,但速度仍然非常快)。

我发现的解决方法是在同一主线程中创建所有记录器;这真的不方便,因为我在应用程序开始时创建了所有应用程序记录器(有点像记录器池)。 虽然效果很好,但它只是不可接受的设计。

所以大家都知道。 请帮助程序员再次见到他的家人。

【问题讨论】:

  • 只是想知道,为什么你完全跳过反应灵敏的作者 (Jarek Kowalski):nlog-project.org/forum 请注意 2.0 仍被视为 Beta,最新的夜间构建甚至 alpha...

标签: c# multithreading logging nlog


【解决方案1】:

这是一个较老的问题,但作为 NLog 的当前所有者,我有以下见解:

  • 创建记录器是线程安全的
  • 写入日志消息是线程安全的
  • 上下文类和渲染器的使用是(GDC、MDC 等)线程安全的
  • 在运行时添加新目标 + 规则是线程安全的(使用 LoggingConfiguration.AddRule + ReconfigExistingLoggers 时)
  • 执行 LoggingConfiguration 的重新加载将导致来自活动记录器的 LogEvents 被丢弃,直到重新加载完成。
  • 在运行时更改现有规则和目标的值不是线程安全的!

您应该避免在运行时更改现有项目的值。相反,应该使用context renderers${event-properties}${GDC}${MDLC} 等)

【讨论】:

  • 我们通常在类的顶部声明一个静态记录器,以便在整个类中使用,这种方法已在一些 Web 应用程序中使用。跨多个线程使用静态 Logger 来写入日志安全吗?
  • 是的。这甚至是推荐的方法:)。见github.com/nlog/nlog/wiki/…
  • @Julian 很抱歉捎带这个问题。我们有一个要求,我们在运行时确实有数百个记录器。 (我们不能使用配置,因为记录器是动态的)。此外,我们需要能够在运行时的日志级别更改记录器。我们创建的日志可能非常冗长,因此我们将它们保留在信息中。如果出现问题,我们希望能够动态地将记录器更改为 DEBUG,以便我们可以排除故障,然后返回 INFO。这样做的建议方法是什么?
  • 请创建一个新问题 StackOverflow :) 我可以回答,但不在评论中
【解决方案2】:

根据their wiki 上的文档,它们是线程安全的:

由于记录器是线程安全的,您只需创建一次记录器并将其存储在静态变量中

根据您收到的错误,您很可能正在执行异常所描述的内容:在 foreach 循环迭代时修改代码中某处的集合。由于您的列表是通过引用传递的,因此不难想象另一个线程在您对其进行迭代时会在哪里修改规则集合。你有两个选择:

  1. 预先创建所有规则,然后批量添加(我认为这是您想要的)。
  2. 将您的列表投射到某个只读集合 (rules.AsReadOnly()) 中,但会错过在您创建的线程创建新规则时发生的任何更新。

【讨论】:

    【解决方案3】:

    通过枚举集合的副本,您可以解决此问题。我对 NLog 源进行了以下更改,它似乎解决了问题:

    internal void GetTargetsByLevelForLogger(string name, IList<LoggingRule> rules, TargetWithFilterChain[] targetsByLevel, TargetWithFilterChain[] lastTargetsByLevel)
    {
       foreach (LoggingRule rule in rules.ToList<LoggingRule>())
       {
       ... 
    

    【讨论】:

      【解决方案4】:

      我对你的问题没有真正的答案,但我确实有一些观察和一些问题:

      根据您的代码,您似乎希望为每个线程创建一个记录器,并且您希望将该记录器记录到以某个传入的 id 值命名的文件中。因此,id 为“abc”的记录器将记录到“x:\abc.log”,“def”将记录到“x:\def.log”,依此类推。我怀疑你可以通过 NLog 配置而不是编程来做到这一点。我不知道它是否会更好,或者 NLog 是否会遇到与您相同的问题。

      我的第一印象是你做了很多工作:为每个线程创建一个文件目标,为每个线程创建一个新规则,获取一个新的记录器实例等,你可能不需要做这些工作来完成它看起来你想要完成的。

      我知道 NLog 允许根据至少一些 NLog LayoutRenderers 动态命名输出文件。例如,我知道这是可行的:

      fileName="${level}.log"
      

      会给你这样的文件名:

      Trace.log
      Debug.log
      Info.log
      Warn.log
      Error.log
      Fatal.log
      

      因此,例如,您似乎可以使用这样的模式来创建基于线程 id 的输出文件:

      fileName="${threadid}.log"
      

      如果您最终拥有线程 101 和 102,那么您将拥有两个日志文件:101.log 和 102.log。

      在您的情况下,您想根据自己的 id 命名文件。您可以将 id 存储在 MappedDiagnosticContext(这是一个允许您存储线程本地名称-值对的字典)中,然后在您的模式中引用它。

      您的文件名模式如下所示:

      fileName="${mdc:myid}.log"
      

      因此,在您的代码中,您可以这样做:

               public class ThreadManager
               {
                 //Get one logger per type.
                 private static readonly Logger logger = LogManager.GetCurrentClassLogger();
      
                 protected override void OnDoWork(DoWorkEventArgs e)
                 {
                   // Set the desired id into the thread context
                   NLog.MappedDiagnosticsContext.Set("myid", myRandomID);
      
                   logger.Info("Hello from thread {0}, myid {1}", Thread.CurrentThread.ManagedThreadId, myRandomID);
                   base.OnDoWork(e);  
      
                   //Clear out the random id when the thread work is finished.
                   NLog.MappedDiagnosticsContext.Remove("myid");
                 }
               }
      

      这样的事情应该允许您的 ThreadManager 类有一个名为“ThreadManager”的记录器。每次它记录一条消息时,它都会在 Info 调用中记录格式化的字符串。如果记录器被配置为记录到文件目标(在配置文件中制定一个规则,将“*.ThreadManager”发送到文件名布局如下所示的文件目标:

      fileName="${basedir}/${mdc:myid}.log"
      

      在记录消息时,NLog 将根据文件名布局的值确定文件名应该是什么(即它在记录时应用格式化标记)。如果文件存在,则将消息写入其中。如果该文件尚不存在,则创建该文件并将消息记录到其中。

      如果每个线程都有一个随机 id,比如“aaaaaaaaaaaa”、“aaaaaaaaaaab”、“aaaaaaaaaaac”,那么你应该得到这样的日志文件:

      aaaaaaaaaaaa.log
      aaaaaaaaaaab.log
      aaaaaaaaaaac.log
      

      等等。

      如果您可以这样做,那么您的生活应该会更简单,因为您不必进行 NLog 的所有编程配置(创建规则和文件目标)。您可以让 NLog 担心创建输出文件名。

      我不确定这是否会比您所做的更好。或者,即使确实如此,您也可能真的需要在更大的范围内完成您正在做的事情。它应该很容易测试以查看它是否有效(即,您可以根据 MappedDiagnosticContext 中的值命名输出文件)。如果它适用于此,那么您可以在创建数千个线程的情况下尝试它。

      更新:

      这里是一些示例代码:

      使用这个程序:

      using System;
      using System.Collections.Generic;
      using System.Linq;
      using System.Text;
      
      using NLog;
      using System.Threading;
      using System.Threading.Tasks;
      
      namespace NLogMultiFileTest
      {
        class Program
        {
          public static Logger logger = LogManager.GetCurrentClassLogger();
      
          static void Main(string[] args)
          {
      
            int totalThreads = 50;
            TaskCreationOptions tco = TaskCreationOptions.None;
            Task task = null;
      
            logger.Info("Enter Main");
      
            Task[] allTasks = new Task[totalThreads];
            for (int i = 0; i < totalThreads; i++)
            {
              int ii = i;
              task = Task.Factory.StartNew(() =>
              {
                MDC.Set("id", "_" + ii.ToString() + "_");
                logger.Info("Enter delegate.  i = {0}", ii);
                logger.Info("Hello! from delegate.  i = {0}", ii);
                logger.Info("Exit delegate.  i = {0}", ii);
                MDC.Remove("id");
              });
      
              allTasks[i] = task;
            }
      
            logger.Info("Wait on tasks");
      
            Task.WaitAll(allTasks);
      
            logger.Info("Tasks finished");
      
            logger.Info("Exit Main");
          }
        }
      }
      

      还有这个 NLog.config 文件:

      <?xml version="1.0" encoding="utf-8" ?>
      <!-- 
        This file needs to be put in the application directory. Make sure to set 
        'Copy to Output Directory' option in Visual Studio.
        -->
      <nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
      
          <targets>
              <target name="file" xsi:type="File" layout="${longdate} | ${processid} | ${threadid} | ${logger} | ${level} | id=${mdc:id} | ${message}" fileName="${basedir}/log_${mdc:item=id}.txt" />
          </targets>
      
          <rules>
              <logger name="*" minlevel="Debug" writeTo="file" />
          </rules>
      </nlog>
      

      我能够为委托的每次执行获取一个日志文件。日志文件以存储在 MDC (MappedDiagnosticContext) 中的“id”命名。

      所以,当我运行示例程序时,我得到了 50 个日志文件,每个日志文件中都有三行“Enter...”、“Hello...”、“Exit...”。每个文件都命名为 log__X_.txt 其中 X 是捕获的计数器 (ii) 的值,所以我有 log_0.txt、log_1.txt、log_1.txt 等,log_49.txt。每个日志文件仅包含与委托的一次执行有关的日志消息。

      这与您想做的类似吗?我的示例程序使用任务而不是线程,因为我前段时间已经编写过它。我认为该技术应该很容易适应您正在做的事情。

      您也可以这样做(为委托的每次执行获取一个新的记录器),使用相同的 NLog.config 文件:

      using System;
      using System.Collections.Generic;
      using System.Linq;
      using System.Text;
      
      using NLog;
      using System.Threading;
      using System.Threading.Tasks;
      
      namespace NLogMultiFileTest
      {
        class Program
        {
          public static Logger logger = LogManager.GetCurrentClassLogger();
      
          static void Main(string[] args)
          {
      
            int totalThreads = 50;
            TaskCreationOptions tco = TaskCreationOptions.None;
            Task task = null;
      
            logger.Info("Enter Main");
      
            Task[] allTasks = new Task[totalThreads];
            for (int i = 0; i < totalThreads; i++)
            {
              int ii = i;
              task = Task.Factory.StartNew(() =>
              {
                Logger innerLogger = LogManager.GetLogger(ii.ToString());
                MDC.Set("id", "_" + ii.ToString() + "_");
                innerLogger.Info("Enter delegate.  i = {0}", ii);
                innerLogger.Info("Hello! from delegate.  i = {0}", ii);
                innerLogger.Info("Exit delegate.  i = {0}", ii);
                MDC.Remove("id");
              });
      
              allTasks[i] = task;
            }
      
            logger.Info("Wait on tasks");
      
            Task.WaitAll(allTasks);
      
            logger.Info("Tasks finished");
      
            logger.Info("Exit Main");
          }
        }
      }
      

      【讨论】:

      • @wageoghe :我的朋友,你的帖子远远超出了我的想象。这正是我一直在寻找的,但是我几天前才发现了 NLog,并且不得不非常快速地实现日志管理。我寻找了一种方法来做到这一点,但我没有轻易找到它,所以我一直以基本的肮脏方式去做。明天早上我会花时间认真地给这个试一试,看看结果如何。如果您知道任何方式可以给您更多的选票或给您积分或其他任何方式,请告诉我,因为我将非常感谢您。
      • @Mika Jacobi - 很高兴为您提供帮助!我只希望它对你有用。我自己没有尝试过,所以我不确定它会完全按照你的意愿做。您可能会发现这里的一些 NLog 技巧也很有用:stackoverflow.com/questions/4091606/…
      • 我听从了你的指示。动态 ID 技巧有效,但我只能写一个记录器(即,对应于创建的第一个线程的那个)。后面的其他内容不会导致写入日志文件)。我认为记录器不应该是静态的,但即使删除静态引用也没有用......(顺便说一句,我已经编辑了你的帖子以进行小的更正,因为它没有按原样编译。)
      • @Mika Jacobi - 查看我的最新编辑,看看它是否对您有帮助。我演示了可以为委托函数的每次执行创建一个日志文件,该文件的命名基于 MappedDiagnosticContext (MDC) 中存储的值。
      • @wageoghe :您的示例代码存在限制。我花了一些时间来精确识别它:如果您的主记录器恰好在 MDC SetMDC remove 任务之间写入,则日志会混淆(即,如果您的任务花时间运行,你的主线程记录东西,这些日志被写入最后创建的日志文件。)示例代码:innerLogger.Info("Enter delegate. i = {0}", ii);logger.Info("PIKABOO");innerLogger.Info("Hello! from delegate. i = {0}", ii);
      【解决方案5】:

      我不知道 NLog,但是从上面的部分和 API 文档 (http://nlog-project.org/help/) 中可以看出,只有一个静态配置。因此,如果您只想在创建记录器时使用此方法向配置添加规则(每个都来自不同的线程),那么您正在编辑相同的配置对象。据我在 NLog 文档中看到的,没有办法为每个记录器使用单独的配置,所以这就是你需要所有规则的原因。

      添加规则的最佳方法是在启动异步工作者之前添加规则,但我假设这不是您想要的。

      也可以只为所有工人使用一个记录器。但我将假设您需要将每个工人放在一个单独的文件中。

      如果每个线程都在创建自己的记录器并将自己的规则添加到配置中,则您必须对其进行锁定。请注意,即使您同步了代码,在您更改规则时,仍有一些其他代码正在枚举规则。正如您所展示的,NLog 不会围绕这些代码位进行锁定。因此,我认为任何线程安全声明仅适用于实际的日志写入方法。

      我不确定您现有的锁是做什么的,但我认为它并没有达到您的预期。所以,改变

      ...
      lock (LogManager.Configuration.LoggingRules)
      config.LoggingRules.Add(Rule);                
      
      LogManager.Configuration = config;
      logger = LogManager.GetLogger(loggerID);
      
      return logger;
      

      ...
      lock(privateConfigLock){
          LogManager.Configuration.LoggingRules.Add(Rule);                
      
          logger = LogManager.GetLogger(loggerID);
      }
      return logger;
      

      请注意,最好只锁定您“拥有”的对象,即您的类私有的对象。这可以防止某些其他代码(不遵守最佳实践)中的某些类锁定可能会导致死锁的相同代码。所以我们应该将privateConfigLock 定义为您的班级的私有。我们还应该将其设为静态,以便每个线程看到相同的对象引用,如下所示:

      public class Logging{
          // object used to synchronize the addition of config rules and logger creation
          private static readonly object privateConfigLock = new object();
      ...
      

      【讨论】:

      • 完美答案。非常感谢。特别是花时间阅读 NLog API,因为你不知道 NLog。你是个好人。如果明天早上我试一试时效果很好,我会将其标记为答案。
      • 谢谢,锁的正确使用效果很好。从一般 .Net 的角度来看,您的提议是正确的答案。然而,@wageoghe 的提议似乎更符合 NLog,因为我不必再为每个记录器声明一个目标,而是使用“通配符”,这解决了我一开始遇到的并发问题。感谢您的帮助。
      【解决方案6】:

      我认为您可能没有正确使用lock。您正在锁定传递给您的方法的对象,所以我认为这意味着不同的线程可能会锁定不同的对象。

      大多数人只是将这个添加到他们的课程中:

      private static readonly object Lock = new object();
      

      然后锁定它并保证它永远是同一个对象。

      我不确定这是否能解决您的问题,但您现在所做的事情对我来说很奇怪。 其他人可能不同意。

      【讨论】:

      • 对不起,我可能不同意。阅读:albahari.com/threading/part2.aspx#_Locking
      • 此外,理论上我什至不必将锁作为 Nlog 状态来进行线程安全
      • 我不明白。我读了那个链接,它也使用static readonly object _locker = new object();。你不同意什么?
      • @Mika:是你写的吗?如果你这样做了,请删除它说可以锁定thisType 实例的部分。这是一个糟糕的锁定选择,因为您不知道调用代码也没有锁定这些东西,并且您将创建死锁。您永远不应该锁定在执行锁定的类之外可见的任何实例。
      • 我的坏我的坏很抱歉。我不明白 Buh Buh 发帖的目的。我很抱歉,我一开始就完全错了。我稍后会解决这个问题。
      猜你喜欢
      • 1970-01-01
      • 1970-01-01
      • 1970-01-01
      • 1970-01-01
      • 1970-01-01
      • 1970-01-01
      • 1970-01-01
      • 1970-01-01
      相关资源
      最近更新 更多