良好的日志记录带来幸福

• 下载源代码 - 1.53 MB

引言

在某种程度上，当你发现一个错误已经传递到测试人员手中，甚至更糟，进入了生产环境时，对其进行故障排除可能会非常具有挑战性。本文介绍了一种异常处理和日志记录的方法，该方法非常简单但有效地利用了Enterprise Library，并添加了一些自定义代码来进一步提升其能力。作为一项附加功能，我还将介绍一种可以使用此相同方法来完成性能日志记录的方法！对于真正好奇的人来说，还有额外的奖励：创建一个Prism日志记录器（实现ILoggerFacade）非常容易，它只需调用SuperLogger即可提供您在下面看到的所有相同价值。如果您想了解这一点，请通过评论或电子邮件与我联系。

目标

在解决良好日志记录和异常处理实践的问题时，我想牢记几个基本目标（您可以查看这些目标，看看是否想继续阅读）。

• 拥有出色的日志记录**以及**出色的日志搜索/审查能力。
• 日志的最终位置将是数据库，以便轻松搜索和报告日志。
• 将代码中的日志记录到消息队列，以在Ent Lib中实现尽可能接近异步的功能。
• 为开发人员提供一个非常简单的框架，让他们在不费太多力气的情况下创建良好、完整的日志条目，并且不必担心各种EntLib引用或其工作原理。
• 能够跨越层边界（客户端/服务器等）隐藏异常详细信息，同时提供一种关联跨边界错误的好方法。
• 不要自己编写日志基础结构 - 利用现有框架 - 在本例中是Enterprise Library。
• 确保无法记录到消息队列或数据库的错误仍然能够被记录到某个地方。

**注意**：在下面的解决方案中，我根本没有使用EntLib ExceptionHandling块。如果您有复杂的处理和隐藏规则，此解决方案可能不适合您。

日志记录设置说明

此框架的**很大一部分**是基于配置的，并且在我下面布局的设置中，您可以进行许多不同的决策。尽可能地，我将突出这些选项并解释我做出这些决定的原因。您可以采纳，也可以放弃。

如果您已经设置了Enterprise Library数据库日志记录和消息队列，那么您的大部分设置部分都可以跳过。

Enterprise Library设置

本节将介绍Enterprise Library、消息队列、日志数据库和分发器服务的设置。我不会非常详细地介绍每一个步骤；相反，我将重点介绍一些特定点，并提供在EntLib或其他文档中查找相关信息的位置。

1. 如果还没有，请获取并安装最新版本的Enterprise Library。
2. 使用提供的脚本创建日志数据库对象。注意：您实际上只需要遵循此页面上的说明1和2。注意：这是一个我进行了一些自定义的区域，我在下面的**数据库自定义**部分解释了这些自定义。
3. 在您的机器上创建一个名为“superLogger”的私有消息队列。您可以使用此TechNet页面作为参考。
4. 安装msmqDistributor服务。要执行此操作，请按照EntLib“使用分发器服务”页面上的步骤4、5和6进行操作。**注意**：步骤4要求您手动编辑msmqDistributor.exe.config文件以指定消息队列的名称。请确保使用上面步骤中提到的名称！
5. 将附加解决方案中的msmqDistributor.exe.config文件复制到您上面安装msmqDistributor.exe服务的目录中的同名文件上。修改日志数据库连接属性，以匹配您上面第1步中的数据库信息。**注意**：如果您重命名了或为WriteLog或AddCategory项提供了不同的存储过程，您需要在Super Database Log目标侦听器部分更新相应的值。
6. 启动（或重新启动）Super Logger Distributor Service（EntLib）。您可以在控制面板的“服务”部分找到它。

完成上述设置后，您应该会有一个正在等待消息的消息队列，并且您应该有一个正在运行的服务，它将等待处理您放入其中的任何消息！

配置和设置说明

数据库自定义

在SuperLogger的实现中，我想在Log数据库表中添加几个自定义列，并使用我们已经拥有的数据库。我选择了以下自定义：

• 将所有对象放在现有数据库中的“EntLib”架构下，而不是拥有单独的日志数据库。
• 为UserName、ErrorId（以支持异常隐藏）和PartitionNum（一个数字标识符，用于表示我们如何分割处理工作）添加自定义列。
• 使用自定义插入存储过程来填充所有列，包括最初创建的列和我的新自定义列。
• 修改插入过程以更改格式化的消息，排除我们已经在日志表中其他地方记录的属性，以减少日志条目的混乱。

在附加代码中，我将msmqDistributor.exe.config文件（这是唯一包含数据库信息的​​文件，因为它也是唯一可以将日志写入数据库的文件）中的所有设置还原为Ent Lib随附的设置，除了以下几项：

• 日志数据库条目的数据库连接信息。
• 用于Database Perf Log侦听器的WriteLog proc（此proc定义上不能与标准日志的WriteLog proc相同）。有关性能日志记录的更多信息，请参阅下文。

我版本的WriteLog proc，用于执行我数据库自定义中的项目3和4，位于附加代码的StoredProcedures文件夹中。如果您想使用类似的东西，请随意使用 - 只需确保更新Super Database Log侦听器中的WriteLog设置。

分发器服务说明

当您将msmqDistributor.exe安装为服务时，它会“记住”它被安装的位置。它将始终从那里运行。如果您想卸载它，原始可执行文件仍然需要位于它被安装的位置。

config文件中的msmqDistributorSettings节点无法通过方便的Ent Lib Configuration Application Block Console进行编辑。它有一个serviceName属性，该属性定义了服务在服务列表中显示时的名称。您可以随时更改。

<msmqDistributorSettings
  msmqPath=".\Private$\superLogger"
  queueTimerInterval="1000"
  serviceName="Super Logger Distributor Service (EntLib)" />

关于分发器服务的最后一个说明是，您可以运行多个服务版本，只要它们是从不同目录安装的，并且名称不同。

日志记录配置

日志记录配置有两个方面 - 一方面是代码如何将日志记录到消息队列（EntLib.config），另一方面是分发器服务如何处理这些日志（msmqDistributor.exe.config）。

代码中的日志记录配置

我在这里采用了一种非常简单的方法 - 创建一个“General”类别，并将其设置为所有内容的默认类别。将其发送到消息队列。将“Unprocessed”特殊类别发送到消息队列。然后将日志错误和警告发送到事件查看器侦听器。请参见下图，这是在Ent Lib配置工具中看到的配置的屏幕截图。

分发器服务日志记录配置

同样，我采取了一种非常简单的方法：将“Unprocessed”特殊类别发送到数据库。任何特殊处理的类别，例如“Performance”，都可以根据您的喜好发送到任何地方。与代码配置一样，将日志错误和警告发送到事件查看器侦听器。屏幕截图如下，供参考。

通过评论或解释，我希望能够创建额外的类别（在我下面的代码中，这基本上是通过一个枚举完成的），而无需重新配置日志记录的任何方面。默认情况下，我希望通过标准的日志记录机制将所有内容都记录到数据库。这种默认行为是通过“Unprocessed”类别实现的 - 即，“当我没有指定将它放在哪里时，就把它放在这里”。在更罕见和特殊的情况下，我可能想写入文件和/或不同的位置。在这种情况下，我们可以更新**任一**方面的配置 - msmqDistributor.exe.config或EntLib.config以实现我们的目标。更新EntLib.config将任何特定类别发送到其他地方，也意味着“其他地方”将同步（并且可能缓慢）写入该侦听器。

日志记录代码

第一个可能出现的问题是“为什么还要包装EntLib代码？”这个问题当然也出现在我身上。在我看来，一个相关的因素是，我们有许多开发人员共享一些通用的库函数。因此，我很快意识到我希望包装EntLib代码有几个原因：

• 我不想看到我们每个开发人员调用Enterprise Library的方式都不一样。
• 我不想让开发人员为如何实例化EntLib和担心其配置而烦恼。
• 我想限制可用的重载数量，并为他们提供一些标准类别。
• 我想注入一些通用信息，并比开箱即用的Ent Lib代码更好地控制异常的格式。

您可能首先感兴趣的代码是定义日志记录类别的枚举。请注意，根据上面的配置，**任何**类别都可以添加，并将记录到标准的数据库表中。

public enum SuperLoggingCategory
{
    // Customize these categories however you like 
    Batch,
    ConsoleApp,
    UserInterface,
    WcfService,
    Website,        
    Library,
    Diagnostic,
    Performance,
    WinService,
    General
}

您可以自己查看代码（SuperLogger.cs文件不到200行），但日志记录的一些“秘方”在于格式化异常消息的函数，如下所示。代码的关键特性：

• 日志条目的“标题” - 它在数据库中的Log表上将有自己的列 - 要么是抛出异常的方法名，要么是存储过程名，如果它是StoredProcedureException的话。这个小技巧使我们能够报告哪些方法/存储过程遇到了最多的问题 - 也就是说，创建一个“狗屋”。
• 将异常中的所有可能信息转储到日志中。转储标准异常属性，然后使用反射查看是否有其他可用属性。
• 使用递归以相同的方式格式化内部异常详细信息，并且每个内部异常都缩进一个制表符（每个级别）。这确保我们包含应用程序正在抛出的**所有**异常的**所有**详细信息。

**注意**：如果您有一些调用存储过程的低级代码，最好捕获SqlException并将其包装在StoredProcException中，以注入一些参数信息。只是随便说一句。

private static string FormatExceptionMessage(Exception exception, 
    ref string title, out string summary, string prepend = "\t")
{
    var exceptionMessage = new StringBuilder();

    var spe = exception as StoredProcException;
    if (string.IsNullOrEmpty(title))
    {
        title = spe != null ? spe.StoredProcName : exception.TargetSite.Name;
    }

    exceptionMessage.Append("\n" + prepend + "Exception:" + exception.GetType());
    exceptionMessage.Append("\n" + prepend + "Message:" + exception.Message);
    summary = exception.Message;

    exceptionMessage.Append(GetOtherExceptionProperties(exception, "\n" + prepend));

    exceptionMessage.Append("\n" + prepend + "Source:" + exception.Source);
    exceptionMessage.Append("\n" + prepend + "StackTrace:" + exception.StackTrace);
    if (exception.InnerException != null)
        exceptionMessage.Append("\n" + prepend + "InnerException: " +
                                FormatExceptionMessage(exception.InnerException, 
                                ref title, out summary, prepend + "\t"));

    return exceptionMessage.ToString();
}

private static string GetOtherExceptionProperties(Exception exception, string s)
{
    var allOtherProps = new StringBuilder();
    var exPropList = exception.GetType().GetProperties();

    var propertiesAlreadyHandled = new List<string> { "StackTrace", "Message", 
        "InnerException", "Data", "HelpLink", "Source", "TargetSite" };
    foreach (var prop in exPropList.Where(prop => !propertiesAlreadyHandled.Contains(prop.Name)))
    {
        allOtherProps.Append(s + string.Format("{0} : {1}", prop.Name, 
          exception.GetType().GetProperty(prop.Name).GetValue(exception, null)));
    }

    return allOtherProps.ToString();
}

异常隐藏，或跨层处理

对上述日志记录的一个相对简单的扩展使我们能够提供一种机制，允许应用程序代码将异常详细信息从调用层隐藏起来，同时保留关联这些项的能力。

在以下代码中，我们接收一个传入的异常（来自较低层，如Wcf服务或类似的东西），为其注入一个GUID，记录它 - **所有**详细信息，然后将一个带有GUID和抛出异常的方法名的字符串返回给调用者，调用者可以将其注入到一个新的异常中（例如FaultException）。我将在“编写应用程序代码”部分展示一个层两侧的示例代码。

public static string Handle(Exception ex, SuperLoggingCategory category, Dictionary<string, object> dict)
{
    var handlingInstance = Guid.NewGuid().ToString();
    dict.Add("ErrorId", handlingInstance);
    SuperLogger.WriteLog(ex, category, dict);
    return string.Format("An error occurred inside the service call [{0}]. --> ErrorId: {1}", 
                         ex.TargetSite.Name, handlingInstance);
}

性能日志记录

基于已创建的基础结构，我们可以非常简单地对其进行扩展，以记录更多自定义信息！为此，我们需要一个PerfLog表（同样，我希望将信息记录到表中以供报告），一个存储过程，以及一点点代码。

表信息和存储过程在附加的zip文件中 - 您只需要在您的日志数据库中提升该表和存储过程，并确保msmqDistributor.exe.config文件的Performance类别和侦听器配置正确。

完成之后，请考虑下面的代码。它定义了启动性能跟踪的构造函数。您为其提供一个名称（例如，“CustomerSearch”），并可选择提供一个影响性能跟踪的参数字典（例如，通配符搜索可能比基于键的搜索花费更多时间）。然后，Stop方法使用标准的日志记录器调用来记录所有内容！

public PerfLogger(string name)
{
    _sw = Stopwatch.StartNew();
    PerfName = name;
    _beginTime = DateTime.Now;
    _details = new Dictionary<string, object>();
}

public PerfLogger(string name, Dictionary<string, object> perfParams) : this(name)
{
    foreach (var item in perfParams)
        _details.Add("input-" + item.Key, item.Value);
}

public void Stop()
{
    _sw.Stop();
    _details.Add("Started", _beginTime.ToString(CultureInfo.InvariantCulture));
    _details.Add("ElapsedMilliseconds", _sw.ElapsedMilliseconds.ToString(CultureInfo.InvariantCulture));
    _details.Add("PerfName", PerfName);

    SuperLogger.WriteLog("Performance captured for " + PerfName, 
                         SuperLoggingCategory.Performance, _details);
}

编写应用程序代码

这就是它变得非常酷的地方。调用SuperLogger.WriteLog函数的代码非常简单。对于以下所有内容，您都需要对SuperLogger的引用以及CustomLogging的using语句。附加源代码中的ConsoleAppExample提供了一些可行的示例。

仅记录一条消息（带有或不带类别）

SuperLogger.WriteLog("Just because....");
    // will go to the General category since one has not been specified.

记录捕获的异常，其中一个名为currCustId的变量将有助于对该问题进行故障排除。

**关于何时捕获异常的编辑旁注**：仅当您需要时。这个答案可能看起来有点陈词滥调，但我*确实*花了一些时间来思考它。在控制台应用程序中，您可能应该在main函数中有一个。在WCF服务库中，您可能应该在OperationContract方法的函数中有一个。在UI（包括Web内容）中，您可能应该有一个全局异常处理程序，因为很难确保所有可能抛出异常的小地方都被捕获并且不会导致UI崩溃。除此之外，这取决于您何时可以*为异常增加价值*。这取决于以下两个方面之一：

• **删除详细信息**。当您需要在层边界执行隐藏时，就是这种情况。
• **添加详细信息**。我认为最佳实践是抛出一个新异常，同时将原始异常包含为内部异常。我的经验让我考虑在何时添加详细信息（包装）异常时，要关注两件事：（a）**存储过程参数**，以及（b）**函数输入参数**。如果您没有比调用堆栈更高层级的信息，请不要对异常进行任何操作。

catch (Exception ex)
{
    SuperLogger.WriteLog(ex, SuperLoggingCategory.Batch, 
          new Dictionary<string, object> { {"CustomerId", currCustId}});
}

记录较低层中的异常并隐藏来自上层的详细信息。

**注意**：我主要处理跨WCF层的隐藏。下面的WcfExceptionHandler（其Handle方法显示了上面的代码）可以轻松重命名为LayeredExceptionHandler或ExceptionSheilder。

catch (Exception ex)
{
    var fault = WcfExceptionHandler.Handle(ex);  /
    throw new FaultException(fault);
}

从上层捕获并记录相同的异常。

catch (FaultException ex)  // This will be a ThreadAbortException if you are doing async wcf calls
{
    SuperLogger.WriteLog(ex.Message, SuperLoggingCategory.UserInterface);
}

性能日志记录

var perfTracker = new PerfLogger("CustomerSearch", 
         new Dictionary<string, object> { { "CustomerID", customerId } } ;
// do customer search here....
perfTracker.Stop();

审查日志

创建日志条目并将其记录到数据库中非常棒，但拥有良好日志的有效性的一部分是使它们易于审查和访问。由于我的方法绝对有点“传统”，这绝对是您可以真正随心所欲的领域。我的主要观点是，它需要让人们（有时甚至是业务用户和/或测试人员！）轻松找到或审查日志，从而使您作为开发人员的工作更轻松。

我的方法有点过时，但仍然效果很好。基本上，我有一个Classic ASP页面提供了一个搜索日志的机制，然后是另一个页面，它实际执行给定的搜索并呈现日志详细信息。

如果您看一下下面的屏幕截图，您可以看到您可以多么快速地获得条目的“核心”内容。您可以看到InnerExceptions的缩进 - 并且请注意，我正在用黄色背景突出每个异常的消息属性。

如果您在某个地方运行了ASP服务器，您可以选择使用ClassicAspViewer文件夹中的文件作为日志查看器。该文件夹中的自述文件将帮助您入门。如果您没有，那您就只能自己想办法了，但也许屏幕截图会给您一些想法……

祝您日志记录愉快！！！

参考文献/来源

• Enterprise Library文档
• John Sonmez关于Enterprise Library日志记录的出色PluralSight课程（以及关于异常处理的课程）。
• Joe和Ben Albahari的C# In a Nutshell

历史

• v1.0 初始提交。
• v.1.01 修复了一些空引用问题，并将Exception.Data字段添加到递归异常格式化中。