Насколько потокобезопасен NLog? - PullRequest
26 голосов
/ 18 апреля 2011

Ну,

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

По сути, я попытался использовать NLog для настройки регистраторов для сотен потоков.Я думал, что это будет очень просто, но я получил это исключение через несколько десятков секунд: " InvalidOperationException: Collection был изменен; операция перечисления может не выполняться "

Вот код.

//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) из разных потоков while GetTargetsByLevelForLogger и FlushAllTargets вызывают.Я пытался прикрутить foreach и заменить его на цикл for, но регистратор оказался мошенническим (пропуская создание многих файлов журнала)

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

Обходной путь, который я нашел, состоит в том, чтобы создать все регистраторы в ОДНОЙ МАСТЕРНОЙ РЕЗЬБЕ;это REALLY неудобно, так как я создаю все свои регистраторы приложений в начале приложения (своего рода пул регистраторов).И хотя он отлично работает, это просто НЕ приемлемый дизайн.

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

Ответы [ 6 ]

34 голосов
/ 18 апреля 2011

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

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

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

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

Если у каждого потока есть случайный идентификатор, такой как "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>

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

Итак, когда я запускаю пример программы, я получаю 50 файлов журнала, в каждом из которых есть три строки «Enter... "," Привет ... "," Выход ... ".Каждый файл называется 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");
    }
  }
}
7 голосов
/ 18 апреля 2011

Я не знаю 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();
...
1 голос
/ 28 января 2019

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

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

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

0 голосов
/ 06 августа 2014

Согласно документации на их вики они являются поточно-ориентированными:

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

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

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

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

internal void GetTargetsByLevelForLogger(string name, IList<LoggingRule> rules, TargetWithFilterChain[] targetsByLevel, TargetWithFilterChain[] lastTargetsByLevel)
{
   foreach (LoggingRule rule in rules.ToList<LoggingRule>())
   {
   ... 
0 голосов
/ 18 апреля 2011

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

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

private static readonly object Lock = new object();

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

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

...