Windows事件跟蹤：OpenTrace/ProcessTrace不回傳任何事件-回呼未被呼叫

精簡版

我正在嘗試使用OpenTrace和ProcessTrace來讀取.etl檔案的事件。

• 對OpenTrace的呼叫成功回傳一個TRACEHANDLE
• 對ProcessTrace的呼叫回傳ERROR_SUCCESS
• 但ProcessTrace從不呼叫我的EVENT_CALLBACK回呼函式

我知道這是一個有效的.etl檔案，因為我可以在以下位置打開它：

• Windows 性能分析器
• 性能視圖
• 跟蹤記錄

長版

Microsoft 提供了有關讀取檔案事件的示例代碼.etl。基本要點是：

1. 使用EVENT_TRACE_LOGFILE我們要打開的檔案名和回呼函式的地址初始化一個結構。回呼函式為檔案中的每個事件呼叫一次：

   var 
     filename: UnicodeString;
     trace: EVENT_TRACE_LOGFILEW;
   
   filename := 'C:\test.etl';
   
   //Initialize trace with filename and callback
   ZeroMemory(@trace, sizeof(trace));
   trace.LogFileName := PWideChar(filename);
   trace.EventCallback := ProcessTraceEventCallback; //called once for each event in the file
   

2. 呼叫OpenTrace打開指定.etl檔案，并獲取TRACEHANDLE會話的一個：

   //Open the trace
   var
     hTrace: TRACEHANDLE;
   
   hTrace := OpenTraceW(trace);
   if (hTrace = INVALID_PROCESSTRACE_HANDLE) then
     RaiseLastOSError;
   

3. 呼叫ProcessTrace開始從檔案中讀取事件。我們的回呼將針對檔案中的每個事件呼叫一次，并且ProcessTrace將在讀取所有事件之前不會回傳：

   var
      res: Cardinal;
   
   res := ProcessTrace(@hTrace, 1, nil, nil);
   if (res <> ERROR_SUCCESS) then
      RaiseLastOSError;
   

應該就是這樣，除了從未呼叫回呼：

procedure ProcessTraceEventCallback(pEvent: PEVENT_TRACE); stdcall;
begin
   //TODO: read the event information out of pEvent
   //pEvent.MofData ==> raw payload information
   //pEvent.MofLength ==> raw payload length (bytes)
   WriteLn('Got an event');
   Winapi.Windows.DebugBreak;
end;

沒有任何代碼回傳錯誤。

• OpenTrace回傳一個有效的句柄
• ProcessTrace需要一點時間回傳（好像在處理事件）
• 并回傳 ERROR_SUCCESS
• 但是用于獲取事件資訊的回呼函式從未被呼叫。

我的示例代碼和下面的 CRME 都強制使用W Unicode 版本的函式（只是為了消除混淆）。我確定我的標題翻譯、記錄打包、對齊或呼叫約定有問題 - 但我找不到任何東西。

完全可重現的最小示例

我知道這似乎不是最小的。但是我們需要所有的 API 函式和結構。

您將需要自己的C:\test.etl檔案。您可以使用Windows Performance Recorder創建一個，或在您的 PC 中搜索.etl檔案 - Windows 和 Microsoft 創建了許多分散在各處的檔案。

program Project4;

{$APPTYPE CONSOLE}
{$ALIGN 8} //Windows ABI

{$R *.res}

uses
  System.SysUtils,
  Winapi.Windows;

type
    EVENT_TRACE_HEADER = packed record
        Size: Word;                         // Size of entire record
        FieldTypeFlags: Word;           // Reserved
        EventType: Byte;                    //Type of event. A provider can define their own event types or use the predefined event types (Info, Start,Stop, Suspend, Checkpoint, Resume, etc.)
        EventLevel: Byte;                   //Provider-defined value that defines the severity level used to generate the event. Verbose, Information, Warning, Error, Critical, etc
        EventVersion: Word;             //Which version of MOF class to use to decipher the event data. Specify zero if there is only one version of your event trace class.
        ThreadId: LongWord;                 //On output, identifies the thread that generated the event.
        ProcessId: LongWord;                //On output, identifies the process that generated the event.
        TimeStamp: Int64;                   //The time that the event occurred. On output, contains the time that the event occurred.
        Guid: TGUID;                        //Guid that identifies event. Event trace class GUID. You can use the class GUID to identify a category of events and the Class.Type member to identify an event within the category of events.
        ClientContext: LongWord;        //Reserved
        Flags: LongWord;              //
    end;
    PEVENT_TRACE_HEADER = ^EVENT_TRACE_HEADER;

  EVENT_TRACE = packed record
     Header: EVENT_TRACE_HEADER;    // Event trace header
     InstanceId: Cardinal;          // Instance identifier. Contains valid data when the provider calls the TraceEventInstance function to generate the event. Otherwise, the value is zero.
     ParentInstanceId: Cardinal;    // Instance identifier for a parent event. Contains valid data when the provider calls the TraceEventInstance function to generate the event. Otherwise, the value is zero.
     ParentGuid: TGUID;             // Class GUID of the parent event. Contains valid data when the provider calls the TraceEventInstance function to generate the event. Otherwise, the value is zero.
     MofData: Pointer;              // Pointer to the beginning of the event-specific data for this event.
     MofLength: Cardinal;           // Number of bytes to which MofData points.
     BufferContext: Cardinal;       // Provides information about the event such as the session identifier and processor number of the CPU on which the provider process ran.
  end;
  PEVENT_TRACE = ^EVENT_TRACE;

  TRACE_LOGFILE_HEADER = record
        BufferSize: LongWord;
        MajorVersion: Byte;
        MinorVersion: Byte;
        SubVersion: Byte;
        SubMinorVersion: Byte;

        ProviderVersion: LongWord;    // defaults to NT version
        NumberOfProcessors: LongWord; // Number of Processors
        EndTime: LARGE_INTEGER;       // Time when logger stops
        TimerResolution: LongWord;
        MaximumFileSize: LongWord;    // Maximum in Mbytes
        LogFileMode: LongWord;        // specify logfile mode
        BuffersWritten: LongWord;     // used to file start of Circular File
        StartBuffers: Cardinal;         // Reserved
        PointerSize: Cardinal;          // Size of a Pointer data type, in bytes.
        EventsLost: Cardinal;           // Number of events lost during the event tracing session. Events may be lost due to insufficient memory or a very high rate of incoming events.
        CpuSpeedInMHz: Cardinal;        // CPU speed, in megahertz.
        LoggerName: PWideChar;          // Do not use.
        LogFileName: PWideChar;         // Do not use
        TimeZone: TIME_ZONE_INFORMATION;    // A TIME_ZONE_INFORMATION structure that contains the time zone for the BootTime, EndTime and StartTime members.
        BootTime: Int64;                    // Time at which the system was started, in 100-nanosecond intervals since midnight, January 1, 1601. BootTime is supported only for traces written to the Global Logger session.
        PerfFreq: Int64;                    // Frequency of the high-resolution performance counter, if one exists.
        StartTime: Int64;                   // Time at which the event tracing session started, in 100-nanosecond intervals since midnight, January 1, 1601.
        ReservedFlags: Cardinal;
        BuffersLost: Cardinal;          // Total number of buffers lost during the event tracing session.
    end;
    PTRACE_LOGFILE_HEADER = ^TRACE_LOGFILE_HEADER;

    PEVENT_TRACE_LOGFILEW = ^EVENT_TRACE_LOGFILEW; //forward

    EVENT_TRACE_BUFFER_CALLBACKW = function (Logfile : PEVENT_TRACE_LOGFILEW) : Cardinal; stdcall;
    PEVENT_TRACE_BUFFER_CALLBACKW = EVENT_TRACE_BUFFER_CALLBACKW;

    //Legacy EventCallback callback
    EVENT_CALLBACK = procedure (pEvent: PEVENT_TRACE); stdcall;
    PEVENT_CALLBACK = EVENT_CALLBACK;

    //Newer EventCallback if ProcessTraceMode of PROCESS_TRACE_MODE_EVENT_RECORD is specified
//  EVENT_RECORD_CALLBACK = procedure (EventRecord: PEVENT_RECORD); stdcall;
//  PEVENT_RECORD_CALLBACK = EVENT_RECORD_CALLBACK;

    EVENT_TRACE_LOGFILEW = packed record
        LogFileName: PWideChar;                 // Logfile Name
        LoggerName: PWideChar;                  // LoggerName
        CurrentTime: Int64;                     // timestamp of last event
        BuffersRead: Cardinal;                  // buffers read to date
        ProcessTraceMode: Cardinal;
        CurrentEvent: EVENT_TRACE;              // Current Event from this stream. (84 bytes)
        LogfileHeader: TRACE_LOGFILE_HEADER;            // logfile header structure (272 bytes)
        BufferCallback: PEVENT_TRACE_BUFFER_CALLBACKW;  // callback before each buffer is read

        // following variables are filled for BufferCallback.
        BufferSize: Cardinal;       //On output, contains the size of each buffer, in bytes
        Filled: Cardinal;               //On output, contains the number of bytes in the buffer that contain valid information
        EventsLost: Cardinal;       //Not used

        // following needs to be propaged to each buffer
        EventCallback: PEVENT_CALLBACK; //or EventRecordCallback: PEvent_Record_Callback if flag is on
        IsKernelTrace: Cardinal;    // TRUE for kernel logfile
        Context: Pointer;          // reserved for internal use
    end;

    TRACEHANDLE  = UInt64;
    PTRACEHANDLE = ^TRACEHANDLE;

function OpenTraceW(var Logfile : EVENT_TRACE_LOGFILEW): Cardinal; stdcall; external advapi32 name 'OpenTraceW';
function ProcessTrace(HandleArray: PTRACEHANDLE; HandleCount: Cardinal; StartTime: PFileTime; EndTime: PFileTime): Cardinal; stdcall; external advapi32 name 'ProcessTrace';
function CloseTrace(ATraceHandle: TRACEHANDLE): Cardinal; stdcall; external advapi32 name 'CloseTrace';

const
    INVALID_PROCESSTRACE_HANDLE: TRACEHANDLE = INVALID_HANDLE_VALUE; //i.e. TRACEHANDLE($00000000FFFFFFFF);

procedure ProcessTraceEventCallback(pEvent: PEVENT_TRACE); stdcall;
begin
{
    Our callback, called once for each event in the file
}
    WriteLn('Got an event');
    Winapi.Windows.DebugBreak;
end;

function BufferCallback(logFile: PEVENT_TRACE_LOGFILEW): LongWord; stdcall;
begin
    WriteLn('Finished processing a buffer-full of events. Buffercallback says ' IntToStr(logfile.EventsLost) ' events lost');

    Result := 1; // Return TRUE to continue processing more events. Otherwise FALSE
end;

procedure Main;
var
    trace: EVENT_TRACE_LOGFILEW;
    th: TRACEHANDLE;
    filename: UnicodeString;
    res: Cardinal;
begin
    filename := 'C:\test.etl';
    WriteLn('Filename: ' filename);

    {
      Example code of how to read from a .etl file:

      Using TdhFormatProperty to Consume Event Data
      https://docs.microsoft.com/en-us/windows/win32/etw/using-tdhformatproperty-to-consume-event-data
    }

    //Initialize EVENT_TRACE_LOGFILE with filename to open, and our callback function
    WriteLn('Initializing EVENT_TRACE_LOGFILE');
    ZeroMemory(@trace, sizeof(trace)); // 408 bytes
    trace.LogFileName := PWideChar(filename);
    trace.EventCallback := ProcessTraceEventCallback; //called once for each event in the file
//  trace.ProcessTraceMode := PROCESS_TRACE_MODE_EVENT_RECORD; //we wanted new style events through the "EventRecordCallback"
//  trace.BufferCallback := BufferCallback; //optional callback for inforamtion after processing a buffer-full of events

    WriteLn('Opening trace file "' filename '"');
    th := OpenTraceW(trace);
    if (th = INVALID_PROCESSTRACE_HANDLE) or (th = -1) then
    begin
        WriteLn('Error opening trace file: ' SysErrorMessage(GetLastError));
        Exit;
    end;
    WriteLn('Successfully opened trace session. TraceHandle: 0x' IntToHex(th, 8));

    WriteLn('Processing trace file');
    res := ProcessTrace(@th, 1, nil, nil);
    if (res <> ERROR_SUCCESS) then // and (hr <> ERROR_CANCELLED) then
        RaiseLastOSError;
    WriteLn('Successfully processed trace file');

    WriteLn('Closing trace handle');
    CloseTrace(th);

    WriteLn('Finished processing ' filename);
end;

begin
  try
        Main;
        WriteLn('Execution complete. Press enter to close...');
        ReadLn;
  except
    on E: Exception do
        Writeln(E.ClassName, ': ', E.Message);
  end;
end.

我的輸出是：

Filename: C:\test.etl
Initializing EVENT_TRACE_LOGFILE
Opening trace file "C:\test.etl"
Successfully opened trace session. TraceHandle: 0x00000041
Processing trace file
Successfully processed trace file
Closing trace handle
Finished processing C:\test.etl
Execution complete. Press enter to close...

誰能看到我做錯了什么？

uj5u.com熱心網友回復：

答案正是我所知道的。

• 我從Franck Soranio翻譯的標題開始
• 其中一些定義是packed records
• 當那不起作用時，我嘗試添加$ALIGN 8- Windows 所需的 ABI
• 當那不起作用時，我嘗試添加packed到所有記錄

當那不起作用時，我問 Stackoverflow。

與此同時，我啟動了 Visual Studio C ，并比較sizeof了原始結構和 Delphi 翻譯。

他們不匹配。

問題是該packed記錄。

• sizeof(EVENT_TRACE_LOGFILEW)：416 位元組（原為 404）
  • sizeof(EVENT_TRACE): 88 位元組（原為 80）
    • sizeof(EVENT_TRACE_HEADER): 44 位元組（原為 40）
  • sizeof(TRACE_LOGFILE_HEADER): 272 位元組

移除唱片包裝修復了它。

標籤：视窗 德尔福 登录 等

上一篇：WS_EX_LAYERED與SetParent()不顯示視窗

下一篇：如何為python定義鹽狀態下的win包名稱？