A few months ago I wrote about how many processes on my system were waking up and wasting CPU time for no good reason, thus wasting battery power, electricity, and CPU power. I was surprised that nobody called me out on the hypocrisy of my complaints because UIforETW, my open-source ETW trace recording and management tool, was not well behaved when idle.
This has now been fixed.
UIforETW creates numerous threads that monitor performance related aspects of the system, such as battery drain, CPU power consumption, timer status, user input, etc. These data are emitted as ETW events that show up in the recorded traces and which can then be used to help understand and analyze the ETW traces.
This is all good, and the overhead of these monitoring threads was designed to be small enough that it would not perturb the processes being profiled.
However “small enough overhead” on a busy system is not the same as “small enough overhead” on an idle system. Originally when UIforETW was open but not currently tracing these threads were still running – waking up many times per second, calculating data, and emitting events that were effectively directed to /dev/null.
As of change 72c71dd I’ve rewritten the monitors so that they start and stop with tracing. This dropped the number of context switches and the CPU usage (monitored with sysinternals’ procexp) of an idle UIforETW significantly. However I was still seeing about ten context switches per second. Hmmm…
I used UIforETW\bin\metatrace.bat to record a trace of UIforETW sitting idle. metatrace.bat is useful because it uses a different kernel provider and can therefore be used to profile UIforETW even during trace startup and shutdown. The trace showed that the context switches were on a windows message call stack. I tried using Spy++ to see what type of message was coming in but couldn’t get that to work. I then noticed that the bursts of activity were happening exactly once a second, as can be seen on the WPA screenshot below which graphs context switch counts for UIforETW against elapsed time in seconds:
A search for SetTimer in the UIforETW source showed a call that I had added months ago. Each time a timer message is received UIforETW checks to see if tracing to a file has been running too long. This is a good feature but doesn’t need to be running when tracing is not, so I changed the code so that now the timer only runs during tracing. I also changed it to wake up every thirty seconds instead of every second – precise timing is not relevant for this feature.
The net result of these changes is that now if you have UIforETW running and you aren’t recording a trace then the CPU overhead is zero. UIforETW will go for long periods of time without a single context switch. This means that UIforETW has gone from being a poster-child for a poorly behaved background application to proof that staying perfectly idle is actually quite easy. This blog post was easy to write but I still spent longer writing it than I did making the changes to UIforETW.
It’s worth noting that UIforETW didn’t lose any functionality from these changes. And it’s also worth noting that I did not try to reduce the number of threads, just the number of threads that were waking up for no reason. So, for instance, the DirectoryMonitorThread – which waits on file notification events so that UIforETW can update its trace list automatically – is still running all the time. It wakes up when it needs to do something and is otherwise just sitting on the kernel’s list of threads that don’t need to run.
So, I repeat my entreaty: write your software so that it doesn’t wake up periodically “just in case”. Wake up only when necessary, and be particularly careful about this when your application is not active. If you are wasteful then I will uninstall your software, and encourage others to do likewise.
And you should grab the latest version of UIforETW, for this improvement and a few others.
Aside: What is UIforETW? It’s an open source tool for recording and managing ETW traces to allow investigation of performance problems on Windows in incredible detail. You can find more details here (or at this more memorable url: https://tinyurl.com/etwcentral).