microsoft
Inconsistent CPU usage, why?
I have a trace, on Thread Time (with StartStopActivities), the method called HighCPUArraySort registered about 16 seconds (16471.5 inc) CPU time:
But on CPU stack, it shows only have about 8.5s (8515.0 inc) CPU time:
Why is it significantly smaller number on CPU view than it is on the activity view?
Trace session (etl) attached: 728d7e2465f04ab2992cb9177322507f.etl.zip
Can anyone help take a look? Thanks.
The difference comes from looking at Context Switch data in the first view which includes VM overhead. You have assigned only one core to that VM. That will delay processing threads which usually run concurrently. The second view is coming from CPU Sampling data which is more accurate in my opinion because that is CPU you did consume within your process. What stands out is that there are many CPU Sample and CSWitch events which have no stacks. ETW does not take any stack when it is not safe to do so. This looks like VM/Hypervisor overhead. You have also some thread pool starvation events logged which delay TPL tasks from running
Here's my understanding:
CPU stacks is basically a sample every 1 millisecond. Let's say your method is MyMethod(). When we observe it, we allocate 1ms to that method (as an approximation).
With Thread Time, we capture the stack for every thread when a context switch happens. This allows us to more accurately account for when a method was on the stack and when it stopped being on the stack.
As you can see - the view with proper start/stop tracking could have more duration. Of course, for the same reason, it could have less if you just happen to find it in two CPU stack samples but in reality it ran for shorter.
You'll see that there's roughly 2M samples in the thread time vs 10K in the stack view.
