Hi,
Could anyone suggest why accumulated CPU Time from Threads view does not remotely match the one from Summary page (the latter is much larger) ? E.g. I see the following numbers: sum cpu time from threads panel ~2m 20s and summary page gives me 5m 18s.
Thanks,
CPU Time in Threads view does not match CPU Time in Summary
-
- Posts: 7
- Joined: Thu Aug 04, 2011 11:15 am
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: CPU Time in Threads view does not match CPU Time in Summ
Hello,
The Summary tab shows the process CPU time as measured with corresponding platform-dependent function. Threads shows CPU time of running threads.
I can offer the following explanation why the process CPU time is larger than the sum of thread CPU times seen in Threads:
1. Threads shows Java threads only, while JVM may have other threads too. For example, those implementing the garbage collector. You application may use native code too, although it's less likely the case.
2. Threads shows live threads and recent dead threads only. If it's a long running application, the oldest dead threads outside the telemetry frame (1 hour by default) will not be shown.
Best regards,
Anton
The Summary tab shows the process CPU time as measured with corresponding platform-dependent function. Threads shows CPU time of running threads.
I can offer the following explanation why the process CPU time is larger than the sum of thread CPU times seen in Threads:
1. Threads shows Java threads only, while JVM may have other threads too. For example, those implementing the garbage collector. You application may use native code too, although it's less likely the case.
2. Threads shows live threads and recent dead threads only. If it's a long running application, the oldest dead threads outside the telemetry frame (1 hour by default) will not be shown.
Best regards,
Anton
-
- Posts: 7
- Joined: Thu Aug 04, 2011 11:15 am
Re: CPU Time in Threads view does not match CPU Time in Summ
Anton,
Thanks for your suggestions. Please, see my comments below.
Could it be that System Time must also be included? If so, any ideas how it could be measured from within YJP (after all yourkit can measure system time showing the line in cpu telemetry chart)?
Thanks for your suggestions. Please, see my comments below.
Does Threads time also include system time?Anton Katilin wrote: The Summary tab shows the process CPU time as measured with corresponding platform-dependent function. Threads shows CPU time of running threads.
Good point, thanks. However, even with 'Internal threads checkbox enabled' and adding Garbage Collector time (from Summary page) still summary cpu time is much higher. My last observation 8 min vs 3 min (threads + internal + gc time)Anton Katilin wrote: 1. Threads shows Java threads only, while JVM may have other threads too. For example, those implementing the garbage collector. You application may use native code too, although it's less likely the case.
Could it be that System Time must also be included? If so, any ideas how it could be measured from within YJP (after all yourkit can measure system time showing the line in cpu telemetry chart)?
This must not be the case here, since the app I'm running is about several mins long (running from Intellij with Profile command).Anton Katilin wrote: 2. Threads shows live threads and recent dead threads only. If it's a long running application, the oldest dead threads outside the telemetry frame (1 hour by default) will not be shown.
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: CPU Time in Threads view does not match CPU Time in Summ
Yes.Does Threads time also include system time?
This adds internal, but still Java threads. There are non-Java, fully native threads too.However, even with 'Internal threads checkbox enabled'
Thread and process times are measured by the profiler agent using corresponding low level OS functions. The GC time is measured by JVM, and, according to our observations, it is not always correct. Strictly speaking, these numbers come from different sources and cannot be directly matched.and adding Garbage Collector time
Anyway, could you please provide a snapshot file demonstrating the problem. Could you please send a download link to [email protected] if you cannot share it in the forum.
As I wrote, it is included.Could it be that System Time must also be included?
I'm afraid I don't understand your question.If so, any ideas how it could be measured from within YJP (after all yourkit can measure system time showing the line in cpu telemetry chart)?
The kernel time is shown in the CPU usage graph, and is included to the thread times shown in Threads (and if you measure CPU time instead of wall time during CPU profiling: https://www.yourkit.com/docs/java/help/times.jsp ).
OK.This must not be the case here, since the app I'm running is about several mins long (running from Intellij with Profile command).
Best regards,
Anton
-
- Posts: 7
- Joined: Thu Aug 04, 2011 11:15 am
Re: CPU Time in Threads view does not match CPU Time in Summ
Here is Performance Snapshot.Anton Katilin wrote: Anyway, could you please provide a snapshot file demonstrating the problem.
http://goo.gl/yd9Q2p
Thread view + gc gives about 110s while summary cpu time is 184s.
The question was if we can see kernel time of the thread (or all threads) separately from its user time as a number (not a line in chart). I thought it would help to explain the discrepancy, but as you pointed system time is included this becomes not actual for this discussion.I'm afraid I don't understand your question.
The kernel time is shown in the CPU usage graph, and is included to the thread times shown in Threads (and if you measure CPU time instead of wall time during CPU profiling: https://www.yourkit.com/docs/java/help/times.jsp )
Anyway, if you could have a look at the snapshot and suggest if there is still hope to find "missing" 184 - 109 = 75 sec, I would appreciate.
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: CPU Time in Threads view does not match CPU Time in Summ
Thank you for providing the snapshot.
You're profiling on Mac OS X.
Process CPU time on this platform is obtained by summing kernel and user times returned from
Thread CPU times are obtained by summing kernel and user times returned from
In both cases the used functions match the functions used in the current JVM implementation for its built-in methods. (The agent explicitly calls OS functions instead of using the Java-provided methods to ensure correct results disregarding the Java version, because historical Java versions had been using incorrect implementations on some platforms.)
So it looks like we're doing it right.
Your snapshot shows there was a significant GC activity. As I earlier wrote, the GC times measured by JVM are not always correct, they are usually smaller than we expect. But we can see the collection counts.
I can suggest to perform the following experiments:
- try running the same on another machine running a different OS, for example, Linux or Windows, and compare the results;
and/or
- try another Java version, e.g. Java 8.
You're profiling on Mac OS X.
Process CPU time on this platform is obtained by summing kernel and user times returned from
Code: Select all
getrusage(RUSAGE_SELF, &usage)
Code: Select all
thread_info(mach_thread, THREAD_BASIC_INFO, (thread_info_t)&tinfo, &tcount)
So it looks like we're doing it right.
Your snapshot shows there was a significant GC activity. As I earlier wrote, the GC times measured by JVM are not always correct, they are usually smaller than we expect. But we can see the collection counts.
I can suggest to perform the following experiments:
- try running the same on another machine running a different OS, for example, Linux or Windows, and compare the results;
and/or
- try another Java version, e.g. Java 8.
-
- Posts: 7
- Joined: Thu Aug 04, 2011 11:15 am
Re: CPU Time in Threads view does not match CPU Time in Summ
Anton,Anton Katilin wrote: Your snapshot shows there was a significant GC activity. As I earlier wrote, the GC times measured by JVM are not always correct, they are usually smaller than we expect. But we can see the collection counts.
I can suggest to perform the following experiments:
- try running the same on another machine running a different OS, for example, Linux or Windows, and compare the results;
and/or
- try another Java version, e.g. Java 8.
Here is another snapshot of the variation of the same program ran on Linux with reduced GC activity.
http://goo.gl/Htuik6
Thread view + GC give ~120s, whereas Summary pages gives 162s.
The app was started with agent loaded during startup time, with 'sampling' mode.
Do I understand correctly that Sum(Own time) < Thread View CPU Time since short methods are not caught by profiler and thread view is asked directly via system call ?
-
- Posts: 6172
- Joined: Wed Aug 11, 2004 8:37 am
Re: CPU Time in Threads view does not match CPU Time in Summ
I would still attribute this difference (or at least its major part) to the uncounted CPU activity of the garbage collector and other JVM's non-Java threads.Thread view + GC give ~120s, whereas Summary pages gives 162s.
And there can be some inaccuracy in the results of the system calls for thread and process CPU time measurement. Even if it's true, we have to use the functions the OS provides, since we don't have other/better ones.
Interesting question. I bet you're the first one who tries to perform such comparison.The app was started with agent loaded during startup time, with 'sampling' mode.
Do I understand correctly that Sum(Own time) < Thread View CPU Time since short methods are not caught by profiler and thread view is asked directly via system call ?
Each sample adds the thread's CPU time difference to the top method in the stack and its parents.
So, if you sum the own times please first turn off the filters to ensure all methods are included:
https://www.yourkit.com/docs/java/help/filters.jsp
I guess that a rounding error may also affect the result.