【问题标题】:How to elegantly log contextual information along with every message如何优雅地记录上下文信息以及每条消息
【发布时间】:2013-01-17 00:27:19
【问题描述】:

我正在寻找有关日志记录的一些建议。我编写了一个名为Logger 的包装器,它在内部使用Microsoft Enterprise Library 5.0。目前它使我们能够以这种方式登录:

Logger.Error(LogCategory.Server, "Some message with some state {0}", state);

我面临的问题是,EventViewer 中的每个日志似乎都不相关,即使其中一些在某种程度上是相关的,例如它们都来自处理来自特定客户端的请求。 p>

让我详细说明这个问题。假设我正在开发一个需要同时处理来自多个客户端的请求的服务,每个客户端都将不同的参数集传递给服务方法。很少有参数可用于来识别请求,例如哪个客户端用what发出what类型的请求em> 唯一可识别的参数等。假设这些参数是(调用上下文信息):

  • ServerProfileId
  • WebProfileId
  • 请求 ID
  • 会话信息

现在服务开始处理请求,做一件又一件的事情(如工作流)。在此过程中,我正在记录本地1 消息,例如 “找不到文件”“在 DB 中找不到条目”,但我没有'不想手动在每个日志中记录上述信息(上下文信息),而是希望记录器在我每次记录本地消息时自动记录它们:

Logger.Error(LogCategory.Server, "requested file not found");

我希望上面的调用记录上下文信息以及消息“未找到请求的文件”,以便我可以将消息与其上下文相关联。

问题是,我应该如何设计这样一个自动记录上下文的记录器包装器?我希望它足够灵活,以便我可以在服务处理请求的过程中添加更多特定上下文信息,因为所有重要信息可能在中不可用请求的开始!

我还想让它可配置,所以我可以记录本地消息而不记录上下文信息,因为当一切正常时不需要它们。 :-)


1. local 消息是指更具体、更本地化的消息。相比之下,我会说,上下文信息是全局消息,因为它们对处理请求的整个流程有意义。

【问题讨论】:

标签: c# logging enterprise-library


【解决方案1】:

这是一种使用企业库的方法,该方法相当容易设置。您可以使用Activity Tracing 存储全局上下文,使用扩展属性存储本地上下文。

为了举例,我将使用没有任何包装类的服务定位器来演示该方法。

var traceManager = EnterpriseLibraryContainer.Current.GetInstance<TraceManager>();

using (var tracer1 = traceManager.StartTrace("MyRequestId=" + GetRequestId().ToString()))
using (var tracer2 = traceManager.StartTrace("ClientID=" + clientId))
{
    DoSomething();
}

static void DoSomething()
{
    var logWriter = EnterpriseLibraryContainer.Current.GetInstance<LogWriter>();
    logWriter.Write("doing something", "General");

    DoSomethingElse("ABC.txt");
}

static void DoSomethingElse(string fileName)
{
    var logWriter = EnterpriseLibraryContainer.Current.GetInstance<LogWriter>();

    // Oops need to log
    LogEntry logEntry = new LogEntry()
    {
        Categories = new string[] { "General" },
        Message = "requested file not found",
        ExtendedProperties = new Dictionary<string, object>() { { "filename", fileName } }
    };

    logWriter.Write(logEntry);
}

配置如下所示:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
    <configSections>
        <section name="loggingConfiguration" type="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.LoggingSettings, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.505.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" requirePermission="true" />
    </configSections>
    <loggingConfiguration name="" tracingEnabled="true" defaultCategory="General"
        logWarningsWhenNoCategoriesMatch="false">
        <listeners>
            <add name="Flat File Trace Listener" type="Microsoft.Practices.EnterpriseLibrary.Logging.TraceListeners.FlatFileTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.505.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
                listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.FlatFileTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.505.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
                fileName="trace.log" formatter="Text Formatter" traceOutputOptions="LogicalOperationStack" />
        </listeners>
        <formatters>
            <add type="Microsoft.Practices.EnterpriseLibrary.Logging.Formatters.TextFormatter, Microsoft.Practices.EnterpriseLibrary.Logging, Version=5.0.505.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
                template="Timestamp: {timestamp}&#xA;Message: {message}&#xA;ActivityID: {activity}&#xA;Context: {category}&#xA;Priority: {priority}&#xA;EventId: {eventid}&#xA;Severity: {severity}&#xA;Title:{title}&#xA;Machine: {localMachine}&#xA;App Domain: {localAppDomain}&#xA;ProcessId: {localProcessId}&#xA;Process Name: {localProcessName}&#xA;Thread Name: {threadName}&#xA;Win32 ThreadId:{win32ThreadId}&#xA;Local Context: {dictionary({key} - {value}{newline})}"
                name="Text Formatter" />
        </formatters>
        <categorySources>
            <add switchValue="All" name="General">
                <listeners>
                    <add name="Flat File Trace Listener" />
                </listeners>
            </add>
        </categorySources>
        <specialSources>
            <allEvents switchValue="All" name="All Events" />
            <notProcessed switchValue="All" name="Unprocessed Category" />
            <errors switchValue="All" name="Logging Errors &amp; Warnings" />
        </specialSources>
    </loggingConfiguration>
</configuration>

这将导致如下输出:

----------------------------------------
Timestamp: 1/16/2013 3:50:11 PM
Message: doing something
ActivityID: 5b765d8c-935a-445c-b9fb-bde4db73124f
Context: General, ClientID=123456, MyRequestId=8f2828be-44bf-436c-9e24-9641963db09a
Priority: -1
EventId: 1
Severity: Information
Title:
Machine: MACHINE
App Domain: LoggingTracerNDC.exe
ProcessId: 5320
Process Name: LoggingTracerNDC.exe
Thread Name: 
Win32 ThreadId:8472
Local Context: 
----------------------------------------
----------------------------------------
Timestamp: 1/16/2013 3:50:11 PM
Message: requested file not found
ActivityID: 5b765d8c-935a-445c-b9fb-bde4db73124f
Context: General, ClientID=123456, MyRequestId=8f2828be-44bf-436c-9e24-9641963db09a
Priority: -1
EventId: 0
Severity: Information
Title:
Machine: MACHINE
App Domain: LoggingTracerNDC.exe
ProcessId: 5320
Process Name: LoggingTracerNDC.exe
Thread Name: 
Win32 ThreadId:8472
Local Context: filename - ABC.txt

----------------------------------------

注意事项:

  • 由于我们使用跟踪,我们免费获得 .NET 活动 ID,可用于关联活动。当然,我们也可以使用自己的上下文信息(自定义请求 ID、客户端 ID 等)。
  • Enterprise Library 使用跟踪“操作名称”作为类别,因此我们需要设置 logWarningsWhenNoCategoriesMatch="false" 否则我们会收到一连串的警告消息。
  • 这种方法的一个缺点可能是性能(但我没有测量过)。

如果你想禁用全局上下文(在这个实现中是跟踪),那么你需要做的就是编辑配置文件并设置tracingEnabled="false"。

这似乎是使用内置企业库功能实现目标的一种相当直接的方法。

要考虑的其他方法可能是使用某种非常优雅的拦截(自定义 LogCallHandler)(但这可能取决于现有设计)。

如果您打算使用自定义实现来收集和管理上下文,那么您可以考虑使用Trace.CorrelationManager 来处理每个线程上下文。您还可以考虑创建一个IExtraInformationProvider 来填充扩展属性字典(参见Enterprise Library 3.1 Logging Formatter Template - Include URL Request 示例)。

【讨论】:

  • +1。伟大的。这有点接近我正在寻找的东西。它给了我很多想法。非常感谢。
  • 一个问题:EnterpriseLibraryContainer.Current 如何知道它应该返回哪个LogWriter 实例?它如何识别或找出它运行的上下文?它使用线程ID吗?如果我在另一个线程中运行 DoSomethingElse() 会怎样?
  • 实际的 LogWriter 实现类在容器中注册为 Singleton,因此您将始终获得相同的 LogWriter 实例;并发在内部处理。 Tracer 实际上在幕后使用 CorrelationManager,因此所有上下文信息都存储在线程绑定上下文中。每个线程都有自己的上下文。
  • 如果请求处理经常使用多线程(最常见的是在不同线程中运行的事件处理程序),我将如何使其工作?
  • 上下文信息将(应该)填充到在逻辑操作中创建的线程中。例如如果我将DoSomethingElse("ABC.txt"); 更改为ThreadPool.QueueUserWorkItem(new WaitCallback(DoSomethingElse), "ABC.txt");,输出将是相同的。有关线程示例,请参阅 CorrelationManager Class
【解决方案2】:

免责声明:我不知道微软技术栈的细节。

在这种情况下我会做的事情是:

实现一个 Singleton(在服务器实例级别,如果您的应用程序部署到集群,它不需要是全局单例),它基本上是一种 Hashmap,其中“Key”是唯一有意义的标识符请求您正在处理。 在 Java 中,我会使用线程 ID(假设您通过从线程池调度线程来服务请求)。 如果这在您的情况下不可能/没有意义,则必须使用请求 ID(但在这种情况下,您必须使其渗透到日志管理器,而我的想法是使用本质上可用的东西线程本身)。

Hashmap 的“值”将是一组数据——在你的情况下是 ServerProfileId、WebProfileId、RequestId(除非它已经是键)、SessionInfo——以便日志管理器可以有条件地检索这些数据并获取对特定的日志事件有意义。

所以:在请求管理开始时创建一个全局可用的请求状态引用,并确保日志管理器可以在需要时检索请求状态

当然,您必须确保正确管理 hashmap(通过在处理请求后删除状态)。

【讨论】:

  • 我正在考虑编写一个记录器,比如ContextualLogger,其实例将被传递给方法,并在此过程中使用上下文信息更新实例(以便可以使用消息记录它们)。通过这种方式,记录器不需要来自外部的任何东西。此外,我可以将一些LogContextProvider(实现ILogContextProvider)的实例注入ContexualLogger 的构造函数。 context-provider 将在记录器需要时提供重要的上下文,而 GC 将在我完成后收集它。听起来不错?
  • 如果在各个调用层中注入 ContextualLogger 的成本不太高,那么您的解决方案可能会更好(如果没有别的,您无需担心在请求时清理 Hashmap结束)。如果将额外信息作为方法的一部分传递太昂贵/太麻烦,我的解决方案会更好。
  • 这里的“成本”是什么意思?它与您的基本相同,只是我将传递记录器实例本身而不是某些 ID。所以我不必担心其他线程处理其他请求。你的解决方案本质上是多线程的,我的取决于我是否使用线程来处理请求。
  • 我同意传递 Request-id 或对象实例是相同的(基本上,您必须在您希望记录某些内容的所有方法调用中添加一个额外的参数),所以是的 -如果您不能使用像线程标识符这样的“隐式”ID,则成本相同,并且您的解决方案更好(更明确,更少像我的单例哈希图那样的“混乱”)。
  • 谢谢,这让我更有信心了。但我也在寻找可能的改进。我确定我不是第一个遇到这个问题的人,正在寻找更好的方法来记录所有相关消息。
猜你喜欢
  • 2016-03-09
  • 2019-09-23
  • 2020-06-26
  • 2015-11-16
  • 1970-01-01
  • 2013-06-30
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
相关资源
最近更新 更多