How to properly use and visualize Start Stop activities in a custom ETW provider

[exelix11]

Context I'm adding profiling support to an application by emitting ETW events that represent logical function calls. Currently, after i capture an ETL trace i use a tool to convert it to json for use on speedscope.app, but this produces jsons up to 300MB which does not feel optimal.

The problem I would like to use something like perfview or Windows Performance Analyzer directly, so i looked into the ETW activity pattern which seems to be meant for this kind of use case, however there is not much documentation.

I tried to follow this reference from ms docs, from what i understand this event pattern should allow perfview to group activities and plot them in a hierarchy view.

Several stackoverflow questions point to the fact that this should be possible, however i couldn't find any working reference code in C.

Repro

I tried writing the following code

#include <stdint.h>
#include <stdbool.h>

#include <windows.h>
#include <winmeta.h>
#include <traceloggingprovider.h>

TRACELOGGING_DEFINE_PROVIDER(
    g_profiler,
    "MyProfiler",
    // Example from https://learn.microsoft.com/it-it/windows/win32/api/traceloggingprovider/nf-traceloggingprovider-tracelogging_define_provider
    // {ce5fa4ea-ab00-5402-8b76-9f76ac858fb5}
    (0xce5fa4ea, 0xab00, 0x5402, 0x8b, 0x76, 0x9f, 0x76, 0xac, 0x85, 0x8f, 0xb5));

void RandomSleep() 
{
    Sleep(10 + rand() % 1000);
}

int main(int argc, char** argv)
{
    if (!SUCCEEDED(TraceLoggingRegister(g_profiler)))
        return -1;

    // Expected flamegraph:
    //  inner()         |---------|
    //  outer()  |---------------------| ... repeat

    while (true) {
        GUID outer, inner;
        if (!SUCCEEDED(CoCreateGuid(&outer))) return -2;
        if (!SUCCEEDED(CoCreateGuid(&inner))) return -3;

        printf("> enter outer\n");
        TraceLoggingWriteActivity(
            g_profiler, "Function",
            &outer, NULL,
            TraceLoggingOpcode(WINEVENT_OPCODE_START),
            TraceLoggingString("outer()", "func_name")
        );

        RandomSleep();

        printf(">> enter inner\n");
        TraceLoggingWriteActivity(
            g_profiler, "Function",
            &inner, &outer,
            TraceLoggingOpcode(WINEVENT_OPCODE_START),
            TraceLoggingString("inner()", "func_name")
        );

        RandomSleep();

        printf(">> leave inner\n");
        TraceLoggingWriteActivity(
            g_profiler, "Function",
            &inner, NULL,
            TraceLoggingOpcode(WINEVENT_OPCODE_STOP)
        );

        RandomSleep();

        printf("> leave outer\n");
        TraceLoggingWriteActivity(
            g_profiler, "Function",
            &outer, NULL,
            TraceLoggingOpcode(WINEVENT_OPCODE_STOP)
        );

        RandomSleep();
    }

    return 0;
}

You can build it from Visual Studio or just the command line tools with cl Repro.c Advapi32.lib Ole32.lib (i only tried x64 tools).

Then I start an event collection like this:

And the events are collected properly:

However, when i try to open the stacks view for start-stop activities i get Error: Could not find stack source Any Stacks (with StartStop Activities)

Questions

• Is there a mistake in the code or have I misunderstood the purpose of start stop activities ?
• If not activities, is there a way to plot custom function stacks in perfview ?
• Is there a way to generate flamegraphs from this data ?

[brianrob]

Your code looks generally correct to me, and so does the events view. Would you be able to share a sample trace containing these events? The error that you've described usually represents a programming error in PerfView because we can't match the view name up with a data stream. If you can share a trace, I can try to repro and debug this.

[exelix11]

Thank you for replying, here's a sample trace: perfviewdata.etl.zip

To create this i did the following: 1) built the repro with the cl command above 2) In a clean Windows Sandbox instance started the binary 3) Then ran PerfView.exe "/DataFile:PerfViewData.etl" /BufferSizeMB:256 /StackCompression /CircularMB:500 /KernelEvents:None /ClrEvents:None /Providers:"ce5fa4ea-ab00-5402-8b76-9f76ac858fb5" /NoGui /FocusProcess:"main.exe" /NoNGenRundown collect (this is the command auto generated by prefview itself) 4) Manually merge and zip the trace from perfview

[brianrob]

Thanks @exelix11. I'm not quite sure how you got the error Error: Could not find stack source Any Stacks (with StartStop Activities). The first issue that I see here is that your trace does not contain the event types required to even show this view. You will need:

1. TPL events (you can enable these by specifying /TPLEvents:Default).
2. Context switch events (you can enable these by specifying '/ThreadTime`).

I also recommend that you specify /KernelEvents:Default-Profile. This will provide enough context to resolve symbols in the stacks that you'll be looking at.

Hopefully that helps - let me know how it goes. If that doesn't work, please do share an updated trace.

[exelix11]

I tried again with the following command line PerfView.exe "/DataFile:PerfViewData.etl" /BufferSizeMB:256 /StackCompression /CircularMB:500 /KernelEvents:Default-Profile /TPLEvents:Default /ThreadTime /Providers:"ce5fa4ea-ab00-5402-8b76-9f76ac858fb5" /NoGui /FocusProcess:"main.exe" /NoNGenRundown collect

And i'm still missing the start stop activities view. PerfViewData.etl.zip

To be clear and please correct me if i misunderstand this feature, i'm trying to replicate what i see in this article https://learn.microsoft.com/en-us/archive/blogs/vancem/exploring-eventsource-activity-correlation-and-causation-features so i can get a view like this with my own events: However the source code and most links of the page are now missing and this feature seems barely documented elsewhere.

This view that i'm after doesn't seem to have any information outside of the custom ETW provider, does it really need the context switch events ? I'm just talking about this simple view, I do understand they will be needed later in case i want to correlate with other events like file io.