How to show the gc pause time with UseShenandoahGC

[Roman Kennke]

I think you are looking at the right logs. Shenandoah does two pauses:
InitMark and InitEvac. You can find it in the log:

> 2015-10-23T15:10:35.930+0800: 1738.287: [GC InitMark end, 0.017967
> secs total = 75497472 K, used = 51861702 K free = 23635769 K]

Here you got 12.9 ms for InitMark.

The other pause is a bit more difficult to find, because it spans over
several intervals:
The first is FinalMark:
> 2015-10-23T15:10:36.182+0800: 1738.538: [GC FinalMark end, 0.034520
> secs total = 75497472 K, used = 52252771 K free = 23244700 K]

34.5ms

Then PrepareEvac:

> 2015-10-23T15:10:36.183+0800: 1738.539: [GC PrepareEvac end, 0.000964
> secs total = 75497472 K, used = 23712714 K free = 51784757 K]

0.96ms

and InitEvac:

> 2015-10-23T15:10:36.190+0800: 1738.547: [GC InitEvac end, 0.007175
> secs total = 75497472 K, used = 23715364 K free = 51782108 K]

7.1ms

They all add up to a total pause of 42,56ms

Since they all go in one pause, we should probably make a measurement
interval around them for better usability.

When you turn on -XX:+PrintGCDetails you will find interesting pause
statistics on program termination. E.g. number of pauses, avg and max
pause time, std deviation, etc.

I hope it helps, let us know!

Roman