A customer found a problem related to CR6369463.

When users set -XX:+UseConcMarkSweepGC in JDK6ux including the fix for 6369463,
the result of GarbageCollectorMXBean.getCollectionTime() is different from total
time of -verbose:gc.

Note:
The result of UseParallelGC and UseSerialGC
conform to total time of -verbose:gc.

This is caused from different start point of GC timer
between GarbageCollectorMXBean and -verbose:gc,
when FullGC(MarkSweep Compaction) occurs.

In GarbageCollectorMXBean, GC timer starts in the
constructor of TraceMemoryManagerStats().
((x) in the following source code portion).



--- jdk6u13 : genCollectedHeap.cpp --->

....
genCollectedHeap.cpp:
   for (int i = starting_level; i <= max_level; i++) {
     if (_gens[i]->should_collect(full, size, is_tlab)) {
       // Timer for individual generations. Last argument is false: no CR
       TraceTime t1(_gens[i]->short_name(), PrintGCDetails, false, gclog_or_tty);
       TraceCollectorStats tcs(_gens[i]->counters());
       TraceMemoryManagerStats tmms(_gens[i]->kind()); ---- (x)
....

<----


In -verbose:gc, it starts in the constructor of TraceTime().
((y) in the following source code portion).

--- jdk6u13 : genMarkSweep.cpp --->
...

  TraceTime t1("Full GC", PrintGC && !PrintGCDetails, true, gclog_or_tty); ---- (y)
...

<---

In UseParallelGC and UseSerialGC,
the above mentioned (x) and (y) start almost the same.
In UseConcMarkSweepGC, the following code block runs between (x) and (y).
This results if the different start time.

--- jdk6u13 : concurrentMarkSweepGeneration.cpp --->
...
     while (_foregroundGCShouldWait) {
       // wait for notification
       CGC_lock->wait(Mutex::_no_safepoint_check_flag);
       // Possibility of delay/starvation here, since CMS token does
       // not know to give priority to VM thread? Actually, i think
       // there wouldn't be any delay/starvation, but the proof of
       // that "fact" (?) appears non-trivial. XXX 20011219YSR
     }
...
<----

They changed source code as follows in prder to print time stamp
and confirmed how much different is.

--- jdk6u13 : genCollectedHeap.cpp --->
....

       TraceTime t1(_gens[i]->short_name(), PrintGCDetails, false, gclog_or_tty);
       TraceCollectorStats tcs(_gens[i]->counters());
 #if TEST
       if (i==1) tty->stamp(); tty->print_cr(" at TraceMemoryManagerStats ###");
 #endif
       TraceMemoryManagerStats tmms(_gens[i]->kind()); ---- (x)
....

<-------

Then they invoked,

java -XX:+UseConcMarkSweepGC -verbose:gc -XX:+PrintGCTimeStamp

They got the following result.

--
(a) 100.454 at TraceMemoryManagerStats ###
(b) 101.568: [Full GC 127754K->92031K(129472K), 2.4266752 secs]
--

(a) shows the start of GarbageCollectorMXBean timer
(b) shows the start of -verbose:gc timer


This is the case of Maximun difference.
About 1[sec] for 2.5[sec] in FullGC is difference between
GarbageCollectorMXBean start and -verbose:gc start.
Averagely, 10% is different.

They think the result of getCollectionTime() should be the same to total time of -verbose:gc.