understanding CMS logs

[Shane Cox]

I'm having trouble reconciling the timings in the following log entries.
Could someone please explain?  Take the first example (concurrent mark).
The cpu time was ~ 25 seconds, elapsed time was ~ 43 seconds.  So how can
"user" time be 283 seconds?  There are only 2 Parallel CMS threads.  I would
think User time would be more along the lines of 50 seconds.  Obviously
there is something that I'm misinterpreting.


Also, If cpu time is 25 seconds but elapsed time is 43 seconds, does that
mean the CM spent 18 seconds doing something other than executing on CPU?
I'm wondering if some condition is extending the CM execution time because
it cannot obtain adequate cpu resources.


Log excerpts:
2011-04-05T19:20:38.944-0400: 164034.340: [CMS-concurrent-mark:
25.221/43.448 secs] [Times: user=283.46 sys=8.05, real=43.44 secs]

2011-04-05T19:20:51.735-0400: 164047.131: [CMS-concurrent-preclean:
10.211/17.222 secs] [Times: user=72.78 sys=2.24, real=17.22 secs]



GC Threads:
"Gang worker#0 (Parallel GC Threads)" prio=10 tid=0x000000005f598000
nid=0x2ab5 runnable
"Gang worker#1 (Parallel GC Threads)" prio=10 tid=0x000000005f59a000
nid=0x2ab6 runnable
"Gang worker#2 (Parallel GC Threads)" prio=10 tid=0x000000005f59c000
nid=0x2ab7 runnable
"Gang worker#3 (Parallel GC Threads)" prio=10 tid=0x000000005f59d800
nid=0x2ab8 runnable
"Gang worker#4 (Parallel GC Threads)" prio=10 tid=0x000000005f59f800
nid=0x2ab9 runnable
"Gang worker#5 (Parallel GC Threads)" prio=10 tid=0x000000005f5a1800
nid=0x2aba runnable
"Gang worker#6 (Parallel GC Threads)" prio=10 tid=0x000000005f5a3000
nid=0x2abb runnable
"Gang worker#7 (Parallel GC Threads)" prio=10 tid=0x000000005f5a5000
nid=0x2abc runnable

"Concurrent Mark-Sweep GC Thread" prio=10 tid=0x000000005f698800 nid=0x2ac3
runnable
"Gang worker#0 (Parallel CMS Threads)" prio=10 tid=0x000000005f694800
nid=0x2ac1 runnable
"Gang worker#1 (Parallel CMS Threads)" prio=10 tid=0x000000005f696800
nid=0x2ac2 runnable


Thanks!
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20110408/3f6d5350/attachment.htm>
-------------- next part --------------
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use