United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
Bug ID: JDK-8012455 Missing time and date stamps for PrintGCApplicationConcurrentTime and PrintGCApplicationStoppedTime
JDK-8012455 : Missing time and date stamps for PrintGCApplicationConcurrentTime and PrintGCApplicationStoppedTime

Details
Type:
Bug
Submit Date:
2013-04-17
Status:
Resolved
Updated Date:
2013-05-06
Project Name:
JDK
Resolved Date:
2013-04-18
Component:
hotspot
OS:
Sub-Component:
gc
CPU:
Priority:
P3
Resolution:
Fixed
Affected Versions:
Fixed Versions:
hs25 (b29)

Related Reports
Backport:
Backport:
Backport:

Sub Tasks

Description
The logging for the flags PrintGCApplicationConcurrentTime and PrintGCApplicationStoppedTime do not print time and date stamps even if PrintGCTimeStamps or PrintGCDateStamps are enabled.

java -XX:+UseConcMarkSweepGC -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime -XX:+ExplicitGCInvokesConcurrent

Application time: 0.0393160 seconds
0.437: [GC (System.gc())  2795K->334K(506816K), 0.0032230 secs]
Total time for which application threads were stopped: 0.0038270 seconds
Application time: 0.0000630 seconds
0.440: [GC (CMS Initial Mark)  334K(506816K), 0.0017760 secs]
Total time for which application threads were stopped: 0.0018860 seconds
Application time: 3.9741740 seconds
Total time for which application threads were stopped: 0.0001640 seconds
Application time: 1.0510580 seconds
5.468: [GC (CMS Final Remark)  5926K(506816K), 0.0019470 secs]
Total time for which application threads were stopped: 0.0020370 seconds 

                                    

Comments
I have a patch that adds time and date stamps. Using the same command line now produces this output:

0.442: Application time: 0.0394060 seconds
0.443: [GC (System.gc())  2795K->333K(506816K), 0.0028170 secs]
0.446: Total time for which application threads were stopped: 0.0034380 seconds
0.446: Application time: 0.0000770 seconds
0.446: [GC (CMS Initial Mark)  333K(506816K), 0.0018220 secs]
0.448: Total time for which application threads were stopped: 0.0019560 seconds
4.423: Application time: 3.9749570 seconds
4.423: Total time for which application threads were stopped: 0.0001710 seconds
5.472: Application time: 1.0491130 seconds
5.472: [GC (CMS Final Remark)  5924K(506816K), 0.0018320 secs]
5.474: Total time for which application threads were stopped: 0.0019660 seconds 
                                     
2013-04-17
Tagged this bug as noreg-hard. Here is the motivation:

It is difficult to write a stable test for our logging. We sometimes get interleaved logging from different threads, so there is no guarantee that the log follows a particular format that is possible to parse automatically. Especially not with date and time stamps.
                                     
2013-04-17
URL:   http://hg.openjdk.java.net/hsx/hotspot-gc/hotspot/rev/07a4efc5ed14
User:  brutisso
Date:  2013-04-18 07:42:11 +0000

                                     
2013-04-18
URL:   http://hg.openjdk.java.net/hsx/hsx25/hotspot/rev/07a4efc5ed14
User:  amurillo
Date:  2013-04-19 20:07:30 +0000

                                     
2013-04-19



Hardware and Software, Engineered to Work Together