Debugging ETW Occasion Drops in Excessive-Throughput Purposes

I used to be engaged on a manufacturing software not too long ago the place we rely closely on ETW (Occasion Tracing for Home windows) to emit high-frequency occasions. We’re speaking about tens of millions of occasions each few seconds. We began noticing gaps in our telemetry—we have been operating into occasion drops.

This was a important concern. If you’re dropping occasions, you might be flying blind. I had to determine which supplier was producing probably the most occasions and the place the bottleneck was. The problem was that we already had an current telemetry agent listening to those occasions, and I didn’t wish to disrupt its operation.

How do you debug a system that’s already struggling beneath load with out making it worse? It was onerous to discover a simple information on “spying” on current classes with out breaking them. Most of my analysis led me to generic documentation, so I made a decision to doc the strategy I used to isolate the noisy supplier and measure the drops.

There have been a number of issues I wanted to determine:

1. Find out how to establish the present session and suppliers
2. Find out how to run a parallel “spy” session
3. Find out how to analyze the dropped occasion information

Let’s undergo them one after the other.

What’s ETW anyway?

Earlier than we repair it, let’s briefly contact on what ETW is for the uninitiated. In case you have a couple of minutes, this video does an excellent job of explaining what ETW is and the way it works:

Here’s a diagram from Microsoft’s weblog that highlights the principle parts of ETW:

As illustrated within the diagram above, ETW depends on a number of distinct parts working in unison:

• Controllers (Prime Left): These are instruments like logman or the wpr command. They inform the system, “Hey, create Session 1 and begin listening.”
• Suppliers (Backside Left): That is your software code. It fires occasions into the void (“One thing occurred!”), normally with out realizing who’s listening.
• The Kernel Session (Inexperienced Field): That is the important piece for debugging drops. When a session is energetic, the Kernel allocates Buffers (the blue file icons) in non-paged reminiscence. That is the place occasions sit earlier than they’re written to a file or learn by a client.
• Shoppers (Backside Proper): These are your monitoring brokers. They request information from the buffers.

The issue of “Occasion Drops” is actually a site visitors jam within the inexperienced field. As proven within the diagram, information flows from Supplier → Buffer → Shopper. In case your Supplier fills these blue Buffers quicker than the Shopper can empty them, the Kernel has no alternative however to discard the most recent occasions.

It’s designed to be extremely quick, however physics nonetheless applies: for those who pour water right into a funnel quicker than it drains, it spills.

1. Find out how to establish the present session and suppliers

Step one was determining precisely what the present monitoring agent was doing. I couldn’t simply guess the Supplier IDs. Home windows has a built-in command-line device known as logman that’s good for this.

I ran the next command to checklist all presently operating occasion tracing classes:

This produces an output much like this:

Knowledge Collector Set                      Kind                          Standing
-------------------------------------------------------------------------------
EventLog-Software                    Hint                         Operating
EventLog-System                         Hint                         Operating
NtfsLog                                 Hint                         Operating
Round Kernel Context Logger          Hint                         Operating
MyDebugSession                          Hint                         Operating

This gave me a listing of energetic classes. I discovered the session comparable to our telemetry agent (MyDebugSession within the instance above). By querying that particular session, I may see precisely which Suppliers (by GUID or identify) it was listening to.

Run the next command to search out all of the supplier GUIDs a session is listening to:

logman question "MyDebugSession" -ets

This command will produce a verbose output, however search for the Supplier: sections:

Title:                 MyDebugSession
Standing:               Operating
...

Supplier:
Title:                 {1AACEA33-2593-5BEE-5746-BCEDB745CD07}
Supplier Guid:        {1AACEA33-2593-5BEE-5746-BCEDB745CD07}
...

Supplier:
Title:                 {6A03660A-10F6-51E1-DAB5-343DA7A7680F}
Supplier Guid:        {6A03660A-10F6-51E1-DAB5-343DA7A7680F}
...

Subsequent, I grabbed all of the supplier GUIDs and put them in a suppliers.txt file:

{1AACEA33-2593-5BEE-5746-BCEDB745CD07}
{6A03660A-10F6-51E1-DAB5-343DA7A7680F}
{B39F4EF0-34CB-5F8E-578D-183AAEA6CB31}

2. Find out how to run a parallel spy session

Right here is the difficult half. I couldn’t cease the present agent to run my assessments. I wanted to run a parallel spy session.

ETW permits a number of classes to subscribe to the identical supplier. This implies I may spin up a new session, subscribe to the similar suppliers present in Step 1, and file the info to a file for evaluation, all whereas the manufacturing agent saved operating.

I used logman once more to create this spy session:

logman create hint "SpySession" -pf "suppliers.txt" -o "C:tempspy_events.etl" -ets

I let this run for a number of seconds—simply sufficient to seize the high-throughput burst—after which stopped it utilizing this command:

logman cease "SpySession" -ets

The ensuing spy_events.etl file turned out to be round 2GB whereas capturing occasions for only some seconds. That was my first clue that the amount was large.

3. Find out how to analyze the dropped occasion information

As soon as I had the .etl file (the usual format for ETW logs), I ran an evaluation on it. You should utilize instruments like Home windows Efficiency Analyzer (WPA) or tracerpt to parse these information. I ended up utilizing tracerpt as it’s obtainable by default whereas WPA requires a separate set up.

You possibly can run an evaluation utilizing this command:

tracerpt spy_events.etl -y -summary abstract.txt

The evaluation supplied precisely what I used to be searching for: a breakdown of occasion counts and, crucially, the “Whole Occasions Misplaced” counter.

Here’s what the info regarded like (truncated):

Information Processed:
    spy_events.etl
Whole Buffers Processed 248423
Whole Occasions  Processed 6110264
Whole Occasions  Misplaced      5580908
Begin Time              Tuesday, December 23, 2025
...
+---------------------------------------------------------------------------------------------------------+
|Occasion Rely   Occasion Title           Occasion ID        Model         Guid                                  |
+---------------------------------------------------------------------------------------------------------+
|          2   EventTrace           0               2               {68fdd900-4a3e-11d1-84f4-0000f80464e3}|
|     143003                        1               5               {c4859ff3-8549-54e3-adc3-dfcb805b4146}|
|      63916                        6               2               {c4859ff3-8549-54e3-adc3-dfcb805b4146}|
|    1040793                        9               2               {c4859ff3-8549-54e3-adc3-dfcb805b4146}|
|    1308511                        11              2               {c4859ff3-8549-54e3-adc3-dfcb805b4146}|
| ...
+---------------------------------------------------------------------------------------------------------+

It was instantly apparent. Occasion ID 9 and 11 have been spamming the system with over one million occasions every in that brief window. The kernel buffers merely couldn’t sustain, leading to over 5 million “Whole Occasions Misplaced.”

These Occasion IDs are specified within the code whereas creating a brand new ETW occasion, so a easy GREP took me straight to the supply. The repair was clear: I needed to both throttle the occasions, batch a number of occasions into one, or cut back the gathering verbosity degree in our monitoring agent in order that we don’t take heed to all occasions in manufacturing.

Conclusion

I had enjoyable digging into the decrease ranges of Home windows tracing and determining that you would be able to primarily “wiretap” your individual functions with out bringing them down. Debugging high-frequency methods can really feel like attempting to repair a jet engine whereas flying, however with instruments like logman and the flexibility to run parallel ETW classes, you may peek beneath the hood safely.

I’m fairly certain there are extra superior methods to do that with WPA (Home windows Efficiency Analyzer), however for a fast prognosis on a manufacturing machine the place you may’t set up new instruments, logman and tracerpt are good options.

If you’re coping with mysterious information gaps in Home windows, I extremely suggest getting comfy with logman. It would prevent days of guessing.

I hope this text helps those that are attempting to debug related high-throughput points! 😄