何时使用“嵌套诊断上下文”(NDC)?

使用log4net,我已经看到了使用称为NDC的每线程堆栈上下文标签的可能性。

通过指定%x%ndc格式参数,在此堆栈上推送的标签将显示在PatternLayout中。

用法是这样的:

 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的编程经验中,你什么时候发现这个function是有用的?

在一个服务器应用程序,如ASP.NET。

例如,您可以将关于当前请求的信息推送到NDC。

想要一个例子吗?

以下使用ASP.NET MVC4编写的Web API:

 // 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 

在这个简单的例子中,可以使用线程ID来区分请求,但随着日志文件复杂度的增加,这可能会变得棘手。

更好的select是提供唯一标识符,将相同请求的日志消息分组在一起。 我们可以更新代码如下:

 // 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 

当有大量日志需要通过时,这些function会派上用场。 你什么时候有很多的日志? 用交错输出诊断生产系统上的奇怪错误。 有更多的上下文给你的方式来过滤输出或不输出不需要的日志。

另一种情况嵌套上下文可能是有用的,如果一个方法或某些function在不同的上下文中被调用多次,你需要一种方法来区分它们。