2024-03-05 / Windows / 425浏览

ETW：Windows 事件追踪 101

ETW 是什么

Event Tracing for Windows® (ETW) is a general-purpose, high-speed tracing facility provided by the operating system. Using a buffering and logging mechanism implemented in the kernel, ETW provides a tracing mechanism for events raised by both user-mode applications and kernel-mode device drivers.

ETW 具有以下特征：

开发人员可以根据预期用途选择合适的实现集（例如，很容易添加像 WPP 实现这样的 Printf，以用于调试目的的事件）。
基础结构管理常用信息，如时间戳、函数名称和源文件行号。
相同的实现用于用户模式应用和内核模式组件。
ETW 可在故障转储和实时调试中进行访问。
ETW 可以被重定向到内核调试器以进行实时查看。
ETW 具有实时视图。
日志文件保存在二进制日志文件（ETL 文件）中。
ETW 支持多进程日志记录。
ETW 具有高吞吐量。
可以在另一台计算机上查看日志文件。
ETW 支持循环缓冲，以实现持续日志记录和监视。
ETW 可以根据目标受众分组到一个通道中。

那我们接下来看看 ETW 是怎么做到这些点的以及我们可以怎么用。首先我们来看看 ETW 的整体架构：

整体架构

总体来说就是：

有一个应用，在做一些事情的时候想记录一下日志，你就可以通过注册一个 provider 来将日志写入 ETW，并向任何请求监听日志的消费者提供信息。

而消费者，则必须启动【会话跟踪】，才能与 provider 交互或者使用 provider 提供的服务。

作为回话，则需要捕获所有指定 provider 提供的信息。

而这些都是由 controller 来控制的。

接下来，我们就来详细的说说具体的模块。

Controller：控制器

所谓 controller，顾名思义，就是用来控制 ETW 的一切。从启动、停止追踪，到启用、禁用特定 provider 的追踪。常用到的一个控制器就是 logman（一款内置的命令行工具）

https://learn.microsoft.com/zh-cn/windows-server/administration/windows-commands/logman

Provider：提供商

提供程序负责生成事件并将其写入 ETW 会话。应用程序可以注册 ETW 提供程序，并根据需要写入任意数量的事件。ETW 支持四种类型的提供程序：

MOF Providers
WPP providers
Manifest-based providers
TraceLogging providers

常见的 provider 有：

Windows 上，所有已注册的 ETW 提供程序都可以从如下注册表中找到：

HKLMSOFTWAREMicrosoftWindowsCurrentVersionWINEVTPublishers

Consumer：消费者

消费者是选择一个或多个事件跟踪会话作为事件源的应用程序。消费者可同时请求多个事件跟踪会话中的事件；系统会按时间顺序交付事件。消费者可以接收存储在日志文件中的事件，也可以从实时提供事件的会话中接收事件。

最常用到的消费者就是事件查看器、性能监听器

为什么要学 ETW

分析系统行为

分析系统行为可分为两大类：

系统出现问题，可以通过事件查看器等工具查看具体问题和原因。以此来排查各类问题。比如系统提供了 App Error、App hang 等日志可以用来查看应用崩溃和卡死的问题；系统提供了 WMI、COM 相关的 provider 可以用来排查 WMI 和 COM 通信相关的问题。
应用/系统性能影响因素排查。通过结合 WPT 捕获当前系统环境和应用运行情况，可以根据某一瞬间的状况，确定是什么原因直接影响到的。比如：可以通过 WPT 排查开机速度较慢的问题。
分析系统组件或者应用的运行机制。

给应用提供一种更完备的日志系统

通常情况下，在开发环境下，我们会采取控制台打印的方式记录日志；正式环境下，我们会通过日志文件来记录日常情况。但这两种方式都存在一定的弊端，控制台打印你得是个控制台吧；文件记录是一个非格式文件，只能通过约定特定的字符串来查看日志，无法方便的消费（查看、过滤、收集等）

而 ETW 则可以通过扩展字段的方式，将日志形成格式化文件；按需对不同类型的日志进行保存文件式存储还是实时输出；同时保持最佳性能。

详细的可以参看这个视频：

怎么用 ETW

这里主要强调作为消费者来使用 ETW。

作为消费者

作为消费者，也就是使用各种 provider 提供的服务。首先，我们就得学会怎么看，也就是得知道 provider 提供了什么，各种字段表示什么意思。

1.1 XML 清单文件解析

结合 etw 的清单文件一起来看：

https://github.com/nasbench/EVTX-ETW-Resources/blob/main/ETWProvidersManifests/Windows11/22H2/W11_22H2_Pro_20221018_22621.674/WEPExplorer/Microsoft-Windows-Windows%20Defender.xml

<provider>

最上层元素便是<provider>了，它可以用于识别提供者。通常，与之关联的属性有如下几个：

Name：顾名思义，就是 provider 的名字
Guid：标识 provider 的唯一标识
ResourceFilePath：包含元数据的 EXE/DLL 的路径
MessageFilePath：包含消息资源的 EXE/DLL 的路径
ParameterFilePath：包含提供者字符串资源的 EXE/DLL 的路径

此元素主要提供一些用于识别提供者或者翻译提供者提供事件所需的元数据和字符串。

<channels>

此元素用于定义和配置事件跟踪会话中的事件通道，通过不同的 channel 来配置不同通道的访问权限、保留情况以及事件的存储位置等。

<Channels>
    <Channel>
        <Message></Message>
        <Path>Microsoft-Windows-Windows Defender/Operational</Path>
        <Index>0</Index>
        <Id>16</Id>
        <Imported>false</Imported>
    </Channel>
    <Channel>
        <Message></Message>
        <Path>Microsoft-Windows-Windows Defender/WHC</Path>
        <Index>1</Index>
        <Id>17</Id>
        <Imported>false</Imported>
    </Channel>
</Channels>

如上，定义了两个通道 Operational 和 WHC。

通常 channel 包含四种类型：

Admin：这些通道记录重要的系统或应用程序事件，通常是需要管理员立即注意的
Operational：这是用于记录那些对系统管理员有用的事件的通道。这些事件通常用于常规的系统监控、问题诊断和维护操作
Analytic：这是用于记录那些对系统管理员有用的事件的通道。这些事件通常用于常规的系统监控、问题诊断和维护操作
Debug：这些是用于记录调试目的的事件，通常只有在开发或详细故障排除时才会启用

在事件查看器中显示如下：

<levels>

levels 用于定义日志的级别，并提供根据不同级别对事件分组的能力（方便消费者筛选、过滤）。

最常用的级别包括以下几种：

win:Critical (1)
win:Error (2)
win:Warning (3)
win:Informational (4)
win:Verbose (5)

除了上述系统预定义的级别（1~5）和系统保留级别（6~15），提供者也可以自定义级别类型。

<tasks> & <opcodes>

Tasks 和 opcodes 主要用来方便消费者根据任务和操作对事件进行分类。

Tasks 和 opcodes 共同描述事件的操作。但 task 和 opcode 存在一些区别：

一个 task 代表了事件的一个更高级别的分组，通常对应于应用程序的一个组件或者一个特定的功能区域
opcode 代表了事件本身的操作代码，提供了关于事件行为的更具体的信息。

tasks 和 opcodes 通常是组合使用的，以提供关于一个事件的完整描述。例如，如果你有一个网络请求的 task，你可能会有多个与之相关的 opcodes，如 connect、disconnect、send、receive 等，每个 opcode 都代表任务中的一个步骤。

例如：Task 都为 CacheCheck，但具体下来，opcode 则可以分为 start 和 stop

一些预定义的操作码可以从下面这个链接中找到：

https://learn.microsoft.com/en-us/windows/win32/wes/eventmanifestschema-opcodetype-complextype

<keywords>

与 levels 和 task 类似，keyword 也被用于消费者筛选。keyboard 有关的主要有如下几个属性：

message：描述关键词的字符串
name：关键词的名称
mask：必须只设置一位的掩码，用于高级过滤。

在跟踪会话的时候，会看到 Keyword(Any) 和 Keyword(All) 两种类型的关键词掩码来启用提供者。如下图：

Keyword (Any)：通过指定一个8字节的十六进制位掩码，代表一个或者多个关键字
Keyword (All)：一个可选的8字节十六进制位掩码，用于进一步限制ETW事件提供者写入的事件类别

具体的我们用一个例子来说明：

我们有三个关键字：

<maps>

如下是一段来自 Microsoft-Windows-Kernel-Process 的 maps：

<maps>
  <bitMap name="ProcessFlags">
    <map value="0x1" message="$(string.map_ProcessFlagsPackageId)" />
  </bitMap>
  <bitMap name="SecurityMitigationsMap">
    <map value="0x0" message="$(string.map_SecurityMitigationsMapNone)" />
    <map value="0x1" message="$(string.map_SecurityMitigationsMapHSP Shadow Stacks in compatibility mode)" />
    <map value="0x2" message="$(string.map_SecurityMitigationsMapHSP Shadow Stacks in strict mode)" />
    <map value="0x4" message="$(string.map_SecurityMitigationsMapHSP Shadow Stacks in compatibility mode (audit mode))" />
    <map value="0x8" message="$(string.map_SecurityMitigationsMapHSP Shadow Stacks in strict mode (audit mode))" />
  </bitMap>
</maps>

Maps 简单的定义了一个值和一个字符串之间的关系，主要用在解析事件时用作翻译机制。

<templates>

顾名思义，templates 就是作为一个模板来描述 provider。

这样比较抽象，我们还是借用一个例子来说明：

在 Microsoft-Windows-Kernel-Process 这个 provider 中的 event id 为 1 的事件中，包含了如下一段 message（也就是用来表述 event 的）：

Process %1 started at time %2 by parent %3 running in session %4 with name %5.

其中包含 %1 ~ %5 5个占位符，其对应的模板是：

<template tid="ProcessStartArgs">
    <data name="ProcessID" inType="win:UInt32" />
    <data name="CreateTime" inType="win:FILETIME" />
    <data name="ParentProcessID" inType="win:UInt32" />
    <data name="SessionID" inType="win:UInt32" />
    <data name="ImageName" inType="win:UnicodeString" />
</template>

于是，就可以得出结论：

%1 就是 ProcessID，%2 就是 CreateTime， %3 是 ParentProcessID， %4 是 SessionID，%5 是 ImageName。

<event>

Event 是我们 provider 中最重要的字段。接下来我们就来看看 event 是怎么定义的：

<Event>
    <Id>1</Id>
    <Version>0</Version>
    <Channel>Microsoft-Windows-Kernel-Process/Analytic</Channel>
    <Level>Information</Level>
    <Task>ProcessStart</Task>
    <Opcode>Start</Opcode>
    <Keyword>WINEVENT_KEYWORD_PROCESS</Keyword>
    <Message>Process %1 started at time %2 by parent %3 running in session %4 with name %5.></Message>
    <Template>ProcessStartArgs</Template>
</Event>

正如上述所见，Id(value) 就是我们在事件日志中 Event Id，通常表示一个事件。还有下面的 Channel、Level、Task、Opcode、Keyword 都是我们上面描述过的，用来过滤事件的属性。

Message 就是对应事件查看器中显示的 General 的那段字符串，通过 Template 来完善整个 message。

<localization>

最后一个就是 localization，这个是相当直接的，就是替换上述的一些根据国家、语言不同，显示不同的字符串为特定的字符串。

比如：

<localization>
    <resources culture="en-US">
      <stringTable>
        <string id="keyword_WINEVENT_KEYWORD_PROCESS" value="WINEVENT_KEYWORD_PROCESS" />
        <string id="keyword_WINEVENT_KEYWORD_THREAD" value="WINEVENT_KEYWORD_THREAD" />
        <string id="keyword_WINEVENT_KEYWORD_IMAGE" value="WINEVENT_KEYWORD_IMAGE" />
        ......
      </stringTable>
    </resources>
  </localization>

至此，就是清单文件的所有元素了。通过上述元素的解析，就可以简单了解这个 provider 提供了什么样的信息，是否能满足你的诉求。再根据特定的属性，在事件查看器或者其他工具中可以快速的找到你关心的事件。

1.2 追踪文件：Event Trace Logs(.etl)

一个会话中，可以通过实时查询 ETW 的数据，也可以将 ETW 的事件保存到本地文件中。

保存的文件就是 Event Trace Logs，一般用 .etl 作为后缀。

为保持高性能，.etl 文件采用二进制保存，无法直接通过文本的方式解析。所以需要采用特定的 API 或者工具来解析：

1.2.1 采用 API 来解析

可以通过 OpenTrace、ProcessTrace 和 CloseTrace来进行解析。

参考代码可以看：https://learn.microsoft.com/zh-cn/windows/win32/etw/using-tdhformatproperty-to-consume-event-data

还有一些三方库：

微软官方库(C#)：

https://github.com/microsoft/ETW2JSON

https://github.com/microsoft/perfview

1.2.2 采用工具来解析

通过 PowerShell： Get-WinEvent -Path "C:WindowsSystem32LogsUpdateHealthTools.001.etl" -Oldest
通过 WPT 中的 WPA 也可以用来查看
Microsoft Message Analyzer
PerfView
通过事件查看器（Event Viewer）

1.3 事件日志（.evtx）和 ETW 的关系

事件日志文件（也就是以 .evtx 为后缀的文件）是事件查看器的日志文件格式，其通过 xml 来存储，易于阅读和处理。

而事件查看器则作为 ETW 中的消费者，来收集 ETW 中各种 provider 的特定事件，通过处理后，将其保存到本地。

事件日志也可以通过 powershell 的 Get-WinEvent 来进行解析。

Windows 事件日志通常保存在：C:WindowsSystem32winevtLogs

1.4 怎么与 ETW 交互

1.4.1 通过 Logman 来交互

logman.exe 是一个原生的 cmd 命令行工具，不用额外安装。

列出所有的 provider

frend in ~ λ logman query providers

Provider                                 GUID
-------------------------------------------------------------------------------
.NET Common Language Runtime             {E13C0D23-CCBC-4E12-931B-D9CC2EEE27E4}
ACPI Driver Trace Provider               {DAB01D4D-2D48-477D-B1C3-DAAD0CE6F06B}
Active Directory Domain Services: SAM    {8E598056-8993-11D2-819E-0000F875A064}
Active Directory: Kerberos Client        {BBA3ADD2-C229-4CDB-AE2B-57EB6966B0C4}
Active Directory: NetLogon               {F33959B4-DBEC-11D2-895B-00C04F79AB69}
ADODB.1                                  {04C8A86F-3369-12F8-4769-24E484A9E725}
ADOMD.1                                  {7EA56435-3F2F-3F63-A829-F0B35B5CAD41}
Application Error                        {A0E9B465-B939-57D7-B27D-95D8E925FF57}
Application Hang                         {C631C3DC-C676-59E4-2DB3-5C0AF00F9675}
Application Popup                        {47BFA2B7-BD54-4FAC-B70B-29021084CA8F}

查看 provider 详细信息

frend in ~ λ logman query providers "Application Error"

Provider                                 GUID
-------------------------------------------------------------------------------
Application Error                        {A0E9B465-B939-57D7-B27D-95D8E925FF57}

Value               Keyword              Description
-------------------------------------------------------------------------------
0x8000000000000000  Application          Application

Value               Level                Description
-------------------------------------------------------------------------------
0x02                win:Error            Error

The command completed successfully.

查看所有事件追踪会话

frend in ~ λ logman query -ets

Data Collector Set                      Type                          Status
-------------------------------------------------------------------------------
Eventlog-Security                       Trace                         Running
Cloud Files Diagnostic Event Listener   Trace                         Running
Diagtrack-Listener                      Trace                         Running
FilterMgr-Logger                        Trace                         Running
LwtNetLog                               Trace                         Running
Microsoft-Windows-ProjFS-Filter-Log     Trace                         Running

创建事件跟踪会话

frend in ~ λ logman create trace process-tracing-test -ets
The command completed successfully.

查看特定的跟踪会话

frend in ~ λ logman query process-tracing-test -ets

Name:                 process-tracing-test
Status:               Running
Root Path:            C:Usersfrend
Segment:              Off
Schedules:            On

Name:                 process-tracing-testprocess-tracing-test
Type:                 Trace
Output Location:      C:Usersfrendprocess-tracing-test.etl
Append:               Off
Circular:             Off
Overwrite:            Off
Buffer Size:          8
Buffers Lost:         0
Buffers Written:      1
Buffer Flush Timer:   0
Clock Type:           Performance
File Mode:            File

The command completed successfully.

向会话中添加 provider（Microsoft-Windows-Kernel-Process）

frend in ~ λ logman update process-tracing-test -p Microsoft-Windows-Kernel-Process 0x30 -ets
The command completed successfully.
frend in ~ λ logman query process-tracing-test -ets

Name:                 process-tracing-test
Status:               Running
Root Path:            C:Usersfrend
Segment:              Off
Schedules:            On

Name:                 process-tracing-testprocess-tracing-test
Type:                 Trace
Output Location:      C:Usersfrendprocess-tracing-test.etl
Append:               Off
Circular:             Off
Overwrite:            Off
Buffer Size:          8
Buffers Lost:         0
Buffers Written:      20
Buffer Flush Timer:   0
Clock Type:           Performance
File Mode:            File

Provider:
Name:                 Microsoft-Windows-Kernel-Process
Provider Guid:        {22FB2CD6-0E7B-422B-A0C7-2FAD1FD0E716}
Level:                255
KeywordsAll:          0x0
KeywordsAny:          0x30 (WINEVENT_KEYWORD_PROCESS,WINEVENT_KEYWORD_THREAD)
Properties:           64
Filter Type:          0

The command completed successfully.

于是可以通过事件查看器打开 [Output Location] 的路径，就可以看到具体的信息了。

从跟踪会话中移除 provider

frend in ~ λ logman update process-tracing-test --p Microsoft-Windows-Kernel-Process 0x30 -ets
The command completed successfully.
frend in ~ λ logman query process-tracing-test -ets

Name:                 process-tracing-test
Status:               Running
Root Path:            C:Usersfrend
Segment:              Off
Schedules:            On

Name:                 process-tracing-testprocess-tracing-test
Type:                 Trace
Output Location:      C:Usersfrendprocess-tracing-test.etl
Append:               Off
Circular:             Off
Overwrite:            Off
Buffer Size:          8
Buffers Lost:         0
Buffers Written:      3538
Buffer Flush Timer:   0
Clock Type:           Performance
File Mode:            File

The command completed successfully.

移除会话跟踪

frend in ~ λ logman stop process-tracing-test -ets
The command completed successfully.
frend in ~ λ logman query process-tracing-test -ets

Error:
Data Collector Set was not found.

查看特定进程监听的 providers

frend in ~ λ logman query providers -pid 38916

Provider                                 GUID
-------------------------------------------------------------------------------
Microsoft-IE                             {9E3B3947-CA5D-4614-91A2-7B624E0E7244}
Microsoft-IE-JSDumpHeap                  {7F8E35CA-68E8-41B9-86FE-D6ADC5B327E7}
Microsoft-IEFRAME                        {5C8BB950-959E-4309-8908-67961A1205D5}
Microsoft-JScript                        {57277741-3638-4A4B-BDBA-0AC6E45DA56C}
Microsoft-PerfTrack-IEFRAME              {B2A40F1F-A05A-4DFD-886A-4C4F18C4334C}
Microsoft-PerfTrack-MSHTML               {FFDB9886-80F3-4540-AA8B-B85192217DDF}
Microsoft-Windows-ACL-UI                 {EA4CC8B8-A150-47A3-AFB9-C8D194B19452}
Microsoft-Windows-Application-Experience {EEF54E71-0661-422D-9A98-82FD4940B820}
Microsoft-Windows-AppModel-Runtime       {F1EF270A-0D32-4352-BA52-DBAB41E1D859}
Microsoft-Windows-AsynchronousCausality  {19A4C69A-28EB-4D4B-8D94-5F19055A1B5C}
Microsoft-Windows-Audio                  {AE4BD3BE-F36F-45B6-8D21-BDD6FB832853}
Microsoft-Windows-COM-Perf               {B8D6861B-D20F-4EEC-BBAE-87E0DD80602B}
Microsoft-Windows-COM-RundownInstrumentation {2957313D-FCAA-5D4A-2F69-32CE5F0AC44E}
Microsoft-Windows-COMRuntime             {BF406804-6AFA-46E7-8A48-6C357E1D6D61}
Microsoft-Windows-Crypto-BCrypt          {C7E089AC-BA2A-11E0-9AF7-68384824019B}
Microsoft-Windows-Deplorch               {B9DA9FE6-AE5F-4F3E-B2FA-8E623C11DC75}
Microsoft-Windows-Devices-Query          {DF63D0DC-97C2-5E48-C1CC-7B46BFD4DF88}
Microsoft-Windows-Diagnosis-PLA          {E4D53F84-7DE3-11D8-9435-505054503030}
Microsoft-Windows-Diagnosis-WDC          {05921578-2261-42C7-A0D3-26DDBCE6C50D}
Microsoft-Windows-Direct3D11             {DB6F6DDB-AC77-4E88-8253-819DF9BBF140}

1.4.2 通过 Performance Monitor 来交互

1.4.3 通过 PowerShell 来交互

PowerShell 没有直接的 cmlet 来与 PowerShell 进行交互，需要通过如下类来进行交互：

https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.eventing.reader?view=dotnet-plat-ext-8.0

列出所有provider

[System.Diagnostics.Eventing.Reader.EventLogSession]::GlobalSession.GetProviderNames()

查看特定 provider 的详细信息

[System.Diagnostics.Eventing.Reader.ProviderMetadata]("Microsoft-Windows-Powershell")

1.4.4 通过消息分析器（Microsoft Message Analyzer）来交互

打开 Microsoft Message Analyzer 后，点击【New Session】，在【New Data Source】中选择【Live Trace】

点击【Add Provider】添加需要监听的 provider

点击 provider 右侧的【Configure】，则可以选择 Level 和 keywords 来进行筛选

于是，你就可以在界面上看到记录下的消息记录了：

1.4.5 通过 ETWExplorer 查看 ETW 提供者清单文件

ETWExplorer 可以从这里下载到：

https://github.com/zodiacon/EtwExplorer

选择特定的 provider，就可以看到 provider 的详细信息了。

作为提供者

作为提供者，我们可以利用 ETW 来优化自己的日志系统（WDF 模板内置了 WPP 的支持）。

这里就不详细介绍了。

参考：

https://nasbench.medium.com/a-primer-on-event-tracing-for-windows-etw-997725c082bf
https://github.com/nasbench/EVTX-ETW-Resources
https://learn.microsoft.com/en-us/windows/win32/etw/about-event-tracing
https://learn.microsoft.com/zh-cn/windows-hardware/test/weg/instrumenting-your-code-with-etw
https://www.ired.team/miscellaneous-reversing-forensics/windows-kernel-internals/etw-event-tracing-for-windows-101