@Test
public void testCMSAdaptiveSizePolicyPrintHeapAtGC() throws Exception {
TestLogHandler handler = new TestLogHandler();
handler.setLevel(Level.WARNING);
IMP_LOGGER.addHandler(handler);
DATA_READER_FACTORY_LOGGER.addHandler(handler);
ByteArrayInputStream in =
new ByteArrayInputStream(
("2012-04-18T14:48:31.855+0200: 29.592: [GC 29.592: [ASParNew: 52825K->6499K(59008K), 0.0268761 secs] 120805K->120749K(517760K), 0.0269605 secs] [Times: user=0.05 sys=0.00, real=0.03 secs]"
+ "\nHeap"
+ "\nadaptive size par new generation total 59008K, used 15368K [0x00000000d8000000, 0x00000000dc000000, 0x00000000dc000000)"
+ "\n eden space 52480K, 16% used [0x00000000d8000000, 0x00000000d88a95a0, 0x00000000db340000)"
+ "\n from space 6528K, 99% used [0x00000000db340000, 0x00000000db998cb0, 0x00000000db9a0000)"
+ "\n to space 6528K, 0% used [0x00000000db9a0000, 0x00000000db9a0000, 0x00000000dc000000)"
+ "\nconcurrent mark-sweep generation total 458752K, used 259541K [0x00000000dc000000, 0x00000000f8000000, 0x00000000f8000000)"
+ "\nconcurrent-mark-sweep perm gen total 65536K, used 2621K [0x00000000f8000000, 0x00000000fc000000, 0x0000000100000000)")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("GC pause", 0.0269605, model.getGCPause().getMin(), 0.000000001);
assertEquals("number of errors", 0, handler.getCount());
}
@Test
public void testPrintCmsStatisticsRemark() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("2012-10-20T18:04:59.443+0200: 2.918: [GC[YG occupancy: 8752 K (78656 K)]2.918: [Rescan (parallel) (Survivor:1chunks) Finished young gen rescan work in 2th thread: 0.000 sec"
+ "\nFinished young gen rescan work in 1th thread: 0.000 sec"
+ "\nFinished young gen rescan work in 0th thread: 0.000 sec"
+ "\nFinished remaining root rescan work in 1th thread: 0.000 sec"
+ "\nFinished remaining root rescan work in 2th thread: 0.000 sec"
+ "\nFinished remaining root rescan work in 0th thread: 0.000 sec"
+ "\nFinished dirty card rescan work in 0th thread: 0.001 sec"
+ "\nFinished dirty card rescan work in 2th thread: 0.001 sec"
+ "\nFinished dirty card rescan work in 1th thread: 0.001 sec"
+ "\nFinished young gen rescan work in 3th thread: 0.000 sec"
+ "\nFinished remaining root rescan work in 3th thread: 0.000 sec"
+ "\nFinished dirty card rescan work in 3th thread: 0.000 sec"
+ "\nFinished work stealing in 3th thread: 0.000 sec"
+ "\nFinished work stealing in 2th thread: 0.000 sec"
+ "\nFinished work stealing in 0th thread: 0.000 sec"
+ "\nFinished work stealing in 1th thread: 0.000 sec"
+ "\n, 0.0008918 secs]2.919: [weak refs processing, 0.0000057 secs]2.919: [class unloading, 0.0001020 secs]2.919: [scrub symbol & string tables, 0.0003265 secs] [1 CMS-remark: 376134K(436928K)] 384886K(515584K), 0.0014952 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("GC pause", 0.0014952, model.getGCPause().getMin(), 0.000000001);
}
/** Tests the combination of -XX:PrintCmsStatistics=2 and -XX:+CMSScavengeBeforeRemark */
@Test
public void testPrintCmsStatisticsScavengeBeforeRemark() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("2012-10-26T18:31:09.699+0200: 15.473: [GC[YG occupancy: 8752 K (78656 K)]2012-10-26T18:31:09.699+0200: 15.473: [GC 15.473: [ParNew: 8752K->64K(78656K), 0.0052352 secs] 388874K->388870K(515584K), 0.0052868 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]"
+ "\n15.478: [Rescan (parallel) (Survivor:0chunks) Finished young gen rescan work in 1th thread: 0.000 sec"
+ "\nFinished young gen rescan work in 1th thread: 0.000 sec"
+ "\nFinished young gen rescan work in 0th thread: 0.000 sec"
+ "\nFinished remaining root rescan work in 1th thread: 0.000 sec"
+ "\nFinished remaining root rescan work in 2th thread: 0.000 sec"
+ "\nFinished remaining root rescan work in 0th thread: 0.000 sec"
+ "\nFinished dirty card rescan work in 0th thread: 0.001 sec"
+ "\nFinished dirty card rescan work in 2th thread: 0.001 sec"
+ "\nFinished dirty card rescan work in 1th thread: 0.001 sec"
+ "\nFinished young gen rescan work in 3th thread: 0.000 sec"
+ "\nFinished remaining root rescan work in 3th thread: 0.000 sec"
+ "\nFinished dirty card rescan work in 3th thread: 0.000 sec"
+ "\nFinished work stealing in 3th thread: 0.000 sec"
+ "\nFinished work stealing in 2th thread: 0.000 sec"
+ "\nFinished work stealing in 0th thread: 0.000 sec"
+ "\nFinished work stealing in 1th thread: 0.000 sec"
+ "\n, 0.0006571 secs]15.479: [weak refs processing, 0.0000041 secs]15.479: [class unloading, 0.0001106 secs]15.479: [scrub symbol table, 0.0004465 secs]15.480: [scrub string table, 0.0000168 secs] [1 CMS-remark: 388806K(436928K)] 388870K(515584K), 0.0067111 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 2, model.size());
GCEvent parNew = (GCEvent) model.get(0);
GCEvent remarkEvent = (GCEvent) model.get(1);
assertEquals("GC pause ParNew", 0.0052868, parNew.getPause(), 0.000000001);
assertEquals("GC pause Remark", 0.0067111 - 0.0052868, remarkEvent.getPause(), 0.000000001);
}
public void render(GCModel model, String chartFilePath) throws IOException {
GCPreferences gcPreferences = new GCPreferences();
gcPreferences.load();
final ModelChartImpl pane = new ModelChartImpl();
pane.setHorizontalScrollBarPolicy(JScrollPane.HORIZONTAL_SCROLLBAR_NEVER);
pane.setModel(model, gcPreferences);
pane.setFootprint(model.getFootprint());
pane.setMaxPause(model.getPause().getMax());
pane.setRunningTime(model.getRunningTime());
Dimension d = new Dimension(gcPreferences.getWindowWidth(), gcPreferences.getWindowHeight());
pane.setSize(d);
pane.addNotify();
pane.validate();
pane.autoSetScaleFactor();
final BufferedImage image = new BufferedImage(d.width, d.height, BufferedImage.TYPE_INT_RGB);
final Graphics2D graphics = image.createGraphics();
graphics.setBackground(Color.WHITE);
graphics.clearRect(0, 0, image.getWidth(), image.getHeight());
pane.paint(graphics);
ImageIO.write(image, "png", new File(chartFilePath));
}
/**
* This log file sample contains much more information about concurrent events than is currently
* parsed. Still the parser must be able to extract the information it can parse.
*/
@Test
public void testGenConMemstats() throws Exception {
// allthough this log file was written with JRockit 1.5 VM, it has the same structure
// as a JRockit 1.6 gc log file.
// TODO refactor JRockit DataReader
InputStream in = getInputStream("SampleJRockit1_5_20_memstats2.txt");
DataReader reader = new DataReaderJRockit1_6_0(in);
GCModel model = reader.read();
assertEquals("count", 11, model.size());
}
@Test
public void testGenPar() throws Exception {
InputStream in = getInputStream("SampleJRockit1_5_12_genpar.txt");
DataReader reader = new DataReaderJRockit1_5_0(in);
GCModel model = reader.read();
assertEquals("count", 17, model.size());
// 2 types of events excpected: "GC" and "parallel nursery GC"
Map<String, DoubleData> gcEventPauses = model.getGcEventPauses();
assertEquals("2 types of events found", 2, gcEventPauses.entrySet().size());
}
@Test
public void testCMSPromotionFailed() throws Exception {
final ByteArrayInputStream in =
new ByteArrayInputStream(
("2011-10-05T16:05:55.964+0200: 41985.374: [GC 41985.375: [ParNew (promotion failed): 104960K->100764K(104960K), 0.3379238 secs]41985.713: [CMS: 1239589K->897516K(1398144K), 38.3189415 secs] 1336713K->897516K(1503104K), [CMS Perm : 55043K->53511K(91736K)], 38.6583674 secs] [Times: user=39.22 sys=0.06, real=38.66 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("gc pause", 38.6583674, model.getFullGCPause().getSum(), 0.000001);
}
@Test
public void testPrintCmsStatistics() throws Exception {
// will not be able to extract sense from this line, but must not loop
ByteArrayInputStream in =
new ByteArrayInputStream(
("0.521: [GC[YG occupancy: 2234 K (14784 K)]0.522: [Rescan (parallel) (Survivor:0chunks) Finished young gen rescan work in 1th thread: 0.000 sec")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 0, model.size());
}
@Test
public void testCmsConcurrentMarkStart() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("2011-10-24T08:12:24.375+0200: 3388.929: [CMS-concurrent-mark-start]").getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("full gc pause", 0.0, model.getFullGCPause().getSum(), 0.01);
}
@Test
public void testFullGcIncrementalDatestamp2() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("2011-10-05T04:23:39.427+0200: 44189.823: [Full GC 44189.824: [CMS: 274825K->223922K(892264K), 8.0594203 secs] 327565K->223922K(992616K), [CMS Perm : 524287K->158591K(524288K)] icms_dc=0 , 8.0600619 secs] [Times: user=4.51 sys=0.05, real=8.06 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("full gc pause", 8.0600619, model.getFullGCPause().getSum(), 0.00000001);
}
@Test
public void testCMSWithoutPrintTimeStamp() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("2012-04-03T20:36:35.035+0200: [GC [ParNew: 16993K->2105K(19136K), 0.0270541 secs] 16993K->16424K(83008K), 0.0272020 secs] [Times: user=0.02 sys=0.05, real=0.03 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("heap", 83008, model.getHeapAllocatedSizes().getMax());
assertEquals("pause", 0.0272020, model.getGCPause().getMax(), 0.00000001);
}
@Test
public void testCmsRemarkTimestamp() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("13455.879: [GC[YG occupancy: 325751 K (471872 K)]13455.879: [Rescan (parallel) , 1.0591220 secs]13456.939: [weak refs processing, 0.0794109 secs] [1 CMS-remark: 1023653K(1572864K)] 1349404K(2044736K), 1.1490033 secs] [Times: user=19.09 sys=0.26, real=1.15 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("gc pause", 1.1490033, model.getGCPause().getSum(), 0.00000001);
}
@Test
public void testCmsRemarkSerial() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("0.778: [GC[YG occupancy: 2179 K (19136 K)]0.778: [Rescan (non-parallel) 0.778: [grey object rescan, 0.0014243 secs]0.780: [root rescan, 0.0000909 secs], 0.0015484 secs]0.780: [weak refs processing, 0.0000066 secs] [1 CMS-remark: 444198K(444416K)] 446377K(463552K), 0.0015882 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("gc pause", 0.0015882, model.getGCPause().getSum(), 0.00000001);
}
@Test
public void testCmsInitiatingOccupancyFraction() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("12460.657: [GC [1 CMS-initial-mark: 789976K(1572864K)] 838178K(2044736K), 0.3114519 secs] [Times: user=0.32 sys=0.00, real=0.31 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals(
"iof", 0.5022532145182292, model.getCmsInitiatingOccupancyFraction().average(), 0.0000001);
}
@Test
public void testFullGcSystem() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("164.078: [Full GC (System) 164.078: [Tenured: 107024K->86010K(349568K), 0.7964528 secs] 143983K->86010K(506816K), [Perm : 85883K->85855K(86016K)], 0.7965714 secs] [Times: user=0.84 sys=0.00, real=0.80 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("full gc pause", 0.7965714, model.getFullGCPause().getSum(), 0.00000001);
}
@Test
public void testPrintTenuringDistributionOpenJdk6() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
"3.141: [GCDesired survivor size 134217728 bytes, new threshold 7 (max 2) [PSYoungGen: 188744K->13345K(917504K)] 188744K->13345K(4063232K), 0.0285820 secs] [Times: user=0.06 sys=0.01, real=0.03 secs]"
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("count", 1, model.size());
assertEquals("main type", "GC", model.get(0).getType().getType());
assertEquals("detail type", "PSYoungGen", model.get(0).details().next().getType().getType());
}
@Test
public void testCMSFullGcCmsInterrupted() throws Exception {
// TODO CMS (concurrent mode interrupted) not recognised (ignored)
ByteArrayInputStream in =
new ByteArrayInputStream(
"78.579: [Full GC (System) 78.579: [CMS (concurrent mode interrupted): 64171K->1538K(107776K), 0.0088356 secs] 75362K->1538K(126912K), [CMS Perm : 2554K->2554K(21248K)], 0.0089351 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]"
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("count", 1, model.getPause().getN());
assertEquals("full gc pause", 0.0089351, model.getFullGCPause().getSum(), 0.00000001);
}
@Test
public void testCommaInTimestamp() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
"12,655: [GC [PSYoungGen: 262656K->28075K(306432K)] 262656K->28075K(1006848K), 0,3541657 secs] [Times: user=0,22 sys=0,48, real=0,35 secs]"
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("GC pause", 0.3541657, model.getGCPause().getMax(), 0.0000001);
assertEquals("GC timestamp", 12.655, model.get(0).getTimestamp(), 0.000001);
}
@Test
public void testCMSConcurrentModeFailureDate() throws Exception {
final ByteArrayInputStream in =
new ByteArrayInputStream(
("2011-10-05T15:53:24.119+0200: 41403.025: [GC 41403.025: [ParNew (promotion failed): 104960K->101572K(104960K), 0.3275017 secs]41403.353: [CMS2011-10-05T15:53:24.629+0200: 41403.534: [CMS-concurrent-abortable-preclean: 1.992/2.650 secs] [Times: user=4.40 sys=0.06, real=2.65 secs]"
+ "\n (concurrent mode failure): 1295417K->906090K(1398144K), 32.4123146 secs] 1395643K->906090K(1503104K), [CMS Perm : 54986K->53517K(91576K)], 32.7410609 secs] [Times: user=33.10 sys=0.05, real=32.74 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 2, model.size());
assertEquals("gc pause", 32.7410609, model.getFullGCPause().getMax(), 0.000001);
}
@Test
public void testCMSWithoutPrintTimeStampConcurrentModeFailure() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("2012-04-03T20:36:35.284+0200: [GC [ParNew: 19081K->19081K(19136K), 0.0000205 secs][CMS2012-04-03T20:36:35.285+0200: [CMS-concurrent-abortable-preclean: 0.005/0.150 secs] [Times: user=0.14 sys=0.14, real=0.15 secs]"
+ "\n (concurrent mode failure): 98182K->3832K(98624K), 0.0195864 secs] 117264K->3832K(117760K), [CMS Perm : 2614K->2613K(21248K)], 0.0199322 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 2, model.size());
assertEquals("heap", 117760, model.getHeapAllocatedSizes().getMax());
assertEquals("pause", 0.0199322, model.getFullGCPause().getMax(), 0.00000001);
}
@Test
public void testFullGcIncrementalDatestamp() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("2011-10-05T04:23:39.427+0200: 42927.215: [Full GC 42927.215: [CMS2011-10-05T04:23:39.427+0200: 42927.255: [CMS-concurrent-sweep: 0.416/6.288 secs] [Times: user=17.38 sys=0.44, real=6.29 secs]"
+ "\n (concurrent mode failure): 262166K->215967K(785256K), 7.8308614 secs] 273998K->215967K(800040K), [CMS Perm : 523009K->155678K(524288K)] icms_dc=8 , 7.8320634 secs] [Times: user=4.59 sys=0.04, real=7.83 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 2, model.size());
assertEquals("full gc pause", 7.8320634, model.getFullGCPause().getSum(), 0.00000001);
}
@Test
public void testAdaptiveSizePolicyFullSystemGc() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("2012-03-21T20:49:09.624+0100: 9.993: [Full GC (System)AdaptiveSizeStart: 10.000 collection: 61"
+ "\nAdaptiveSizeStop: collection: 61"
+ "\n[PSYoungGen: 480K->0K(270976K)] [PSOldGen: 89711K->671K(145536K)] 90191K->671K(416512K) [PSPermGen: 2614K->2614K(21248K)], 0.0070749 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("Full GC pause", 0.0070749, model.getFullGCPause().getMax(), 0.00000001);
}
@Test
public void testCMSConcurrentModeFailure() throws Exception {
final ByteArrayInputStream in =
new ByteArrayInputStream(
("25866.053: [GC 25866.054: [ParNew (promotion failed): 458123K->468193K(471872K), 0.9151441 secs]25866.969: [CMS25870.038: [CMS-concurrent-mark: 3.120/4.102 secs] [Times: user=26.00 sys=0.12, real=4.10 secs]"
+ "\n (concurrent mode failure): 1143630K->1154547K(1572864K), 40.1744087 secs] 1590086K->1154547K(2044736K), [CMS Perm : 65802K->63368K(109784K)], 41.0904457 secs] [Times: user=60.57 sys=0.07, real=41.09 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 2, model.size());
assertEquals("gc pause", 41.0904457, model.getFullGCPause().getMax(), 0.000001);
}
@Test
public void testCMSConcurrentModeFailureCmsAbortPreclean() throws Exception {
final ByteArrayInputStream in =
new ByteArrayInputStream(
("39323.400: [GC 39323.400: [ParNew (promotion failed): 471871K->457831K(471872K), 10.5045897 secs]39333.905: [CMS CMS: abort preclean due to time 39334.591: [CMS-concurrent-abortable-preclean: 4.924/15.546 secs] [Times: user=24.45 sys=9.40, real=15.55 secs]"
+ "\n (concurrent mode failure): 1301661K->1299268K(1572864K), 43.3433234 secs] 1757009K->1299268K(2044736K), [CMS Perm : 64534K->63216K(110680K)], 53.8487115 secs] [Times: user=54.83 sys=9.22, real=53.85 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 2, model.size());
assertEquals("gc pause", 53.8487115, model.getFullGCPause().getMax(), 0.000001);
}
/** Tests -XX:+PrintTenuringDistribution with -XX:+UseParallelGC */
@Test
public void testPSPrintTenuringDistribution() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("2012-04-10T20:58:43.009+0200: 0.690: [GC"
+ "\nDesired survivor size 89456640 bytes, new threshold 7 (max 15)"
+ "\n [PSYoungGen: 524288K->35633K(611648K)] 524288K->35633K(2009792K), 0.0240717 secs] [Times: user=0.01 sys=0.03, real=0.02 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 1, model.size());
assertEquals("heap", 2009792, model.getHeapAllocatedSizes().getMax());
assertEquals("pause", 0.0240717, model.getGCPause().getMax(), 0.00000001);
}
@Test
public void testPrintGCDateStamps() throws Exception {
final ByteArrayInputStream in =
new ByteArrayInputStream(
("2011-10-05T04:23:39.427+0200: 19.845: [GC 19.845: [ParNew: 93184K->5483K(104832K), 0.0384413 secs] 93184K->5483K(1036928K), 0.0388082 secs] [Times: user=0.41 sys=0.06, real=0.04 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertTrue("hasDateStamp", model.hasDateStamp());
assertEquals(
"DateStamp", dateParser.parse("2011-10-05T04:23:39.427+0200"), model.getFirstDateStamp());
assertEquals("gc pause", 0.0388082, model.getGCPause().getMax(), 0.000001);
}
@Test
public void testCMSPromotionFailedPrintPromotionFailure() throws Exception {
final ByteArrayInputStream in =
new ByteArrayInputStream(
("2012-03-26T21:46:32.546+0200: 2.204: [GC 2.204: [ParNew (0: promotion failure size = 4098) (1: promotion failure size = 4098) (2: promotion failure size = 4098) (3: promotion failure size = 4098) (promotion failed): 39277K->39255K(39296K), 0.0175749 secs]2.221: [CMS: 87276K->43438K(87424K), 0.0276222 secs] 95765K->43438K(126720K), [CMS Perm : 2612K->2612K(21248K)], 0.0453577 secs] [Times: user=0.08 sys=0.00, real=0.05 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals(
"gc type",
"GC ParNew (promotion failed): CMS: CMS Perm :",
model.getFullGCEvents().next().getTypeAsString());
}
@Test
public void testPrintHeapAtGC() throws Exception {
TestLogHandler handler = new TestLogHandler();
handler.setLevel(Level.WARNING);
IMP_LOGGER.addHandler(handler);
DATA_READER_FACTORY_LOGGER.addHandler(handler);
final InputStream in = getClass().getResourceAsStream("SampleSun1_6_0PrintHeapAtGC.txt");
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 2, model.size());
assertEquals("GC pause", 0.0134287, model.getGCPause().getMin(), 0.000000001);
assertEquals("number of errors", 0, handler.getCount());
}
@Test
public void testMixedLineTimestamp() throws Exception {
ByteArrayInputStream in =
new ByteArrayInputStream(
("36628.590: [GC 36628.591: [ParNew36628.625: [CMS-concurrent-abortable-preclean: 0.128/0.873 secs] [Times: user=2.52 sys=0.02, real=0.87 secs]"
+ "\n: 14780K->1041K(14784K), 0.0417590 secs] 304001K->295707K(721240K) icms_dc=56 , 0.0419761 secs] [Times: user=0.81 sys=0.01, real=0.04 secs]")
.getBytes());
final DataReader reader = new DataReaderSun1_6_0(in, GcLogType.SUN1_6);
GCModel model = reader.read();
assertEquals("GC count", 2, model.size());
assertEquals("gc pause", 0.0419761, model.getGCPause().getSum(), 0.00000001);
}
@Test
public void testGenCon() throws Exception {
InputStream in = getInputStream("SampleJRockit1_5_12_gencon.txt");
DataReader reader = new DataReaderJRockit1_5_0(in);
GCModel model = reader.read();
assertEquals("count", 8, model.size());
GCEvent event = (GCEvent) model.get(0);
assertEquals("timestamp", 6.038, event.getTimestamp(), 0.000001);
assertEquals("name", Type.JROCKIT_GC.getName(), event.getExtendedType().getName());
assertEquals("before", 3089328, event.getPreUsed());
assertEquals("after", 352551, event.getPostUsed());
assertEquals("total", 3145728, event.getTotal());
assertEquals("pause", 0.1186, event.getPause(), 0.0000001);
}