PrintGCApplicationConcurrentTime / PrintGCApplicationStoppedTime
rainer.jung at kippdata.de
Thu Apr 16 08:06:31 PDT 2009
On 16.04.2009 15:48, Jon Masamitsu wrote:
> Sentiment at this point seems to favor including
> the application times (stopped time and run time)
> for all the safepoints. We'll start on making that
> the fix.
I would also agree, but with the additional remark, that in case this
increases the number of output lines (number of events per time that
trigger a line) very much (like by a factor of 10), then it might be not
If it would be allowed w.r.t. compatibility to include some keyword
indicating the cause/type of the event on the same line, that would make
it even more useful. GC could be one such event type.
> On 04/14/09 11:14, Jon Masamitsu wrote:
>> Question: Do users care about applications times output
>> for PrintGCApplicationConcurrentTime only relative to
>> I have a CR
>> 6782663: Data produced by PrintGCApplicationConcurrentTime and
>> PrintGCApplicationStoppedTime is not accurate
>> where the complaint is that the application time as output
>> for PrintGCApplicationConcurrentTime does not match the time
>> as measured by the time between GC timestamps. Actually the
>> user is adding up all the times reported for
>> PrintGCApplicationConcurrentTime between the GC timestamps
>> and saying that that sum can be vastly off from the
>> time between GC timestamps. And the user is right.
>> I think the problem is that the timers used to report
>> PrintGCApplicationConcurrentTime are updated more often
>> than the PrintGCApplicationConcurrentTime time is
>> reported. In VMThread::loop() in share/vm/runtime/vmThread.cpp
>> around line 425 the PrintGCApplicationConcurrentTime is
>> reported before the call to SafepointSynchronize::begin().
>> Whereas near line 391 and near line 520 calls to
>> SafepointSynchronize::begin() do not report for
>> PrintGCApplicationConcurrentTime. The calls to
>> SafepointSynchronize::begin() will update the application
>> timer (_app_timer via a call to
>> RuntimeService::record_safepoint_begin()). Updating
>> resets the timer to the current time and the
>> PrintGCApplicationConcurrentTime output is then the
>> time since the last safepoint (not since the application
>> restarted after the last GC).
>> So anyone know why the PrintGCApplicationConcurrentTime output
>> does not print for all safepoints? Should it only printout
>> when a VM operation is executed as it does now?
>> If yes, should the spelling of
>> PrintGCApplicationConcurrentTime be changed to drop
>> the GC, PrintApplicationConcurrentTime. Similarly with
>> PrintGCApplicationStoppedTime -> PrintApplicationStoppedTime.
>> Or should it printout for all safepoints? This is
>> simpler in that the printing could be added to
>> RuntimeService::record_safepoint_begin()) so
>> we would not miss new safepoints. But we might
>> be dumping useless information.
>> Or I could hack the code so that information is only
>> printed around GC's. And maybe not printout some
>> useful information.
More information about the hotspot-gc-dev