G1 concurrent phase durations do not state the time units ("secs")

[Srinivas Ramakrishna]

Hi John, all --

I'm using 7u9, perhaps this has been fixed subsequently. Here's an example
of the missing units (and the inconsistency):-

The young and mixed pauses print duration units of "secs" :-

2013-01-30T01:46:45.652-0800: 9522.134: [GC pause (young), 1.10620800 secs]
2013-01-30T01:47:03.563-0800: 9540.045: [GC pause (young), 0.90593900 secs]
2013-01-30T01:47:18.619-0800: 9555.101: [GC pause (young), 0.81425400 secs]
2013-01-30T01:47:59.536-0800: 9596.018: [GC pause (young), 0.84935400 secs]
2013-01-30T01:48:12.097-0800: 9608.579: [GC pause (young) (initial-mark),
0.50153600 secs]
2013-01-30T01:48:59.189-0800: 9655.671: [GC pause (young), 0.02815400 secs]
2013-01-30T01:51:53.952-0800: 9830.457: [GC pause (mixed), 0.66860800 secs]
2013-01-30T01:53:20.704-0800: 9917.186: [GC pause (mixed), 0.47479200 secs]
2013-01-30T01:54:41.098-0800: 9997.579: [GC pause (mixed), 0.72149500 secs]
2013-01-30T01:55:58.944-0800: 10075.426: [GC pause (young), 0.32158300 secs]


The concurrent phases are often missing the units, but not always (mark
phase duration prints "sec", others are mum):-

2013-01-30T01:12:10.711-0800: 7447.193: [GC
concurrent-root-region-scan-end, 1.0222980]
2013-01-30T01:12:41.386-0800: 7477.868: [GC concurrent-mark-end, 30.6749800
sec]
2013-01-30T01:12:41.626-0800: 7478.108: [GC concurrent-cleanup-end,
0.0063520]
2013-01-30T01:24:18.588-0800: 8175.070: [GC
concurrent-root-region-scan-end, 0.5868510]
2013-01-30T01:25:01.089-0800: 8217.571: [GC concurrent-mark-end, 42.5016130
sec]
2013-01-30T01:25:01.321-0800: 8217.803: [GC concurrent-cleanup-end,
0.0057450]
2013-01-30T01:36:27.063-0800: 8903.545: [GC
concurrent-root-region-scan-end, 0.3746230]
2013-01-30T01:37:18.642-0800: 8955.124: [GC concurrent-mark-end, 51.5794260
sec]
2013-01-30T01:37:18.869-0800: 8955.351: [GC concurrent-cleanup-end,
0.0048270]
2013-01-30T01:48:13.162-0800: 9609.644: [GC
concurrent-root-region-scan-end, 0.5630820]
2013-01-30T01:48:55.513-0800: 9651.995: [GC concurrent-mark-end, 42.3504330
sec]
2013-01-30T01:48:55.769-0800: 9652.251: [GC concurrent-cleanup-end,
0.0041170]


Would be nice to have it be consistent across G1 and indeed across all
collectors, if not already the case. Also makes for more consistent parsing
of logs.

thanks!
-- ramki
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20130130/1cad30b7/attachment.htm>