ETW 介紹 - 以 Event Tracing Session 為範例

因為工作需求,開始接觸 Windows System Programming,每次都覺得 MSDN 寫的很混亂,有時候太注重細節,對於系統沒有全面性的介紹;有時又只有概論,沒有程式碼或實作內容;有些甚至把不同的文件連結在一起就結束了。即使是 Google 找到的資料也比日本製的壓縮機還稀少。最後只能花時間慢慢測試,聽部門的人說,有好幾次都是他們自己試出很 tricky 的用法,跟微軟的技術人員聊一聊,結果居然變成 MSDN 的內容,不知道該哭還是笑。

什麼是 ETW ?

ETW(Event Tracing for Windows) 是 Windows 提供的一種事件追蹤的方式,利用 ETW 可以實現 real-time 的高速事件追蹤,讓程式設計師可以利用事件做除錯或是效能優化。

ETW 分為三個部分,Controller、Provider 和 Consumer,Controller 可以開關 Provider,Provider 會提供事件(Event)本身,而 Consumer 則是消費(Consume)事件的人,也就是我們的角色。

另外,Controller 可以註冊 Session 並設定要負責的 Provrider,Provider 會把本身的事件發給 Session,Session 可以把事件直接發給 Consumer(Real-time mode),或是存到一個 Trace File,Consumer 再去這個檔案拿事件(File Mode)。

Sessions

Session 會從一個或多個 Providers 記錄事件,並且也負責管理和清除 buffer 的資料,而 Session 本身的屬性則是由 Controller 設定的。

Session 分為很多種:

  • Event Tracing Session
  • SystemTraceProvider Session
    • NT Kernel Logger Session
  • AutoLogger Session
    • Global Logger Session
  • Private Logger Session

我們在這裡先探討如何簡單地使用 Event tracing sessions 把 Events 存到 Log file。

使用 Event Tracing Session

我們參考 MSDN 上的範例,Example that Creates a Session and Enables a Manifest-based or Classic Provider

定義常數

首先定義 Log file 的位置,以及 Session 的名稱。

1
2
#define LOGFILE_PATH L"<FULLPATHTOLOGFILE.etl>"
#define LOGSESSION_NAME L"My Event Trace Session"

接下來是 Session 的 GUID 以及 Provider 的 GUID,其中 Session 的 GUID 是自己設定的唯一值。
Provider 的 GUID 則可以透過在 cmd 下 logman query providers 找到。

1
2
3
4
5
6
7
// {AE44CB98-BD11-4069-8093-770EC9258A12}
static const GUID SessionGuid =
{ 0xae44cb98, 0xbd11, 0x4069, { 0x80, 0x93, 0x77, 0xe, 0xc9, 0x25, 0x8a, 0x12 } };

// {D8909C24-5BE9-4502-98CA-AB7BDC24899D}
static const GUID ProviderGuid =
{ 0xd8909c24, 0x5be9, 0x4502, {0x98, 0xca, 0xab, 0x7b, 0xdc, 0x24, 0x89, 0x9d } };

初始化空間

首先要為 Session 建立一個空間,儲存 Session 的結構是 EVENT_TRACE_PROPERTIES (Evntrace.h),但我們還需要儲存上面定義的 Logfile Path 以及 Session name,所以總長會是三者相加。之後再用 malloc 向系統要一塊記憶體。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
ULONG status = ERROR_SUCCESS;
TRACEHANDLE SessionHandle = 0;
EVENT_TRACE_PROPERTIES* pSessionProperties = NULL;
ULONG BufferSize = 0;
BOOL TraceOn = TRUE;

// Allocate memory for the session properties. The memory must
// be large enough to include the log file name and session name,
// which get appended to the end of the session properties structure.

BufferSize = sizeof(EVENT_TRACE_PROPERTIES) + sizeof(LOGFILE_PATH) + sizeof(LOGSESSION_NAME);
pSessionProperties = (EVENT_TRACE_PROPERTIES*) malloc(BufferSize);
if (NULL == pSessionProperties)
{
wprintf(L"Unable to allocate %d bytes for properties structure.\n", BufferSize);
goto cleanup;
}

配置 Session

我們剛才已經將記憶體空間準備好了,現在要來設置當中的設定。
關於詳細的結構內容可以參考 EVENT_TRACE_PROPERTIES structure
我們不需要完整設定全部的內容,除了必要的欄位,其他的欄位會在啟動時被填入預設值。

首先我們利用 ZeroMemory() 初始化這塊空間,ZeroMemory 是微軟對 memset 的封裝,將目標空間填 0。詳細請參考 Why do ZeroMemory, etc. exist when there are memset, etc. already?

接下來開始填入 pSessionProperties 的內容。
EVENT_TRACE_PROPERTIES 結構中有一個 Wnode 的結構,我們必須設定它的 BufferSize、Flags 以及 Guid, ClientContext 則是選擇性的。Guid 填入我們所定義的 SessionGuid,Flags 則必須包含 WNODE_FLAG_TRACED_GUID。詳細請參考 WNODE_HEADER structure

接著是 LogFileMode,設定我們要採用什麼模式去紀錄 Event tracing session,可以是記錄到 log file,也可以即時呼叫 callback,或兩者同時採用。其設定請參考 Logging Mode Constants。在範例中,EVENT_TRACE_FILE_MODE_SEQUENTIAL 代表將事件循序寫入 Log file 中,直到我們設定的檔案大小,也就是 MaximumFileSize。值得注意的是,如果我們把儲存 log file 的路徑設定在和作業系統同一個磁碟區,ETW 會另外檢查是否有 200MB 的空間可以用。即,我們設定 100MB,實際的磁碟空間要求會是 300MB。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
// Set the session properties. You only append the log file name
// to the properties structure; the StartTrace function appends
// the session name for you.

ZeroMemory(pSessionProperties, BufferSize);
pSessionProperties->Wnode.BufferSize = BufferSize;
pSessionProperties->Wnode.Flags = WNODE_FLAG_TRACED_GUID;
pSessionProperties->Wnode.ClientContext = 1; //QPC clock resolution
pSessionProperties->Wnode.Guid = SessionGuid;
pSessionProperties->LogFileMode = EVENT_TRACE_FILE_MODE_SEQUENTIAL;
pSessionProperties->MaximumFileSize = 1; // 1 MB
pSessionProperties->LoggerNameOffset = sizeof(EVENT_TRACE_PROPERTIES);
pSessionProperties->LogFileNameOffset = sizeof(EVENT_TRACE_PROPERTIES) + sizeof(LOGSESSION_NAME);
StringCbCopy((LPWSTR)((char*)pSessionProperties + pSessionProperties->LogFileNameOffset), sizeof(LOGFILE_PATH), LOGFILE_PATH);

建立 Session

我們已經把 Session 的內容都寫好了,就像前面所述,Session 是由 Controller 操控,所以接下來,我們要利用 Controller 的 API 來建立、修改或啟動 Session。

Controller API

Controller 的 API 主要有

  • StartTrace()
    • 啟動 Session。
  • ControlTrace()
    • 控制 Session,包括修改與中止。
  • EnableTraceEx2()
    • 在 Windows 8.1 與 Windows Server 2012 R2 之後的版本才呼叫 EnableTraceEx2(),更之前有 EnableTrace() 及 EnableTraceEx()。

要把這個 Session 實際建立起來,直接呼叫 StartTrace,填入 TRACEHANDLE、Session name 以及我們剛剛配置好的結構 EVENT_TRACE_PROPERTIES 便可以了。

1
2
3
4
5
6
status = StartTrace((PTRACEHANDLE)&SessionHandle, LOGSESSION_NAME, pSessionProperties);
if (ERROR_SUCCESS != status)
{
wprintf(L"StartTrace() failed with %lu\n", status);
goto cleanup;
}

啟動 Provider

我們利用 EnableTraceEx2() 將 Session 和 Provider 綁在一起,並啟動 Provider、設定要接收的事件等級,在範例中設定的是 TRACE_LEVEL_INFORMATION。詳細請參考 EnableTraceEx2 function 的 Level,總共有五個等級。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
status = EnableTraceEx2(
SessionHandle,
(LPCGUID)&ProviderGuid,
EVENT_CONTROL_CODE_ENABLE_PROVIDER,
TRACE_LEVEL_INFORMATION,
0,
0,
0,
NULL
);

if (ERROR_SUCCESS != status)
{
wprintf(L"EnableTrace() failed with %lu\n", status);
TraceOn = FALSE;
goto cleanup;
}

Cleanup

在 EnableTraceEx2() 傳入 EVENT_CONTROL_CODE_DISABLE_PROVIDER 將 Provider 關閉,再用 ControlTrace 傳入 EVENT_TRACE_CONTROL_STOP 關閉 Session。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
if (SessionHandle)
{
if (TraceOn)
{
status = EnableTraceEx2(
SessionHandle,
(LPCGUID)&ProviderGuid,
EVENT_CONTROL_CODE_DISABLE_PROVIDER,
TRACE_LEVEL_INFORMATION,
0,
0,
0,
NULL
);
}

status = ControlTrace(SessionHandle, LOGSESSION_NAME, pSessionProperties, EVENT_TRACE_CONTROL_STOP);

if (ERROR_SUCCESS != status)
{
wprintf(L"ControlTrace(stop) failed with %lu\n", status);
}
}

if (pSessionProperties)
{
free(pSessionProperties);
pSessionProperties = NULL;
}

完整程式碼

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
#include <windows.h>
#include <stdio.h>
#include <conio.h>
#include <strsafe.h>
#include <wmistr.h>
#include <evntrace.h>

#define LOGFILE_PATH L"<FULLPATHTOLOGFILE.etl>"
#define LOGSESSION_NAME L"My Event Trace Session"

// GUID that identifies your trace session.
// Remember to create your own session GUID.

// {AE44CB98-BD11-4069-8093-770EC9258A12}
static const GUID SessionGuid =
{ 0xae44cb98, 0xbd11, 0x4069, { 0x80, 0x93, 0x77, 0xe, 0xc9, 0x25, 0x8a, 0x12 } };

// GUID that identifies the provider that you want
// to enable to your session.

// {D8909C24-5BE9-4502-98CA-AB7BDC24899D}
static const GUID ProviderGuid =
{ 0xd8909c24, 0x5be9, 0x4502, {0x98, 0xca, 0xab, 0x7b, 0xdc, 0x24, 0x89, 0x9d } };

void wmain(void)
{
ULONG status = ERROR_SUCCESS;
TRACEHANDLE SessionHandle = 0;
EVENT_TRACE_PROPERTIES* pSessionProperties = NULL;
ULONG BufferSize = 0;
BOOL TraceOn = TRUE;

// Allocate memory for the session properties. The memory must
// be large enough to include the log file name and session name,
// which get appended to the end of the session properties structure.

BufferSize = sizeof(EVENT_TRACE_PROPERTIES) + sizeof(LOGFILE_PATH) + sizeof(LOGSESSION_NAME);
pSessionProperties = (EVENT_TRACE_PROPERTIES*) malloc(BufferSize);
if (NULL == pSessionProperties)
{
wprintf(L"Unable to allocate %d bytes for properties structure.\n", BufferSize);
goto cleanup;
}

// Set the session properties. You only append the log file name
// to the properties structure; the StartTrace function appends
// the session name for you.

ZeroMemory(pSessionProperties, BufferSize);
pSessionProperties->Wnode.BufferSize = BufferSize;
pSessionProperties->Wnode.Flags = WNODE_FLAG_TRACED_GUID;
pSessionProperties->Wnode.ClientContext = 1; //QPC clock resolution
pSessionProperties->Wnode.Guid = SessionGuid;
pSessionProperties->LogFileMode = EVENT_TRACE_FILE_MODE_SEQUENTIAL;
pSessionProperties->MaximumFileSize = 1; // 1 MB
pSessionProperties->LoggerNameOffset = sizeof(EVENT_TRACE_PROPERTIES);
pSessionProperties->LogFileNameOffset = sizeof(EVENT_TRACE_PROPERTIES) + sizeof(LOGSESSION_NAME);
StringCbCopy((LPWSTR)((char*)pSessionProperties + pSessionProperties->LogFileNameOffset), sizeof(LOGFILE_PATH), LOGFILE_PATH);

// Create the trace session.

status = StartTrace((PTRACEHANDLE)&SessionHandle, LOGSESSION_NAME, pSessionProperties);
if (ERROR_SUCCESS != status)
{
wprintf(L"StartTrace() failed with %lu\n", status);
goto cleanup;
}

// Enable the providers that you want to log events to your session.

status = EnableTraceEx2(
SessionHandle,
(LPCGUID)&ProviderGuid,
EVENT_CONTROL_CODE_ENABLE_PROVIDER,
TRACE_LEVEL_INFORMATION,
0,
0,
0,
NULL
);

if (ERROR_SUCCESS != status)
{
wprintf(L"EnableTrace() failed with %lu\n", status);
TraceOn = FALSE;
goto cleanup;
}

wprintf(L"Run the provider application. Then hit any key to stop the session.\n");
_getch();

cleanup:

if (SessionHandle)
{
if (TraceOn)
{
status = EnableTraceEx2(
SessionHandle,
(LPCGUID)&ProviderGuid,
EVENT_CONTROL_CODE_DISABLE_PROVIDER,
TRACE_LEVEL_INFORMATION,
0,
0,
0,
NULL
);
}

status = ControlTrace(SessionHandle, LOGSESSION_NAME, pSessionProperties, EVENT_TRACE_CONTROL_STOP);

if (ERROR_SUCCESS != status)
{
wprintf(L"ControlTrace(stop) failed with %lu\n", status);
}
}

if (pSessionProperties)
{
free(pSessionProperties);
pSessionProperties = NULL;
}
}

結語

最後會得到一個 Log file,副檔名是 etl,像是這樣

如果有裝 Windows Performance Analyzer,就可以打開來看。圖中是收 TCP/IP 的 Event。

以上便是最簡單的 ETW 使用方式,在 Windows 收 Event 還有很多不同的做法,有機會再與大家分享。