.net - net - ¿Cuándo usar ''contexto de diagnóstico anidado''(NDC)?

log4net xmlconfigurator

Question

Al jugar con log4net, he visto la posibilidad de usar una pila de etiquetas de contexto por hilo llamada NDC.

Las etiquetas presionadas en esta pila se muestran en un PatternLayout especificando el %x o el parámetro de formato %ndc .

El uso es algo así como:

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"); 

La salida es algo así como:

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

En su experiencia de programación con log4net, ¿cuándo encontró útil esta función?

Answer 1

¿Quieres un ejemplo?

Tome la siguiente API web escrita usando 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";
}

Cuando se realizan solicitudes HTTP concurrentes del servidor, el registro puede entrelazarse. P.ej

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

En este ejemplo simple, puede usar el Id. De subproceso para distinguir las solicitudes, pero puede ser complicado a medida que el archivo de registro crece en complejidad.

Una mejor alternativa es proporcionar identificadores únicos que agrupen los mensajes de registro para la misma solicitud. Podemos actualizar el código de la siguiente manera:

// 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";
    }
}

Esto produce un registro que puede grep para ver los problemas asociados con una solicitud específica. P.ej

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 2

En una aplicación de servidor como ASP.NET.

Por ejemplo, puede enviar información sobre la solicitud actual al NDC.

Answer 3

Estas características son útiles cuando tienes muchos registros por recorrer. ¿Cuándo tendrías muchos registros? Diagnóstico de errores extraños en un sistema de producción con salidas de entrelazado. Tener más contextos le permite filtrar el resultado o no generar registros innecesarios.

Otro caso de contextos anidados podría ser útil si un método o una característica se llama varias veces en diferentes contextos y necesita una forma de distinguirlos.

Answer 4

NDC.Push ha quedado obsoleto. La forma preferida ahora ( ThreadContext.Stacks["NDC"] ) es esta:

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

Recuerde verificar su patrón de conversión para que incluya %property{NDC} :

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