Cannot find output of Win32 TraceLogging

Question

I tried to replicate the short sample program for TraceLogging that Microsoft provides (see below, with minor changes). I completed the "development" (rather copy) in Visual Studio 2019. All is fine, compiles without issues, runs without issues, but nowhere on my PC I can find an updated *.etl or *.log file, nor do I find an entry somewhere in the Event Viewer.

I carefully read the Microsoft documentation and I searched the Internet for many hours, but no useful findings.

I know that I'm stupid from time to time and I must miss something obvious, but what is it? Any hints, please? Many thanks!

#include <windows.h> // or <wdm.h> for kernel-mode.
#include <winmeta.h>
#include <TraceLoggingProvider.h>
#include <stdio.h>

// Define the GUID to use in TraceLoggingRegister 
// {5B5852D4-DC24-4A0F-87B6-9115AE9D2768}
TRACELOGGING_DEFINE_PROVIDER (      // defines g_hProvider
    g_hProvider,                    // Name of the provider variable
    "Test-Test",                    // Human-readable name of the provider
    (0x5b5852d4, 0xdc24, 0x4a0f, 0x87, 0xb6, 0x91, 0x15, 0xae, 0x9d, 0x27, 0x68) );     // Provider GUID


int main ( int argc, char *argv[] ) // or DriverEntry for kernel-mode.
{
    HRESULT hrRegister;

    hrRegister = TraceLoggingRegister ( g_hProvider );
    if ( !SUCCEEDED ( hrRegister ) ) {
        printf ( "TraceLoggingRegister failed. Stopping." );
        return 1;
    }
    TraceLoggingWrite (
        g_hProvider,
        "MyEvent1",
        // TraceLoggingChannel ( WINEVENT_CHANNEL_CLASSIC_TRACE ),
        // TraceLoggingLevel ( WINEVENT_LEVEL_CRITICAL ),
        TraceLoggingString ( argv[0], "arg0" ),     // field name is "arg0"
        TraceLoggingInt32 ( argc ) );               // field name is implicitly "argc"

    TraceLoggingUnregister ( g_hProvider );
    return 0;
}

Answer 1

First of all, running this C++ code will not generate the .log or .etl file you want, it just sends the TraceLogging event, you need to capture it in other ways to generate the etl file.

According to the MSDN,You have two steps to capture TraceLogging events：

1. Capture trace data with WPR
2. Capture TraceLogging events on Windows Phone

First create a .WPRP file, I used the same C++ code and WPRP file from MSDN as follow.

test.cpp

#include <windows.h> // or <wdm.h> for kernel-mode.
#include <winmeta.h>
#include <TraceLoggingProvider.h>
#include <stdio.h>


    // Define the GUID to use in TraceLoggingProviderRegister 
    // {3970F9cf-2c0c-4f11-b1cc-e3a1e9958833}
TRACELOGGING_DEFINE_PROVIDER(
    g_hMyComponentProvider,
    "SimpleTraceLoggingProvider",
    (0x3970f9cf, 0x2c0c, 0x4f11, 0xb1, 0xcc, 0xe3, 0xa1, 0xe9, 0x95, 0x88, 0x33));


void main()
{

    char sampleValue[] = "Sample value";

    // Register the provider
    TraceLoggingRegister(g_hMyComponentProvider);
    // Log an event
    TraceLoggingWrite(g_hMyComponentProvider, // handle to my provider
        "HelloWorldTestEvent",              // Event Name that should uniquely identify your event.
        TraceLoggingValue(sampleValue, "TestMessage")); // Field for your event in the form of (value, field name).
    // Stop TraceLogging and unregister the provider
    TraceLoggingUnregister(g_hMyComponentProvider);
}

Sample WPRP file

<?xml version="1.0" encoding="utf-8"?>
<!-- TODO: 
1. Find and replace "SimpleTraceLoggingProvider" with the name of your provider.
2. See TODO below to update GUID for your event provider
-->
<WindowsPerformanceRecorder Version="1.0" Author="Microsoft Corporation" Copyright="Microsoft Corporation" Company="Microsoft Corporation">
  <Profiles>
    <EventCollector Id="EventCollector_SimpleTraceLoggingProvider" Name="SimpleTraceLoggingProvider">
      <BufferSize Value="64" />
      <Buffers Value="4" />
    </EventCollector>

    <!-- TODO: 
 1. Update Name attribute in EventProvider xml element with your provider GUID, eg: Name="3970F9cf-2c0c-4f11-b1cc-e3a1e9958833". Or
    if you specify an EventSource C# provider or call TraceLoggingRegister(...) without a GUID, use star (*) before your provider
    name, eg: Name="*MyEventSourceProvider" which will enable your provider appropriately.  
 2. This sample lists one EventProvider xml element and references it in a Profile with EventProviderId xml element. 
    For your component wprp, enable the required number of providers and fix the Profile xml element appropriately
-->
    <EventProvider Id="EventProvider_SimpleTraceLoggingProvider" Name="*SimpleTraceLoggingProvider" />

    <Profile Id="SimpleTraceLoggingProvider.Verbose.File" Name="SimpleTraceLoggingProvider" Description="SimpleTraceLoggingProvider" LoggingMode="File" DetailLevel="Verbose">
      <Collectors>
        <EventCollectorId Value="EventCollector_SimpleTraceLoggingProvider">
          <EventProviders>
            <!-- TODO:
 1. Fix your EventProviderId with Value same as the Id attribute on EventProvider xml element above
-->
            <EventProviderId Value="EventProvider_SimpleTraceLoggingProvider" />
          </EventProviders>
        </EventCollectorId>
      </Collectors>
    </Profile>

    <Profile Id="SimpleTraceLoggingProvider.Light.File" Name="SimpleTraceLoggingProvider" Description="SimpleTraceLoggingProvider" Base="SimpleTraceLoggingProvider.Verbose.File" LoggingMode="File" DetailLevel="Light" />
    <Profile Id="SimpleTraceLoggingProvider.Verbose.Memory" Name="SimpleTraceLoggingProvider" Description="SimpleTraceLoggingProvider" Base="SimpleTraceLoggingProvider.Verbose.File" LoggingMode="Memory" DetailLevel="Verbose" />
    <Profile Id="SimpleTraceLoggingProvider.Light.Memory" Name="SimpleTraceLoggingProvider" Description="SimpleTraceLoggingProvider" Base="SimpleTraceLoggingProvider.Verbose.File" LoggingMode="Memory" DetailLevel="Light" />

  </Profiles>
</WindowsPerformanceRecorder>

Then start the capture using WPR from an elevated (run as Administrator) Command Prompt window.

wpr.exe -start C:\Users\songz\Desktop\test.wprp

Next you may run the application that contains your events and stop the trace capture.

wpr.exe -stop C:\Users\songz\Desktop\test.etl description

This can generate the etl file you need normally.

After completing the above operations, you should capture TraceLogging events. According to the github, you can use the following commands:

xperf -start MySession -f C:\Users\songz\Desktop\test.etl -on 3970F9cf-2c0c-4f11-b1cc-e3a1e9958833

xperf -stop MySession

Note:You should use like xperf -start MySession -f MyFile.etl -on Id

Finally you can view the corresponding information through WPA.

Answer 2

Zhu Song, thank you very much for your input! Your comments brought me to the right track. Well, I did not follow strictly your text, but I found new stuff to read.

I want the controller to be part of my application as well. So, what I did is roughly the following:

• Prepare EVENT_TRACE_PROPERTIES structure
• TraceLogRegister
• StartTrace
• EnableTraceEx2 (enable)
• TraceLoggingWrite
• TraceLoggingUnregister
• EnableTraceEx2 (disable)
• ControlTrace (stop)

This resulted in an xxx.etl file that I could view with tracerpt or WPA.

Thanks again! I'm all fine now.

This is the code in detail:

#include <windows.h> // or <wdm.h> for kernel-mode.
#include <winmeta.h>
#include <TraceLoggingProvider.h>
#include <evntrace.h>
#include <stdio.h>
#include <strsafe.h>

#define LOGFILE_NAME TEXT(".\\Test-Test.etl")
#define LOGSESSION_NAME TEXT("Test-Test-Session")


// Define the GUID to use in TraceLoggingRegister 
// {5B5852D4-DC24-4A0F-87B6-9115AE9D2768}
TRACELOGGING_DEFINE_PROVIDER (      // defines g_hProvider
    g_hProvider,                    // Name of the provider variable
    "Test-Test",                    // Human-readable name of the provider
    (0x5b5852d4, 0xdc24, 0x4a0f, 0x87, 0xb6, 0x91, 0x15, 0xae, 0x9d, 0x27, 0x68) );     // Provider GUID

static const GUID ProviderGUID = { 0x5b5852d4, 0xdc24, 0x4a0f, {0x87, 0xb6, 0x91, 0x15, 0xae, 0x9d, 0x27, 0x68} };


int main ( int argc, char *argv[] ) // or DriverEntry for kernel-mode.
{
    TRACEHANDLE hTrace = 0;
    EVENT_TRACE_PROPERTIES *petProperties;
    HRESULT hrRegister;

    ULONG bufferSize, ret_val;

    bufferSize = sizeof ( EVENT_TRACE_PROPERTIES ) + sizeof ( LOGFILE_NAME ) + sizeof ( LOGSESSION_NAME ) + 512;    // The additional bytes are necessary because the path of thr LOGFILE_NAME is expanded
    petProperties = (EVENT_TRACE_PROPERTIES *) malloc ( bufferSize );
    if ( petProperties == NULL ) {
        printf ( "Unable to allocate %d bytes for properties structure.\n", bufferSize );
        return 1;
    }

    ZeroMemory ( petProperties, bufferSize );
    petProperties->Wnode.BufferSize = bufferSize;
    petProperties->Wnode.Flags = WNODE_FLAG_TRACED_GUID;
    petProperties->Wnode.ClientContext = 1;
    petProperties->Wnode.Guid = ProviderGUID;
    petProperties->LogFileMode = EVENT_TRACE_FILE_MODE_SEQUENTIAL | EVENT_TRACE_PRIVATE_LOGGER_MODE | EVENT_TRACE_PRIVATE_IN_PROC;
    petProperties->MaximumFileSize = 100;       // was 1
    petProperties->BufferSize = 512;
    petProperties->MinimumBuffers = 8;
    petProperties->MaximumBuffers = 64;
    petProperties->LoggerNameOffset = sizeof ( EVENT_TRACE_PROPERTIES );
    petProperties->LogFileNameOffset = sizeof ( EVENT_TRACE_PROPERTIES ) + sizeof ( LOGSESSION_NAME );
    StringCbCopy ( (LPWSTR) ((char *) petProperties + petProperties->LogFileNameOffset), sizeof ( LOGFILE_NAME ), LOGFILE_NAME );

    hrRegister = TraceLoggingRegister ( g_hProvider );
    if ( !SUCCEEDED ( hrRegister ) ) {
        printf ( "TraceLoggingRegister failed. Stopping.\n" );
        return 1;
    }

    ret_val = StartTrace ( &hTrace, LOGSESSION_NAME, petProperties );
    if ( ret_val != ERROR_SUCCESS ) {
        printf ( "StartTrace failed with %i\n", ret_val );
        if ( ret_val != ERROR_ALREADY_EXISTS )
            return 1;
    }

    ret_val = EnableTraceEx2 ( hTrace, &ProviderGUID, EVENT_CONTROL_CODE_ENABLE_PROVIDER, TRACE_LEVEL_VERBOSE, 0, 0, 0, NULL );
    if ( ret_val != ERROR_SUCCESS ) {
        printf ( "EnableTraceEx2(enable) failed with %i\n", ret_val );
        ret_val = ControlTrace ( hTrace, LOGSESSION_NAME, petProperties, EVENT_TRACE_CONTROL_STOP );
        if ( ret_val != ERROR_SUCCESS ) {
            printf ( "ControlTrace(stop) failed with %i\n", ret_val );
        }
        return 1;
    }

    if ( TraceLoggingProviderEnabled ( g_hProvider, 0, 0 ) )
        printf ( "TraceLoggingProvider enabled\n" );
    else
        printf ( "TraceLoggingProvider NOT enabled\n" );

    TraceLoggingWrite (
        g_hProvider,
        "MyEvent1",
        TraceLoggingString ( argv[0], "arg0" ),     // field name is "arg0"
        TraceLoggingInt32 ( argc ) );               // field name is implicitly "argc"

    TraceLoggingUnregister ( g_hProvider );

    ret_val = EnableTraceEx2 ( hTrace, &ProviderGUID, EVENT_CONTROL_CODE_DISABLE_PROVIDER, TRACE_LEVEL_VERBOSE, 0, 0, 0, NULL );
    if ( ret_val != ERROR_SUCCESS ) {
        printf ( "EnableTraceEx2(disable) failed with %i\n", ret_val );
    }
    ret_val = ControlTrace ( hTrace, LOGSESSION_NAME, petProperties, EVENT_TRACE_CONTROL_STOP );
    if ( ret_val != ERROR_SUCCESS ) {
        printf ( "ControlTrace(stop) failed with %i\n", ret_val );
    }

    return 0;
}

Answer 3

ETW is an event routing system. TraceLoggingWrite means "send the event to ETW". But if nobody is interested in your event then ETW will just ignore it.

To collect the data from TraceLoggingWrite, there needs to be an ETW session that is listening for events from you. There are many ways to start and control ETW sessions, including the StartTrace API, the AutoLogger registry key, the WPR tool, and the TRACELOG tool.

I usually prefer the TRACELOG tool. It is included with the Windows SDK, so it is installed if I have installed Visual Studio, and it will be on my path if I open a "Developer command prompt". On my computer, TRACELOG is in C:\Program Files (x86)\Windows Kits\10\bin\10.0.22000.0\x86\tracelog.exe.

To capture events from the provider you show in your source code, I would run:

TRACELOG -start MySessionName -f MySession.etl -guid #5B5852D4-DC24-4A0F-87B6-9115AE9D2768

After my code has run, I would stop the trace with:

TRACELOG -stop MySessionName

I could then use various tools to decode the trace. I usually use the TRACEFMT tool.

TRACEFMT MySession.etl