Correct data/chart for IBM J9 tenured space

Due to wrong timestamps the last size of tenured space was used
as value for the whole graph.

Author: Christian Mötzing

src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderIBM_J9_R28.java

@@ -4,6 +4,7 @@
 import java.io.InputStream;
 import java.io.LineNumberReader;
 import java.io.UnsupportedEncodingException;
+import java.sql.Timestamp;
 import java.time.LocalDateTime;
 import java.time.ZoneId;
 import java.time.ZonedDateTime;
@@ -158,9 +159,10 @@ else if (event.isEndElement()) {
     private GCEvent handleExclusiveStart(StartElement startElement) {
         GCEvent event = new GCEvent();
         try {
-            event.setDateStamp(ZonedDateTime.of(
-                    LocalDateTime.parse(getAttributeValue(startElement, "timestamp"), dateTimeFormatter),
-                    ZoneId.systemDefault()));
+            String timestamp = getAttributeValue(startElement, "timestamp");
+            LocalDateTime local = LocalDateTime.parse(timestamp, dateTimeFormatter);
+            event.setDateStamp(ZonedDateTime.of(local, ZoneId.systemDefault()));
+            event.setTimestamp(Timestamp.valueOf(local).getTime() / 1000);
         }
         catch (DateTimeParseException e) {
             if (getLogger().isLoggable(Level.WARNING)) getLogger().warning("line " + in.getLineNumber() + ": " + e.toString());
@@ -211,6 +213,7 @@ else if (startEl.getName().getLocalPart().equals("mem")) {
                     switch (getAttributeValue(startEl, "type")) {
                         case "nursery":
                             GCEvent young = new GCEvent();
+                            young.setTimestamp(event.getTimestamp());
                             young.setType(Type.lookup("nursery"));
                             setTotalAndPreUsed(young, startEl);
                             event.add(young);
@@ -219,6 +222,7 @@ else if (startEl.getName().getLocalPart().equals("mem")) {
                             // scavenge prints tenure space but does not change it as it is young only
                             if(!typeName.contains("scavenge")) {
                                 GCEvent tenured = new GCEvent();
+                                tenured.setTimestamp(event.getTimestamp());
                                 tenured.setType(Type.lookup("tenure"));
                                 setTotalAndPreUsed(tenured, startEl);
                                 event.add(tenured);

src/main/java/com/tagtraum/perf/gcviewer/model/AbstractGCEvent.java

@@ -277,7 +277,8 @@ public boolean isSystem() {
     }
 
     public boolean isInc() {
-        return getExtendedType().getType() == GCEvent.Type.INC_GC;
+        Type type = getExtendedType().getType();
+        return type == GCEvent.Type.INC_GC || type == Type.IBM_AF_SCAVENGE;
     }
 
     public boolean isConcurrent() {

src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderIBM_J9_R27.java

@@ -1,7 +1,9 @@
 package com.tagtraum.perf.gcviewer.imp;
 
 import static com.tagtraum.perf.gcviewer.UnittestHelper.toKiloBytes;
+import static com.tagtraum.perf.gcviewer.imp.TestDataReaderIBM_J9_R28.*;
 import static org.hamcrest.Matchers.is;
+import static org.hamcrest.Matchers.startsWith;
 import static org.hamcrest.number.IsCloseTo.closeTo;
 import static org.junit.Assert.assertThat;
 
@@ -23,6 +25,8 @@
  */
 public class TestDataReaderIBM_J9_R27 {
 
+    public static final String EXPECTED_ERROR_MESSAGE = "line 233: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[234,1]";
+
     private InputStream getInputStream(String fileName) throws IOException {
         return UnittestHelper.getResourceAsStream(FOLDER.IBM, fileName);
     }
@@ -58,11 +62,13 @@ public void testFullHeaderWithAfGcs() throws Exception {
         assertThat("tenured before", event.getTenured().getPreUsed(), is(toKiloBytes(805306368 - 804158480)));
         assertThat("tenured after", event.getTenured().getPostUsed(), is(toKiloBytes(805306368 - 804158480)));
 
-        assertThat("timestamp 1", event.getTimestamp(), closeTo(0.0, 0.0001));
-        assertThat("timestamp 2", model.get(1).getTimestamp(), closeTo(1.927, 0.0001));
-        assertThat("timestamp 3", model.get(2).getTimestamp(), closeTo(3.982, 0.0001));
+        verifyTimestamp("timestamp 1", event.getTimestamp(), "2014-09-24T15:57:32.116");
+        verifyTimestamp("timestamp 2", model.get(1).getTimestamp(), "2014-09-24T15:57:34.043");
+        verifyTimestamp("timestamp 3", model.get(2).getTimestamp(), "2014-09-24T15:57:36.098");
 
         assertThat("number of errors", handler.getCount(), is(1));
+        String message = handler.getLogRecords().get(0).getMessage();
+        assertThat("missing close tag </verbosegc>", message, startsWith(EXPECTED_ERROR_MESSAGE));
     }
 
     @Test

src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderIBM_J9_R28.java

@@ -8,6 +8,9 @@
 
 import java.io.IOException;
 import java.io.InputStream;
+import java.sql.Timestamp;
+import java.time.LocalDateTime;
+import java.time.format.DateTimeFormatter;
 import java.util.logging.Level;
 
 import com.tagtraum.perf.gcviewer.UnittestHelper;
@@ -56,12 +59,16 @@ public void testAfScavenge() throws Exception {
         assertThat("tenured before", event.getTenured().getPreUsed(), is(toKiloBytes(402653184 - 401882552)));
         assertThat("tenured after", event.getTenured().getPostUsed(), is(toKiloBytes(402653184 - 401882552)));
 
-        assertThat("timestamp 1", event.getTimestamp(), closeTo(0.0, 0.0001));
-        assertThat("timestamp 2", model.get(1).getTimestamp(), closeTo(1.272, 0.0001));
 
         assertThat("type", event.getTypeAsString(), equalTo("af scavenge; nursery"));
         assertThat("generation", event.getExtendedType().getGeneration(), is(AbstractGCEvent.Generation.YOUNG));
         assertThat("full", event.isFull(), is(false));
+        assertThat("full", event.isInc(), is(true));
+
+        verifyTimestamp("first pause timestamp", model.getFirstPauseTimeStamp(), "2015-12-31T15:22:46.957");
+        verifyTimestamp("event timestamp", event.getTimestamp(), "2015-12-31T15:22:46.957");
+        verifyTimestamp("event timestamp 2", model.get(1).getTimestamp(), "2015-12-31T15:22:48.229");
+
         assertThat("number of errors", handler.getCount(), is(0));
     }
 
@@ -81,6 +88,9 @@ public void testAfGlobal() throws Exception {
         assertThat("pause", event.getPause(), closeTo(1.255648, 0.0000001));
         assertThat("type", event.getTypeAsString(), equalTo("af global; tenure"));
 
+        verifyTimestamp("event timestamp", event.getTimestamp(), "2016-08-09T14:58:58.343");
+        verifyTimestamp("first pause timestamp", model.getFirstPauseTimeStamp(), "2016-08-09T14:58:58.343");
+
         assertThat("number of errors", handler.getCount(), is(0));
     }
 
@@ -100,6 +110,9 @@ public void testSysGlobal() throws Exception {
         assertThat("pause", event.getPause(), closeTo(0.097756, 0.0000001));
         assertThat("type", event.getTypeAsString(), equalTo("sys explicit global; nursery; tenure"));
 
+        verifyTimestamp("event timestamp", event.getTimestamp(), "2015-12-31T15:23:00.646");
+        verifyTimestamp("first pause timestamp", model.getFirstPauseTimeStamp(), "2015-12-31T15:23:00.646");
+
         assertThat("number of errors", handler.getCount(), is(0));
     }
 
@@ -131,10 +144,22 @@ public void testConcurrentCollection() throws Exception {
         AbstractGCEvent<?> event = model.get(0);
         assertThat("model size", model.size(), is(1));
         assertThat("duration", event.getPause(), closeTo(1.182375, 0.00000001));
-        assertThat("number of errors", handler.getCount(), is(0));
 
-        assertThat("", event.getExtendedType().getConcurrency(), is(AbstractGCEvent.Concurrency.CONCURRENT));
-        assertThat("", event.getExtendedType().getGeneration(), is(AbstractGCEvent.Generation.ALL));
+        assertThat("concurrency", event.getExtendedType().getConcurrency(), is(AbstractGCEvent.Concurrency.CONCURRENT));
+        assertThat("generation", event.getExtendedType().getGeneration(), is(AbstractGCEvent.Generation.ALL));
+        assertThat("full", event.isFull(), is(true));
+        assertThat("full", event.isInc(), is(false));
+
+        verifyTimestamp("event timestamp", event.getTimestamp(), "2016-08-09T15:14:56.110");
+        verifyTimestamp("first pause timestamp", model.getFirstPauseTimeStamp(), "2016-08-09T15:14:56.110");
+
+        assertThat("number of errors", handler.getCount(), is(0));
     }
 
+    public static void verifyTimestamp(String reason, double actual, String dateTime) {
+        DateTimeFormatter formatter = DateTimeFormatter.ISO_LOCAL_DATE_TIME;
+        LocalDateTime localDateTime = LocalDateTime.parse(dateTime, formatter);
+        double expected = Long.valueOf(Timestamp.valueOf(localDateTime).getTime()/1000).doubleValue();
+        assertThat(reason, actual, is(expected));
+    }
 }