VOID DumpEventHeader( __in PEVENT_RECORD Event, __in PTRACE_EVENT_INFO EventInfo, __inout PPROCESSING_CONTEXT LogContext ) /*++ Routine Description: This routine dumps the metadata and the excecution parameters for the event. Arguments: Event - Supplies the event whose header will be dumped. EventInfo - Supplies the information about the event whose header will be dumped. LogContext - Supplies processing context for the event. Return Value: None. --*/ { ULONG Status = ERROR_SUCCESS; PEVENT_HEADER Header = (PEVENT_HEADER)&Event->EventHeader; LPGUID RelatedActivityID = NULL; PEVENT_EXTENDED_ITEM_TS_ID SessionID = NULL; PBYTE Sid = NULL; PEVENT_EXTENDED_ITEM_INSTANCE Instance = NULL; PULONG Stack32 = NULL; PULONG64 Stack64 = NULL; ULONG FrameCount = 0; LPGUID Guid; WCHAR GuidString[STRLEN_GUID]; WCHAR DateTimeString[STRLEN_UTC_DATETIME]; FILETIME FileTime; ULONG GuidStringSize = STRLEN_GUID * sizeof(WCHAR); ULONG DateTimeStringSize = STRLEN_UTC_DATETIME * sizeof(WCHAR); USHORT Consumed; ULONG DataLeft = ULONG_MAX; for (ULONG i = 0; i < Event->ExtendedDataCount; i++) { switch (Event->ExtendedData[i].ExtType) { case EVENT_HEADER_EXT_TYPE_RELATED_ACTIVITYID: RelatedActivityID = (LPGUID)(Event->ExtendedData[i].DataPtr); break; case EVENT_HEADER_EXT_TYPE_SID: Sid = (PBYTE)(Event->ExtendedData[i].DataPtr); break; case EVENT_HEADER_EXT_TYPE_TS_ID: SessionID = (PEVENT_EXTENDED_ITEM_TS_ID)(Event->ExtendedData[i].DataPtr); break; case EVENT_HEADER_EXT_TYPE_INSTANCE_INFO: Instance = (PEVENT_EXTENDED_ITEM_INSTANCE)(Event->ExtendedData[i].DataPtr); break; case EVENT_HEADER_EXT_TYPE_STACK_TRACE32: Stack32 = (PULONG)(Event->ExtendedData[i].DataPtr); FrameCount = Event->ExtendedData[i].DataSize / 4; break; case EVENT_HEADER_EXT_TYPE_STACK_TRACE64: Stack64 = (PULONG64)(Event->ExtendedData[i].DataPtr); FrameCount = Event->ExtendedData[i].DataSize / 8; break; default: break; } } VPrintFToFile(FALSE, LogContext, L"\r\n\t<System>"); // // Provider element: Name is not printed for Wbem events since it // can be localized and, hence, belongs in the <RenderingInfo> element. // VPrintFToFile(FALSE, LogContext, L"\r\n\t\t<Provider"); if ((EventInfo != NULL) && (IS_WBEM_EVENT(EventInfo) == 0) && (TEI_PROVIDER_NAME(EventInfo) != NULL)) { VPrintFToFile(FALSE, LogContext, L" Name=\"%s\"", TEI_PROVIDER_NAME(EventInfo)); } Guid = &Event->EventHeader.ProviderId; if (Event->EventHeader.Flags & EVENT_HEADER_FLAG_CLASSIC_HEADER) { Guid = EventInfo ? &EventInfo->ProviderGuid : NULL; } if (Guid != NULL) { Status = GuidToBuffer((PBYTE)Guid, DataLeft, (PBYTE)&GuidString, GuidStringSize, &Consumed); if (Status == ERROR_SUCCESS) { VPrintFToFile(FALSE, LogContext, L" Guid=\"%s", GuidString); } } VPrintFToFile(FALSE, LogContext, L"\" />"); VPrintFToFile(FALSE, LogContext, L"\r\n\t\t<EventID>%u</EventID>" L"\r\n\t\t<Version>%u</Version>" L"\r\n\t\t<Level>%u</Level>" L"\r\n\t\t<Task>%u</Task>" L"\r\n\t\t<Opcode>%u</Opcode>" L"\r\n\t\t<Keywords>0x%I64X</Keywords>", Header->EventDescriptor.Id, Header->EventDescriptor.Version, Header->EventDescriptor.Level, Header->EventDescriptor.Task, Header->EventDescriptor.Opcode, Header->EventDescriptor.Keyword); Move64(&Header->TimeStamp, (PLARGE_INTEGER)&FileTime); Status = FileTimeToBuffer((PBYTE)&FileTime, sizeof(FILETIME), (PBYTE)&DateTimeString[0], DateTimeStringSize, &Consumed); if (Status == ERROR_SUCCESS) { VPrintFToFile(FALSE, LogContext, L"\r\n\t\t<TimeCreated SystemTime=\"%s\" />", DateTimeString); } // // ActivityId is in the event header. // RelatedActivityID is the ExtendedData of the event. // VPrintFToFile(FALSE, LogContext, L"\r\n\t\t<Correlation "); Status = GuidToBuffer((PBYTE)&Header->ActivityId, sizeof(GUID), (PBYTE)&GuidString, GuidStringSize, &Consumed); if (Status == ERROR_SUCCESS) { VPrintFToFile(FALSE, LogContext, L"ActivityID=\"%s\"", (PWSTR)GuidString); } if (RelatedActivityID != NULL) { Status = GuidToBuffer((PBYTE)RelatedActivityID, sizeof(GUID), (PBYTE)&GuidString, ULONG_MAX, &Consumed); if (Status == ERROR_SUCCESS) { VPrintFToFile(FALSE, LogContext, L" RelatedActivityID=\""); VPrintFToFile(FALSE, LogContext, L"%s\"", GuidString); } } VPrintFToFile(FALSE, LogContext, L" />"); // // Execution parameters // VPrintFToFile(FALSE, LogContext, L"\r\n\t\t<Execution" L" ProcessID=\"%u\"" L" ThreadID=\"%u\"" L" ProcessorID=\"%u\" ", Header->ProcessId, Header->ThreadId, Event->BufferContext.ProcessorNumber); if (SessionID != NULL) { VPrintFToFile(FALSE, LogContext, L" SessionID=\"%lu\"", SessionID->SessionId); } if (LogContext->IsPrivateLogger != FALSE) { VPrintFToFile(FALSE, LogContext, L" KernelTime=\"%I64u\" />", Header->ProcessorTime); } else { VPrintFToFile(FALSE, LogContext, L" KernelTime=\"%lu\" UserTime=\"%lu\" />", Header->KernelTime * LogContext->TimerResolution, Header->UserTime * LogContext->TimerResolution); } // // For simplicity, the eventual call stack is not dumped. The call stack // structure can be either EVENT_EXTENDED_ITEM_STACK_TRACE32 or // EVENT_EXTENDED_ITEM_STACK_TRACE64. These structures are pointed to by Stack32 // and Stack64 variables, respectively, depending on machine architecture. // VPrintFToFile(FALSE, LogContext, L"\r\n\t</System>"); }
static void WINAPI _HandleEvent(_In_ PEVENT_RECORD per) { if (!_s_fIsEnding) { PTRACE_EVENT_INFO ptei = nullptr; // Populate ptei. { DWORD cbEventInfo = 0; DWORD status = TdhGetEventInformation(per, 0, nullptr, nullptr, &cbEventInfo); if (ERROR_INSUFFICIENT_BUFFER == status) { ptei = (TRACE_EVENT_INFO*)malloc(cbEventInfo); if (ptei != nullptr) { status = TdhGetEventInformation(per, 0, nullptr, ptei, &cbEventInfo); if (status != ERROR_SUCCESS) { free(ptei); ptei = nullptr; } } } } // Timestamp { FILETIME ft; ft.dwHighDateTime = per->EventHeader.TimeStamp.HighPart; ft.dwLowDateTime = per->EventHeader.TimeStamp.LowPart; SYSTEMTIME st; FileTimeToSystemTime(&ft, &st); SystemTimeToTzSpecificLocalTime(nullptr, &st, &st); wchar_t wszDate[100]; GetDateFormatEx(LOCALE_NAME_INVARIANT, NULL, &st, L"yyyyy-MM-dd", wszDate, ARRAYSIZE(wszDate), nullptr); wchar_t wszTime[100]; GetTimeFormatEx(LOCALE_NAME_INVARIANT, NULL, &st, L"HH:mm:ss", wszTime, ARRAYSIZE(wszTime)); // yyyy-MM-dd HH:mm:ss:fffffff // Windows refuses to give us milliseconds for free, let alone fractions of milliseconds wprintf(L"%s ", wszDate); wprintf(L"%s", wszTime); wprintf(L".%07u, ", ft.dwLowDateTime % ((1000000000 /*nanoseconds per second*/) / (100 /* nanoseconds per interval */))); } // Thread ID wprintf(L"Thread %lu, ", per->EventHeader.ThreadId); // Provider name or GUID { const wchar_t* providerName = ptei ? TEI_PROVIDER_NAME(ptei) : nullptr; if (providerName != nullptr) { wprintf(L"%s, ", (BYTE*)ptei + ptei->ProviderNameOffset); } else { BSTR bstrGuid; if (SUCCEEDED(StringFromCLSID(per->EventHeader.ProviderId, &bstrGuid))) { wprintf(L"%s, ", bstrGuid); ::CoTaskMemFree(bstrGuid); } } } // Task name or id { const wchar_t* taskName = ptei ? TEI_TASK_NAME(ptei) : nullptr; if (taskName != nullptr) { wprintf(L"%s, ", taskName); } else { // printf converts 8-bit chars to 16-bit ints, in case you don't know wprintf(L"%hu, ", per->EventHeader.EventDescriptor.Task); } } // Event ID // wprintf(L"%hu, ", per->EventHeader.EventDescriptor.Id); // Activity ID //{ // BSTR bstrGuid; // if (SUCCEEDED(StringFromCLSID(per->EventHeader.ActivityId, &bstrGuid))) // { // wprintf(L"%s, ", bstrGuid); // ::CoTaskMemFree(bstrGuid); // } //} // Opcode name or ID { wchar_t* opcodeName = ptei ? TEI_OPCODE_NAME(ptei) : nullptr; if (opcodeName != nullptr) { wprintf(L"%s, ", (BYTE*)ptei + ptei->OpcodeNameOffset); } else { wprintf(L"%hu, ", per->EventHeader.EventDescriptor.Opcode); } } // Payload if (EVENT_HEADER_FLAG_STRING_ONLY == (per->EventHeader.Flags & EVENT_HEADER_FLAG_STRING_ONLY)) { wprintf(L"%s", (LPWSTR)per->UserData); } else { for (USHORT i = 0; i < ptei->TopLevelPropertyCount; i++) { DWORD status = PrintProperties(per, ptei, i, nullptr, 0); if (ERROR_SUCCESS != status) { wprintf(L"Printing top level properties failed."); } wprintf(L", "); } } // endl wprintf(L"\r\n"); // combat stdout buffering _flushall(); if (ptei != nullptr) { free(ptei); ptei = nullptr; } } else { if (!_s_fIsClosed) { CloseTrace(*((TRACEHANDLE*)per->UserContext)); _s_fIsClosed = true; } } }