使用 IL 重写和 .NET 性能计数器 API 实现的真正简单的日志记录

• 下载源文件 - 92.25 KB

问题

我从来都不是在应用程序中编写日志记录的忠实粉丝。有几个原因。一、它在我的个人代码开发中从未真正有用。使用调试器或查看堆栈跟踪更容易。当然，在生产应用程序中，您无法使用调试器，而这正是拥有一些日志记录的地方。然而，这让我们来到了我不喜欢日志记录的第二个原因。似乎总是在应用程序出错的部分没有日志记录代码。当然，当这种情况发生时，没有简单的方法可以回去添加所需的日志记录代码。通常这需要重新编译并将此新临时版本重新安装在有问题的系统上……这并不是一个好情况。

想法

这让我思考，如果我能通过添加我需要的日志记录来修改生产代码来诊断问题，然后在我完成后删除添加的代码，那不是很好吗？很久以前，我偶然发现了一篇关于 .NET 代码性能计数器 API 和 IL 重写思想的文章。我稍后将深入探讨它的确切技术细节及其工作原理，但就目前而言，它的基本思想是，您可以在运行时，在汇编代码被编译成机器代码之前获取它，然后先重写代码（例如，添加一些日志记录）。

起点

理想情况下，我想能够做到的是记录每个方法的入口和出口点，记录它们进入和退出的时间，能够记录传递给方法的参数，并且能够在一个方法的各种点上输入特定的日志记录命令（例如“记录第二个 switch 语句后 x 的值”）。显然，这太多了，所以我认为我应该从第一个开始，即记录每个方法进入的时间以及进入的时间。

性能计数器 API

这一切都得益于内置于 .NET 运行时的 .NET 性能计数器 API。性能计数器 API 基本上是一组运行时钩子，您可以使用它们来了解应用程序运行时正在发生什么。它可以提供从垃圾回收到抛出的异常再到程序集/类/方法加载的信息。在我们的例子中，我们将使用最后一部分。具体来说，我们将使用 JITCompilationStarted 来查找即将被运行时编译成机器代码的代码，并首先添加我们的日志记录代码。

性能计数器 API 的一个问题是它必须实现为 COM 组件。乍一看，这似乎是一个奇怪的要求，但如果你稍微想一下，它的原因就清楚了。如果您的性能计数器是用 .NET 编写的，它会不断尝试对自身进行性能计数。

顺便说一句，还有一些方法可以挂钩，每次进入/退出方法时都会通知您。这些使用起来要容易得多。事实上，我的第一个尝试就是使用了这些方法，但我最终出于两个原因选择了 IL 重写路径。一、每次进入或退出方法时，.NET 运行时调用您的性能计数器代码都非常慢。二、这不能实现我最终在方法内的任何点添加更具体的日志记录代码的目标。

研究

与任何新的事业一样，我直接去了谷歌并开始了我的研究。我找到了一些关于这个主题的文章，但到目前为止最有帮助的是 Aleksandr Mikunov 的一篇。Aleksandr 很好地介绍了 IL 重写的基础知识，甚至包含了一些接近我想要做的示例代码。如果您想使用 IL 重写，您绝对应该阅读他的文章。

混乱的细节

所以，简而言之，IL 重写就是这样工作的。当您编译 .NET 代码（无论是 C# 还是 VB 还是其他什么）时，您的代码会被转换为称为中间语言或 IL 代码（看起来有点像汇编代码）。当您运行编译后的应用程序时，每次使用某个方法时，.NET 运行时会将 IL 代码转换为实际的机器代码。这被称为即时 (JIT) 编译。JIT 编译是您应用程序的每个部分第一次使用时运行速度更慢的原因。我们所做的就是当运行时即将将任何 IL 代码片段编译成机器代码时获得通知，并首先修改 IL 代码。在我们的例子中，我们在每个方法的开头插入一个对日志记录类的调用。

由于本文主要介绍 IL 重写，因此我只简要介绍外围程序集，然后更详细地解释实际处理重写的代码。Logger.Controller 程序集负责启动您想要进行性能计数分析的应用程序。它处理将 .NET Windows 应用程序或 ASP.NET 应用程序（Windows 服务即将推出……）连接到我们的性能计数器的所有细节。然后它打开一个远程通道来监听被日志记录的项目发出的回调。

Logger.Core 程序集包含一个 static log 方法。这是我们的 IL 重写器将添加到每个被性能计数分析的方法开头的调用。为了确保所有应用程序都能找到此程序集，它会在安装过程中（或者如果您正在编译源代码，则在生成后过程中）注册到 GAC。

解决方案中的其他项目是

• Logger.Common：定义用于远程处理的接口
• Logger.Gui：操作 Logger.Controller 的图形用户界面
• Logger.Profiler 和 Logger.ProfilerPS：.NET 性能计数器 API 的 C++ COM 实现。这是应用程序的核心。
• TestApplication：一个简单的测试工具
• Logger：安装包

代码

为了本文的篇幅，我将把代码解释限制在 Logger.Profiler 项目。Logger.Profiler 是一个实现了 .NET 性能计数器 API 的 C++ COM 组件。我们讨论的真正切入点是 Profiler 类中 JITCompilationStarted 的实现。它看起来是这样的

HRESULT Profiler::JITCompilationStarted(FunctionID functionID, BOOL fIsSafeToBlock) 
{ 
  FunctionInfo* functionInfo = 
        FunctionInfo::CreateFunctionInfo(profilerInfo, functionID); 
  if (NULL == functionInfo) { return S_OK; } 

  ILWriterBase *ilWriter = ILWriterBase::CreateILWriter(profilerInfo, functionInfo); 
  if(ilWriter->CanRewrite()) 
  { 
    Check(profilerInfo->SetILFunctionBody(functionInfo->GetModuleID(), 
                         functionInfo->GetToken(), (LPCBYTE)ilWriter->GetNewILBytes())); 
  } 

  return S_OK; 
} 

第一行是对 FunctionInfo 类上的 static 方法 CreateFunctionInfo 的调用。CreateFunctionInfo 实际上是一个工厂方法，它返回一个 FunctionInfo 类（包含有关即将 JIT 编译的函数签名的所有信息），或者在不应进行性能计数分析时返回 NULL。

下一个代码块以调用另一个工厂方法 CreateILWriter 开头。此方法返回 ILWriterBase 类的三个具体实现之一。原因是 IL 函数有两种不同的格式：tiny 和 fat。基本上，tiny 方法格式用于不带任何参数的非常小的方法，而 fat 格式用于所有其他方法。这些格式中的每一种都需要略有不同的 IL 重写方法。

此时，您可能正在心中计算……等等，有两种 IL 函数格式，但有三种 ILWriterBase 实现。原因是我们在修改 IL 时遇到了三种情况：需要重写 fat 函数、需要重写 tiny 函数，以及需要将 tiny 格式转换为 fat 函数，因为添加的代码使重写后的函数很大。

JITCompilationStarted 所做的最后一件事是调用我们通过在 Initialize 中查询接口获得的性能计数引擎 ICorProfilerInfo 引用的 SetILFunctionBody。我们通过调用我们调用 CreateILWriter 时获得的 ILWriterBase 实现的 GetNewILBytes 来获取要传递给此调用的 IL。这是代码

void *ILWriterBase::GetNewILBytes() 
{ 
  void* newMethodBytes = AllocateNewMethodBody(functionInfo); 
  
  WriteHeader(newMethodBytes); 
  WriteNewIL(newMethodBytes); 
  WriteOldIL(newMethodBytes); 
  WriteExtra(newMethodBytes); 
  
  Diagnostics::GetInstance()->PrintIL((BYTE*)GetOldMethodBytes(), GetOldMethodSize()); 
  Diagnostics::GetInstance()->PrintIL((BYTE*)newMethodBytes, GetNewMethodSize()); 

  return newMethodBytes; 
} 

我们首先使用 AllocateNewMethodBody 创建新代码的空间，它使用 ICorProfilerInfo 的 GetILFunctionBodyAllocator 函数为我们获取指向为新函数分配的内存的指针。然后我们开始编写标头信息。“标头”基本上是方法的一些元数据。WriteHeader 是一个纯抽象方法，因为 fat 和 tiny 格式的标头编写方式完全不同。然后，我们通过调用 WriteNewIL 写入对我们日志方法的调用，该方法简单地使用 memcpy 将新 IL 的字节直接复制到标头信息之后。接下来，我们通过调用 WriteOldIL 写入原始字节，再次使用 memcpy 将旧函数体直接复制到我们的新 IL 指令之后。最后，我们调用 WriteExtra。WriteExtra 仅由 FatILWriter 实现，用于写入原始函数中的任何 try/catch 块信息。它还更新了 catch 处理程序的 **位置，我将不在此详细介绍。有关更多信息，请参阅上面引用的 Aleksandr Mikunov 的文章。

就这样。此时，我们的代码退出，.NET 运行时将我们修改后的 IL 代码（包括我们的日志调用）编译成机器代码。

总结

我意识到这只是对正在发生的事情的 30,000 英尺的概览，但这有点是故意的。首先，我关于 IL 重写是什么以及它如何工作的绝大部分知识都来自 Aleksandr Mikunov 的文章，在此重述无异于抄袭。其次，我一直非常努力地编写“自文档化”的代码。我个人宁愿看编写良好的源代码也不愿看文档。我希望我提供的是合理的、编写良好的源代码，可以帮助您开始编写自己的 IL 重写。

下一步

我希望我提供的内容实际上是一个有用的工具的开端，但我承认，就目前而言，它的价值有限。下一步是记录代码的退出点。这涉及更多的工作，但我认为它正在朝着正确的方向发展。那样的话，这实际上就变成了一个性能相当不错的性能调优工具。我用过市面上的一些工具，它们工作得非常好，但性能非常慢。我相信我见过的所有工具都在使用我之前提到的 COM 回调方法。

最后一步是实际允许用户在应用程序的任何点插入他们想要的任何自定义代码。例如，想象一下能够实际修改类 MyClass 中的方法 MyMethod，以便在不重新编译和重新安装的情况下，在实时系统中每调用代码四次时记录 MyProperty 的值。