PrintGCApplicationConcurrentTime / PrintGCApplicationStoppedTime

[Jon Masamitsu]

Question: Do users care about applications times output
for PrintGCApplicationConcurrentTime only relative to
GC's?


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.