Подтвердить что ты не робот

Как Thread-Safe является NLog?

Ну,

Я подождал несколько дней, прежде чем решила опубликовать этот вопрос, поскольку я не был уверен, как это сказать, перейдя в длинный подробный пост. Тем не менее, я думаю, что на данный момент важно обратиться за помощью к сообществу.

В принципе, я пытался использовать 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;
    }
}   

Итак, я сделал свою работу, а не просто разместил свой вопрос здесь и получил семейное качество-время, я потратил на это выходные (Lucky Boy!) Я загрузил последнюю стабильную версию 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, но логгер стал изгоем (пропуская много файлов журналов)

SOoooo НАКОНЕЦ
Во всем мире написано, что NLOG является потокобезопасным, но я пришел через несколько сообщений, которые все больше копают и утверждают, что это зависит от сценария использования. Как насчет моего дела? Я должен создать тысячи регистраторов (не всех одновременно, но все же очень быстро).

Обходной путь, который я нашел, - создать все регистраторы в SAME MASTER THREAD; это ДЕЙСТВИТЕЛЬНО неудобно, поскольку я создаю все свои регистраторы приложений в начале приложения (вроде пула Logger). И хотя это работает сладко, это просто НЕ приемлемый дизайн.

Итак, вы знаете все это. Пожалуйста, помогите кодеру снова увидеть его семью.

4b9b3361

Ответ 1

У меня нет ответа на вашу проблему, но у меня есть некоторые замечания и некоторые вопросы:

В соответствии с вашим кодом, похоже, вы хотите создать журнал для каждого потока, и вы хотите, чтобы этот журнал регистрации был в файле с именем для некоторого значения 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

Так, например, кажется, что вы можете использовать такой шаблон для создания выходных файлов на основе идентификатора потока:

fileName="${threadid}.log"

И если у вас появились потоки 101 и 102, у вас будет два файла журнала: 101.log и 102.log.

В вашем случае вы хотите назвать файл на основе вашего собственного идентификатора. Вы можете сохранить идентификатор в 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". Каждый раз, когда он регистрирует сообщение, он будет записывать форматированную строку в информационном вызове. Если логгер настроен на запись в целевой файл (в конфигурационном файле создается правило, которое отправляет "*.ThreadManager" в файл, чей формат имени файла выглядит примерно так:

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

Во время регистрации сообщения NLog определит, каким должно быть имя файла, на основе значения макета fileName (т.е. он применяет маркеры форматирования во время регистрации). Если файл существует, сообщение записывается в него. Если файл еще не существует, файл создается и сообщение регистрируется на нем.

Если каждый поток имеет случайный идентификатор типа "aaaaaaaaaaaa", "aaaaaaaaaaab", "aaaaaaaaaaac", тогда вы должны получить файлы журналов следующим образом:

aaaaaaaaaaaa.log
aaaaaaaaaaab.log
aaaaaaaaaaac.log

И так далее.

Если вы можете сделать это таким образом, тогда ваша жизнь должна быть проще, поскольку вам не нужно выполнять всю эту программную конфигурацию NLog (создание правил и целевых файлов). И вы можете позволить NLog беспокоиться о создании имен выходных файлов.

Я не знаю точно, что это будет работать лучше, чем то, что вы делаете. Или, даже если это так, вам действительно понадобится то, что вы делаете в своей более широкой картине. Это должно быть достаточно легко проверить, чтобы убедиться, что он работает (т.е. Вы можете назвать свой выходной файл на основе значения в MappedDiagnosticContext). Если он работает для этого, вы можете попробовать его для своего случая, когда вы создаете тысячи потоков.

UPDATE:

Вот пример кода:

С помощью этой программы:

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>

Я могу получить один файл журнала для каждого выполнения делегата. Файл журнала имеет имя для "id", хранящегося в MDC (MappedDiagnosticContext).

Итак, когда я запускаю программу-образец, я получаю 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");
    }
  }
}

Ответ 2

Я не знаю 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();
...

Ответ 3

Это старый вопрос, но, как нынешний владелец NLog, я понял следующее:

  • Создать регистратор является потокобезопасным
  • Написание сообщений журнала является потокобезопасным
  • Использование контекстных классов и средств визуализации (GDC, MDC и т.д.) Поточно-ориентировано
  • Добавление новых целей + правил во время выполнения является поточно- LoggingConfiguration.AddRule (при использовании LoggingConfiguration.AddRule + ReconfigExistingLoggers)
  • Выполнение перезагрузки LoggingConfiguration приведет к удалению LogEvents из активных регистраторов до завершения перезагрузки.
  • Изменение значений существующих правил и целей во время выполнения не является поточно-ориентированным!

Вы должны избегать изменения значений существующих элементов во время выполнения. Вместо этого следует использовать средства визуализации контекста (${event-properties}, ${GDC}, ${MDLC} и т.д.)

Ответ 4

Я думаю, что вы, возможно, не используете lock правильно. Вы блокируете объекты, которые передаются в ваш метод, поэтому я думаю, что это означает, что различные потоки могут блокироваться для разных объектов.

Большинство людей просто добавляют это в свой класс:

private static readonly object Lock = new object();

Затем заблокируйте это и убедитесь, что он всегда будет тем же самым объектом.

Я не уверен, что это исправит вашу проблему, но то, что вы делаете, теперь кажется странным для меня. Другие люди могут не согласиться.

Ответ 5

Перечислив копию коллекции, вы можете решить эту проблему. Я внес изменения в источник NLog и, похоже, исправил проблему:

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

Ответ 6

Согласно документации на их вики они потокобезопасны:

Поскольку регистраторы являются потокобезопасными, вы можете просто создать логгер один раз и сохранить его в статической переменной

Основываясь на полученной вами ошибке, вы, скорее всего, выполняете именно то, что имеет значение: изменение коллекции где-то в коде, а цикл foreach - итерация. Поскольку ваш список передается по ссылке, нетрудно представить, где другой поток будет изменять набор правил, пока вы выполняете итерацию по нему. У вас есть два варианта:

  • Создайте все свои правила спереди, а затем добавьте их навалом (это то, что я думаю, вы хотите).
  • Передайте свой список в некоторую коллекцию только для чтения (rules.AsReadOnly()), но пропустите любые обновления, которые происходят по мере того, как созданные вами потоки создают новые правила.