1919import com .tagtraum .perf .gcviewer .model .GCResource ;
2020
2121/**
22- * DataReaderShenandoah can parse all the main messages for GCViewer with default decorations. <p>
23- * Initial mark, Final mark, Init Update Refs, Final Update Refs, Pause Full Allocation Failure, Pause Full (System.gc()),
24- * Concurrent mark, Concurrent evacuation, Concurrent reset bitmaps, Concurrent update references, Concurrent precleaning
22+ * DataReaderUnifiedJvmLogging can parse all gc events of unified jvm logs with default decorations.
2523 * <p>
26- * For more information: <a href="https://wiki.openjdk.java.net/display/shenandoah/Main">Shenandoah Wiki at OpenJDK</a>
24+ * Currently needs the "gc" selector with "info" level and "uptime,level,tags" decorators (Java 9.0.1).
25+ * <ul>
26+ * <li>minimum configuration with defaults: <code>-Xlog:gc:file="path-to-file"</code></li>
27+ * <li>configuration with tags + decorations: <code>-Xlog:gc=info:file="path-to-file":tags,uptime,level</code></li>
28+ * </ul>
29+ * Only processes the following information format for Serial, Parallel, CMS, G1 and Shenandoah algorithms, everything else is ignored:
30+ * <pre>
31+ * [0.731s][info][gc ] GC(0) Pause Init Mark 1.021ms
32+ * [0.735s][info][gc ] GC(0) Concurrent marking 74M->74M(128M) 3.688ms
33+ * [43.948s][info][gc ] GC(831) Pause Full (Allocation Failure) 7943M->6013M(8192M) 14289.335ms
34+ * </pre>
2735 *
2836 * <p>
29- * Example Format
30- * <p>[0.730s][info][gc,start ] GC(0) Pause Init Mark
31- * <p>[0.731s][info][gc ] GC(0) Pause Init Mark 1.021ms
32- * <p>[0.731s][info][gc,start ] GC(0) Concurrent marking
33- * <p>[0.735s][info][gc ] GC(0) Concurrent marking 74M->74M(128M) 3.688ms
34- * <p>[0.735s][info][gc,start ] GC(0) Pause Final Mark
35- * <p>[0.736s][info][gc ] GC(0) Pause Final Mark 74M->76M(128M) 0.811ms
36- * <p>[0.736s][info][gc,start ] GC(0) Concurrent evacuation
37- * <p>...
38- * <p>[43.948s][info][gc ] GC(831) Pause Full (Allocation Failure) 7943M->6013M(8192M) 14289.335ms
37+ * For more information about Shenandoah see: <a href="https://wiki.openjdk.java.net/display/shenandoah/Main">Shenandoah Wiki at OpenJDK</a>
3938 */
40- public class DataReaderShenandoah extends AbstractDataReader {
41-
39+ public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
4240
4341 // Input: [0.693s][info][gc ] GC(0) Pause Init Mark 1.070ms
4442 // Group 1: 0.693
4543 // Group 2: Pause Init Mark
46- // Group 3: 1.070
44+ // Group 3: 1.070 -> optional
4745 // Regex: ^\[([^s\]]*)[^\-]*\)[ ]([^\-]*)[ ]([0-9]+[.,][0-9]+)
4846 private static final Pattern PATTERN_WITHOUT_HEAP = Pattern .compile (
49- "^\\ [([^s\\ ]]*)[^\\ -]*\\ )[ ]([^\\ - ]*)[ ]( [0-9]+[.,][0-9]+)" );
47+ "^\\ [([^s\\ ]]*)[^\\ -]*\\ )[ ]([^\\ d ]*)(( [0-9]+[.,][0-9]+)|$ )" );
5048
5149 // Input: [13.522s][info][gc ] GC(708) Concurrent evacuation 4848M->4855M(4998M) 2.872ms
5250 // Group 1: 13.522
@@ -84,27 +82,29 @@ public class DataReaderShenandoah extends AbstractDataReader {
8482 private static final int HEAP_CURRENT_TOTAL = 5 ;
8583 private static final int HEAP_CURRENT_TOTAL_UNIT = 6 ;
8684
87- private static final List <String > EXCLUDE_STRINGS = Arrays .asList ("Using Shenandoah" , "Cancelling concurrent GC" ,
88- "[gc,start" , "[gc,ergo" , "[gc,stringtable" , "[gc,init" , "[gc,heap" , "[pagesize" , "[class" , "[os" , "[startuptime" ,
89- "[os,thread" , "[gc,heap,exit" , "Cancelling concurrent GC: Allocation Failure" , "Phase " ,
90- "[gc,stats" , "[biasedlocking" , "[logging" , "[verification" , "[modules,startuptime" , "[safepoint" , "[stacktrace" ,
91- "[exceptions" , "thrown" , "at bci" , "for thread" , "[module,load" , "[module,startuptime" );
85+ /** list of strings, that must be part of the gc log line to be considered for parsing */
86+ private static final List <String > INCLUDE_STRINGS = Arrays .asList ("[gc " , "[gc]" );
87+ /** list of strings, that target gc log lines, that - although part of INCLUDE_STRINGS - are not considered a gc event */
88+ private static final List <String > EXCLUDE_STRINGS = Arrays .asList ("Cancelling concurrent GC" , "[debug" , "[trace" );
89+ /** list of strings, that are gc log lines, but not a gc event -> should be logged only */
90+ private static final List <String > LOG_ONLY_STRINGS = Arrays .asList ("Using" );
91+
9292
93- protected DataReaderShenandoah (GCResource gcResource , InputStream in ) throws UnsupportedEncodingException {
93+ protected DataReaderUnifiedJvmLogging (GCResource gcResource , InputStream in ) throws UnsupportedEncodingException {
9494 super (gcResource , in );
9595 }
9696
9797 @ Override
9898 public GCModel read () throws IOException {
99- getLogger ().info ("Reading Shenandoah format..." );
99+ getLogger ().info ("Reading Oracle / OpenJDK unified jvm logging format..." );
100100
101101 try {
102102 GCModel model = new GCModel ();
103- model .setFormat (GCModel .Format .RED_HAT_SHENANDOAH_GC );
103+ model .setFormat (GCModel .Format .UNIFIED_JVM_LOGGING );
104104
105105 Stream <String > lines = in .lines ();
106- lines .filter (this ::lineNotInExcludedStrings )
107- .map (this ::parseShenandoahEvent )
106+ lines .filter (this ::lineContainsParseableEvent )
107+ .map (this ::parseEvent )
108108 .filter (Objects ::nonNull )
109109 .forEach (model ::add );
110110
@@ -114,24 +114,31 @@ public GCModel read() throws IOException {
114114 }
115115 }
116116
117- private AbstractGCEvent <?> parseShenandoahEvent (String line ) {
117+ private AbstractGCEvent <?> parseEvent (String line ) {
118118 AbstractGCEvent <?> event = null ;
119119
120120 Matcher noHeapMatcher = PATTERN_WITHOUT_HEAP .matcher (line );
121121 Matcher withHeapMatcher = PATTERN_WITH_HEAP .matcher (line );
122- if (noHeapMatcher .find ()) {
123- event = new GCEvent ();
124- AbstractGCEvent .Type type = AbstractGCEvent .Type .lookup (noHeapMatcher .group (NO_HEAP_EVENT_NAME ));
125- event .setType (type );
126- setPauseAndDateOrTimestamp (event , noHeapMatcher .group (NO_HEAP_TIMESTAMP ), noHeapMatcher .group (NO_HEAP_DURATION ));
127- } else if (withHeapMatcher .find ()) {
122+ try {
128123 event = line .contains ("Concurrent" ) ? new ConcurrentGCEvent () : new GCEvent ();
129- AbstractGCEvent .Type type = AbstractGCEvent .Type .lookup (withHeapMatcher .group (WITH_HEAP_EVENT_NAME ));
130- event .setType (type );
131- setPauseAndDateOrTimestamp (event , withHeapMatcher .group (WITH_HEAP_TIMESTAMP ), withHeapMatcher .group (WITH_HEAP_DURATION ));
132- addHeapDetailsToEvent (event , withHeapMatcher .group (WITH_HEAP_MEMORY ));
133- } else {
134- getLogger ().warning (String .format ("Failed to parse line number %d in the log file: %s" , in .getLineNumber (), line ));
124+ if (noHeapMatcher .find ()) {
125+ AbstractGCEvent .ExtendedType type = getDataReaderTools ().parseType (noHeapMatcher .group (NO_HEAP_EVENT_NAME ));
126+ event .setExtendedType (type );
127+ setPauseAndDateOrTimestamp (event , noHeapMatcher .group (NO_HEAP_TIMESTAMP ), noHeapMatcher .groupCount () > 2 ? noHeapMatcher .group (NO_HEAP_DURATION ) : null );
128+ } else if (withHeapMatcher .find ()) {
129+ AbstractGCEvent .ExtendedType type = getDataReaderTools ().parseType (withHeapMatcher .group (WITH_HEAP_EVENT_NAME ));
130+ event .setExtendedType (type );
131+ setPauseAndDateOrTimestamp (event , withHeapMatcher .group (WITH_HEAP_TIMESTAMP ), withHeapMatcher .group (WITH_HEAP_DURATION ));
132+ addHeapDetailsToEvent (event , withHeapMatcher .group (WITH_HEAP_MEMORY ));
133+ } else {
134+ // prevent incomplete event from being added to the GCModel
135+ event = null ;
136+ getLogger ().warning (String .format ("Failed to parse line number %d (line=\" %s\" )" , in .getLineNumber (), line ));
137+ }
138+ } catch (UnknownGcTypeException | NumberFormatException e ) {
139+ // prevent incomplete event from being added to the GCModel
140+ event = null ;
141+ getLogger ().warning (String .format ("Failed to parse gc event (%s) on line number %d (line=\" %s\" )" , e .toString (), in .getLineNumber (), line ));
135142 }
136143
137144 return event ;
@@ -143,8 +150,10 @@ private AbstractGCEvent<?> parseShenandoahEvent(String line) {
143150 * @param dateOrTimeStampAsString Date- or timestamp information from regex group as string
144151 */
145152 private void setPauseAndDateOrTimestamp (AbstractGCEvent <?> event , String dateOrTimeStampAsString , String pauseAsString ) {
146- double pause = Double .parseDouble (pauseAsString .replace ("," , "." ));
147- event .setPause (pause / 1000 );
153+ if (pauseAsString != null && pauseAsString .length () > 0 ) {
154+ double pause = Double .parseDouble (pauseAsString .replace ("," , "." ));
155+ event .setPause (pause / 1000 );
156+ }
148157 if (PATTERN_ISO8601_DATE .matcher (dateOrTimeStampAsString ).find ()) {
149158 ZonedDateTime dateTime = ZonedDateTime .parse (dateOrTimeStampAsString , AbstractDataReaderSun .DATE_TIME_FORMATTER );
150159 event .setDateStamp (dateTime );
@@ -169,12 +178,32 @@ private void addHeapDetailsToEvent(AbstractGCEvent<?> event, String memoryString
169178 Integer .parseInt (matcher .group (HEAP_CURRENT_TOTAL )), matcher .group (HEAP_CURRENT_TOTAL_UNIT ).charAt (0 ), memoryString ));
170179 event .setExtendedType (event .getExtendedType ());
171180 } else {
172- getLogger ().warning ("Failed to find heap details from line: " + memoryString );
181+ getLogger ().warning ("Failed to find heap details from string: \" " + memoryString + " \" "
173182 }
174183 }
175184
176- private boolean lineNotInExcludedStrings (String line ) {
177- return EXCLUDE_STRINGS .stream ().noneMatch (line ::contains );
185+ private boolean isExcludedLine (String line ) {
186+ return EXCLUDE_STRINGS .stream ().anyMatch (line ::contains );
187+ }
188+
189+ private boolean isCandidateForParseableEvent (String line ) {
190+ return INCLUDE_STRINGS .stream ().anyMatch (line ::contains );
191+ }
192+
193+ private boolean isLogOnlyLine (String line ) {
194+ return LOG_ONLY_STRINGS .stream ().anyMatch (line ::contains );
195+ }
196+
197+ private boolean lineContainsParseableEvent (String line ) {
198+ if (isCandidateForParseableEvent (line ) && !isExcludedLine (line )) {
199+ if (isLogOnlyLine (line )) {
200+ getLogger ().info (line .substring (line .lastIndexOf ("]" )+1 ));
201+ return false ;
202+ } else {
203+ return true ;
204+ }
205+ }
206+ return false ;
178207 }
179208
180209}
0 commit comments