Когда использовать "вложенный диагностический контекст" (NDC)?

Question

Играя с log4net, я видел возможность использовать стек контекстных меток для каждого потока, называемый NDC.

Метки, помещенные в этот стек, отображаются в PatternLayout путем указания %x или %ndc параметр формата.

Использование что-то вроде:

ILog log = log4net.LogManager.GetLogger(...) ;

//pattern layout format: "[%ndc] - %message%newline"

log.Info("message 1"); 
using(log4net.NDC.Push("context")
{
    using(log4net.NDC.Push("inner_context")
    {
      log.Info("message 2"); 
    }
    log.Info("message 3"); 
}
log.Info("message 4"); 

Вывод что-то вроде:

null - message 1
context inner_context - message 2
context - message 3
null - message 4

Когда вы находили эту функцию полезной в своем опыте программирования с log4net?

Answer 1

В серверном приложении, таком как ASP.NET.

Например, вы можете отправить информацию о текущем запросе в НДЦ.

Answer 2

Хотите пример?

Возьмите следующий веб-API, написанный с использованием ASP.NET MVC4:

// GET api/HypervResource
public string Get()
{
    logger.Debug("Start of service test");
    System.Threading.Thread.Sleep(5000); // simulate work
    logger.Debug("End of service test");
    return "HypervResource controller running, use POST to send JSON encoded RPCs";
}

Когда выполняются параллельные HTTP-запросы сервера, регистрация может чередоваться. Например

2013-06-27 13:28:11,967 [10] DEBUG HypervResource.WmiCalls [(null)] - Start of service test
2013-06-27 13:28:12,976 [12] DEBUG HypervResource.WmiCalls [(null)] - Start of service test
2013-06-27 13:28:14,116 [13] DEBUG HypervResource.WmiCalls [(null)] - Start of service test
2013-06-27 13:28:16,971 [10] DEBUG HypervResource.WmiCalls [(null)] - End of service test
2013-06-27 13:28:17,979 [12] DEBUG HypervResource.WmiCalls [(null)] - End of service test
2013-06-27 13:28:19,119 [13] DEBUG HypervResource.WmiCalls [(null)] - End of service test

В этом простом примере вы могли бы использовать идентификатор потока, чтобы различать запросы, но это может оказаться сложным по мере того, как лог-файл становится все сложнее.

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

// GET api/HypervResource
public string Get()
{
    using(log4net.NDC.Push(Guid.NewGuid().ToString()))
    {
        logger.Debug("Start of service test");
        System.Threading.Thread.Sleep(5000); // simulate work
        logger.Debug("End of service test");
        return "HypervResource controller running, use POST to send JSON encoded RPCs";
    }
}

Это создает журнал, который вы можете grep, чтобы увидеть проблемы, связанные с конкретным запросом. Например

2013-06-27 14:04:31,431 [11] DEBUG HypervResource.WmiCalls [525943cb-226a-43c2-8bd5-03c258d58a79] - Start of service test
2013-06-27 14:04:32,322 [12] DEBUG HypervResource.WmiCalls [5a8941ee-6e26-4c1d-a1dc-b4d9b776630d] - Start of service test
2013-06-27 14:04:34,450 [13] DEBUG HypervResource.WmiCalls [ff2246f1-04bc-4451-9e40-6aa1efb94073] - Start of service test
2013-06-27 14:04:36,434 [11] DEBUG HypervResource.WmiCalls [525943cb-226a-43c2-8bd5-03c258d58a79] - End of service test
2013-06-27 14:04:37,325 [12] DEBUG HypervResource.WmiCalls [5a8941ee-6e26-4c1d-a1dc-b4d9b776630d] - End of service test
2013-06-27 14:04:39,453 [13] DEBUG HypervResource.WmiCalls [ff2246f1-04bc-4451-9e40-6aa1efb94073] - End of service test

Answer 3

Эта функция пригодится, когда вам нужно просмотреть много журналов. Когда у вас будет много журналов? Диагностика странной ошибки в производственной системе с чередованием выходных данных. Наличие большего количества контекстов дает вам возможность фильтровать вывод или не выводить ненужные журналы.

В другом случае вложенные контексты могут быть полезны, если метод или некоторая функция вызывается несколько раз в разных контекстах, и вам нужен способ различать их.

Answer 4

NDC.Push был объявлен устаревшим Предпочтительный способ сейчас (ThreadContext.Stacks["NDC"]) это:

var disposable = ThreadContext.Stacks["NDC"].Push("context");
try
{
  Log.Info("begin"); // optional, but nice
  ...
}
finally
{
  Log.Info("end"); // optional, but nice
  disposable.Dispose();
}

Не забудьте проверить свой шаблон конверсии, чтобы он включал %property{NDC}:

<layout type="log4net.Layout.PatternLayout">
  <conversionPattern
    value="%date [%2thread] %-5level [%property{NDC}] - %.10240message%newline" />
</layout>