Search in sources :

Example 6 with GCEvent

use of com.tagtraum.perf.gcviewer.model.GCEvent in project GCViewer by chewiebug.

the class DataReaderIBM_J9_R28 method read.

@Override
public GCModel read() throws IOException {
    GCModel model = new GCModel();
    try {
        XMLInputFactory factory = XMLInputFactory.newInstance();
        XMLEventReader eventReader = factory.createXMLEventReader(in);
        GCEvent currentGcEvent = null;
        String eventNameStart = null;
        while (eventReader.hasNext()) {
            try {
                XMLEvent event = eventReader.nextEvent();
                if (event.isStartElement()) {
                    StartElement startElement = event.asStartElement();
                    switch(startElement.getName().getLocalPart()) {
                        case VERBOSEGC:
                            handleVerboseGC(startElement);
                            break;
                        case INITIALIZED:
                            handleInitialized(eventReader);
                            break;
                        case EXCLUSIVE_START:
                            currentGcEvent = handleExclusiveStart(startElement);
                            break;
                        case SYS_START:
                            assert eventNameStart == null : "eventNameStart was expected to be null, but was " + eventNameStart;
                            eventNameStart = handleSysStart(eventReader, startElement);
                            break;
                        case AF_START:
                            assert eventNameStart == null : "eventNameStart was expected to be null, but was " + eventNameStart;
                            eventNameStart = handleAfStart(eventReader, startElement);
                            break;
                        case GC_START:
                            handleGcStart(eventReader, startElement, currentGcEvent, eventNameStart);
                            break;
                        case GC_END:
                            if (currentGcEvent.getTypeAsString() != null) {
                                handleGcEnd(eventReader, currentGcEvent);
                            }
                            break;
                        case EXCLUSIVE_END:
                            handleExclusiveEnd(startElement, currentGcEvent);
                            if (currentGcEvent.getExtendedType() == null) {
                                if (getLogger().isLoggable(Level.FINE))
                                    getLogger().fine("event at " + in.getLineNumber() + " doesn't contain any information, the parser can handle");
                            } else {
                                model.add(currentGcEvent);
                            }
                            currentGcEvent = null;
                            eventNameStart = null;
                            break;
                    }
                }
            } catch (Exception e) {
                if (e instanceof XMLStreamException) {
                    throw e;
                }
                if (getLogger().isLoggable(Level.WARNING))
                    getLogger().warning("line " + in.getLineNumber() + ": " + e.toString());
                if (getLogger().isLoggable(Level.FINE))
                    getLogger().log(Level.FINE, "line " + in.getLineNumber() + ": " + e.getMessage(), e);
            }
        }
    } catch (XMLStreamException e) {
        if (getLogger().isLoggable(Level.WARNING))
            getLogger().warning("line " + in.getLineNumber() + ": " + e.toString());
        if (getLogger().isLoggable(Level.FINE))
            getLogger().log(Level.FINE, "line " + in.getLineNumber() + ": " + e.getMessage(), e);
    } finally {
        if (getLogger().isLoggable(Level.INFO))
            getLogger().info("Done reading.");
    }
    return model;
}
Also used : StartElement(javax.xml.stream.events.StartElement) XMLStreamException(javax.xml.stream.XMLStreamException) XMLEvent(javax.xml.stream.events.XMLEvent) XMLEventReader(javax.xml.stream.XMLEventReader) AbstractGCEvent(com.tagtraum.perf.gcviewer.model.AbstractGCEvent) GCEvent(com.tagtraum.perf.gcviewer.model.GCEvent) GCModel(com.tagtraum.perf.gcviewer.model.GCModel) XMLInputFactory(javax.xml.stream.XMLInputFactory) IOException(java.io.IOException) DateTimeParseException(java.time.format.DateTimeParseException) XMLStreamException(javax.xml.stream.XMLStreamException) UnsupportedEncodingException(java.io.UnsupportedEncodingException)

Example 7 with GCEvent

use of com.tagtraum.perf.gcviewer.model.GCEvent in project GCViewer by chewiebug.

the class DataReaderIBM_J9_R28 method handleGcStart.

private void handleGcStart(XMLEventReader eventReader, StartElement startElement, GCEvent event, String eventNameStart) throws XMLStreamException, UnknownGcTypeException {
    String typeName = eventNameStart + getAttributeValue(startElement, "type");
    AbstractGCEvent.Type type = Type.lookup(typeName);
    if (type == null) {
        throw new UnknownGcTypeException(typeName, startElement.toString());
    }
    event.setType(type);
    String currentElementName = "";
    while (eventReader.hasNext() && !currentElementName.equals(GC_START)) {
        XMLEvent xmlEvent = eventReader.nextEvent();
        if (xmlEvent.isStartElement()) {
            StartElement startEl = xmlEvent.asStartElement();
            if (startEl.getName().getLocalPart().equals("mem-info")) {
                setTotalAndPreUsed(event, startEl);
            } else if (startEl.getName().getLocalPart().equals("mem")) {
                switch(getAttributeValue(startEl, "type")) {
                    case "nursery":
                        GCEvent young = new GCEvent();
                        young.setType(Type.lookup("nursery"));
                        setTotalAndPreUsed(young, startEl);
                        event.add(young);
                        break;
                    case "tenure":
                        GCEvent tenured = new GCEvent();
                        tenured.setType(Type.lookup("tenure"));
                        setTotalAndPreUsed(tenured, startEl);
                        event.add(tenured);
                        break;
                }
            }
        } else if (xmlEvent.isEndElement()) {
            EndElement endElement = xmlEvent.asEndElement();
            currentElementName = endElement.getName().getLocalPart();
        }
    }
}
Also used : StartElement(javax.xml.stream.events.StartElement) EndElement(javax.xml.stream.events.EndElement) Type(com.tagtraum.perf.gcviewer.model.AbstractGCEvent.Type) XMLEvent(javax.xml.stream.events.XMLEvent) AbstractGCEvent(com.tagtraum.perf.gcviewer.model.AbstractGCEvent) AbstractGCEvent(com.tagtraum.perf.gcviewer.model.AbstractGCEvent) GCEvent(com.tagtraum.perf.gcviewer.model.GCEvent)

Example 8 with GCEvent

use of com.tagtraum.perf.gcviewer.model.GCEvent in project GCViewer by chewiebug.

the class DataReaderIBMi5OS1_4_2 method read.

/**
     * Reads the GC data lines and translates them to GCEvents which
     * are collected in the GCModel.
     *
     * @throws IOException When reading the inputstream fails.
     */
public GCModel read() throws IOException {
    if (getLogger().isLoggable(Level.INFO))
        getLogger().info("Reading IBM i5/OS 1.4.2 format...");
    try {
        // Initialize model
        final GCModel model = new GCModel();
        model.setFormat(GCModel.Format.IBM_VERBOSE_GC);
        // Initialize local variables
        int state = 0;
        String line = null;
        GCEvent event = null;
        int freed = 0;
        int previousCycle = 0;
        int currentCycle = 0;
        long basetime = 0;
        // Initialize date formatter
        cycleStartGCFormat = new SimpleDateFormat("dd/MM/yy HH:mm:ss");
        // Read the GC data lines
        while ((line = in.readLine()) != null && shouldContinue()) {
            final String trimmedLine = line.trim();
            // GC Data line always start with GC
            if (!"".equals(trimmedLine) && !trimmedLine.startsWith("GC")) {
                if (getLogger().isLoggable(Level.INFO))
                    getLogger().info("Malformed line (" + in.getLineNumber() + "): " + line);
                state = 0;
            }
            switch(state) {
                case 0:
                    if (line.indexOf("GC:") != -1) {
                        // This is the start of the GC log
                        event = new GCEvent();
                        event.setType(AbstractGCEvent.Type.GC);
                        event.setPreUsed(parseInitialHeap(line));
                        event.setPostUsed(event.getPreUsed());
                        event.setTotal(event.getPreUsed());
                        model.add(event);
                        event = null;
                        // stay in state 0
                        break;
                    } else if (line.indexOf("collection starting") != -1) {
                        // This is the start of a GC event
                        event = new GCEvent();
                        event.setType(AbstractGCEvent.Type.GC);
                        final long time = parseGCCycleStart(line);
                        if (basetime == 0)
                            basetime = time;
                        event.setTimestamp((time - basetime) / 1000.0d);
                        state++;
                        break;
                    }
                    break;
                case 1:
                    // Collect data to add to the event
                    if (line.indexOf("current heap(KB) ") != -1) {
                        event.setTotal(parseTotalAfterGC(line));
                        break;
                    } else if (line.indexOf("collect (milliseconds) ") != -1) {
                        event.setPause(parsePause(line));
                        break;
                    } else if (line.indexOf("collected(KB) ") != -1) {
                        freed = parseFreed(line);
                        break;
                    } else if (line.indexOf("current cycle allocation(KB) ") != -1) {
                        previousCycle = parsePreviousCycle(line);
                        currentCycle = parseCurrentCycle(line);
                        event.setPreUsed((event.getTotal() - previousCycle - currentCycle) + freed);
                        event.setPostUsed((event.getTotal() - previousCycle - currentCycle));
                        break;
                    } else if (line.indexOf("collection ending") != -1) {
                        // End of GC event, store data in the model and reset variables
                        model.add(event);
                        event = null;
                        state = 0;
                        freed = 0;
                        previousCycle = 0;
                        currentCycle = 0;
                        break;
                    }
                    break;
                default:
            }
        }
        return model;
    } finally {
        if (in != null)
            try {
                in.close();
            } catch (IOException ioe) {
            }
        if (getLogger().isLoggable(Level.INFO))
            getLogger().info("Done reading.");
    }
}
Also used : IOException(java.io.IOException) GCEvent(com.tagtraum.perf.gcviewer.model.GCEvent) AbstractGCEvent(com.tagtraum.perf.gcviewer.model.AbstractGCEvent) GCModel(com.tagtraum.perf.gcviewer.model.GCModel) SimpleDateFormat(java.text.SimpleDateFormat)

Example 9 with GCEvent

use of com.tagtraum.perf.gcviewer.model.GCEvent in project GCViewer by chewiebug.

the class DataReaderJRockit1_6_0 method read.

public GCModel read() throws IOException {
    if (getLogger().isLoggable(Level.INFO))
        getLogger().info("Reading JRockit 1.6.0 format...");
    boolean gcSummary = false;
    try {
        GCModel model = new GCModel();
        model.setFormat(GCModel.Format.SUN_X_LOG_GC);
        String line = null;
        GCEvent event = null;
        int nurserySize = -1;
        while ((line = in.readLine()) != null && shouldContinue()) {
            // Sample JRockit log entry types to be parsed:
            //
            // [INFO ][memory ] GC mode: Garbage collection optimized for throughput, strategy: Generational Parallel Mark & Sweep
            // [INFO ][memory ] Heap size: 8388608KB, maximal heap size: 8388608KB, nursery size: 4194304KB
            // [INFO ][memory ] <start>-<end>: <type>..
            // [INFO ][memory ] [OC#2] 34.287-34.351: OC 460781KB->214044KB (524288KB), 0.064 s, sum of pauses 5.580 ms, longest pause 4.693 ms.
            final int memoryIndex = line.indexOf(MEMORY_MARKER);
            if (memoryIndex == -1) {
                if (getLogger().isLoggable(Level.FINE))
                    getLogger().fine("Ignoring line " + in.getLineNumber() + ". Missing \"[memory ]\" marker: " + line);
                continue;
            }
            if (line.endsWith(MEMORY_MARKER)) {
                continue;
            }
            final int startLog = memoryIndex + MEMORY_MARKER.length();
            // print some special JRockit summary statements to the log.
            if (!gcSummary) {
                gcSummary = line.endsWith("Memory usage report");
            }
            // Log any relevant memory usage reports at INFO level, rest as FINE
            if (gcSummary) {
                if (getLogger().isLoggable(Level.INFO))
                    getLogger().info(line.substring(startLog));
                continue;
            } else if (line.indexOf("Prefetch distance") != -1) {
                if (getLogger().isLoggable(Level.INFO))
                    getLogger().info(line.substring(startLog));
                continue;
            } else if (line.indexOf("GC mode") != -1) {
                if (getLogger().isLoggable(Level.INFO))
                    getLogger().info(line.substring(startLog));
                continue;
            } else if (line.indexOf("GC strategy") != -1) {
                if (getLogger().isLoggable(Level.INFO))
                    getLogger().info(line.substring(startLog));
                continue;
            } else if (line.indexOf("OutOfMemory") != -1) {
                if (getLogger().isLoggable(Level.INFO))
                    getLogger().warning("GC log contains OutOfMemory error: " + line.substring(startLog));
                continue;
            } else if (line.substring(startLog).startsWith("<")) {
                // ignore
                if (getLogger().isLoggable(Level.FINE))
                    getLogger().fine(line.substring(startLog));
                continue;
            } else if (line.toLowerCase().indexOf("heap size:") != -1) {
                if (getLogger().isLoggable(Level.INFO))
                    getLogger().info(line.substring(startLog));
                final int nurserySizeStart = line.indexOf(NURSERY_SIZE);
                final int nurserySizeEnd = line.indexOf('K', nurserySizeStart + NURSERY_SIZE.length());
                if (nurserySizeStart != -1) {
                    nurserySize = Integer.parseInt(line.substring(nurserySizeStart + NURSERY_SIZE.length(), nurserySizeEnd));
                }
                continue;
            } else if ((line.indexOf("C#") == -1) || (line.indexOf("->") == -1)) {
                // No [YC#] or [OC#] logs which we are interested in
                if (getLogger().isLoggable(Level.FINE))
                    getLogger().fine(line.substring(startLog));
                continue;
            }
            // Assume this is an actual GC log of interest. Look for time string, skip ahead of [OC#2]
            // [memory ] [OC#2] 34.287-34.351: OC 460781KB->214044KB (524288KB), 0.064 s, sum of pauses 5.580 ms, longest pause 4.693 ms.
            //   OR if timestamp logging enabled...
            // [memory ][Sat Oct 27 20:04:38 2012][23355] [OC#2]
            // skip to OC# or YC#
            int startGCStats = line.indexOf("C#");
            // Example:
            // go to end of "[OC#2]" in above example
            final int startTimeIndex = line.indexOf(']', startGCStats) + 1;
            final int colon = line.indexOf(':', startTimeIndex);
            if (colon == -1) {
                if (getLogger().isLoggable(Level.WARNING))
                    getLogger().warning("Malformed line (" + in.getLineNumber() + "). Missing colon after start time: " + line);
                continue;
            }
            event = new GCEvent();
            //34.287-34.351: OC 460781KB->214044KB (524288KB), 0.064 s, sum of pauses 5.580 ms, longest pause 4.693 ms.
            // set timestamp
            final String timestampString = line.substring(startTimeIndex, colon);
            final int minus = timestampString.indexOf('-');
            if (minus == -1) {
                event.setTimestamp(NumberParser.parseDouble(timestampString));
            } else {
                event.setTimestamp(NumberParser.parseDouble(timestampString.substring(0, minus)));
            }
            // set type
            final int typeStart = skipSpaces(colon + 1, line);
            int typeEnd = typeStart;
            while (!Character.isDigit(line.charAt(++typeEnd))) {
            }
            final AbstractGCEvent.Type type = AbstractGCEvent.Type.lookup("jrockit." + line.substring(typeStart, typeEnd).trim());
            if (type == null) {
                if (getLogger().isLoggable(Level.INFO))
                    getLogger().info("Failed to determine type: " + line.substring(startTimeIndex));
                continue;
            }
            event.setType(type);
            // Parse GC before/after sizes: "460781KB->214044KB (524288KB)"
            // before
            final int startBefore = typeEnd;
            final int endBefore = line.indexOf('K', startBefore);
            event.setPreUsed(Integer.parseInt(line.substring(startBefore, endBefore)));
            // after
            final int startAfter = endBefore + 4;
            final int endAfter = line.indexOf('K', startAfter);
            event.setPostUsed(Integer.parseInt(line.substring(startAfter, endAfter)));
            // total
            final int startTotal = line.indexOf('(', endAfter) + 1;
            final int endTotal = line.indexOf('K', startTotal);
            event.setTotal(Integer.parseInt(line.substring(startTotal, endTotal)));
            // pause
            // 7786210KB->3242204KB (8388608KB), 0.911 s, sum of pauses 865.900 ms, longest pause 865.900 ms.
            final int startPause = line.indexOf(PAUSE_MARKER, endTotal) + PAUSE_MARKER.length();
            final int endPause = line.indexOf(' ', startPause);
            event.setPause(NumberParser.parseDouble(line.substring(startPause, endPause)) / 1000.0d);
            model.add(event);
            // add artificial detail events
            if (nurserySize != -1 && event.getExtendedType().getGeneration() == Generation.YOUNG) {
                GCEvent detailEvent = new GCEvent();
                detailEvent.setType(event.getExtendedType().getType());
                detailEvent.setTimestamp(event.getTimestamp());
                detailEvent.setTotal(nurserySize);
                event.add(detailEvent);
            }
            if (nurserySize != -1 && event.getExtendedType().getGeneration() == Generation.TENURED) {
                GCEvent detailEvent = new GCEvent();
                detailEvent.setType(event.getExtendedType().getType());
                detailEvent.setTimestamp(event.getTimestamp());
                detailEvent.setTotal(event.getTotal() - nurserySize);
                event.add(detailEvent);
            }
        }
        return model;
    } finally {
        if (in != null)
            try {
                in.close();
            } catch (IOException ioe) {
            }
        if (getLogger().isLoggable(Level.INFO))
            getLogger().info("Reading done.");
    }
}
Also used : AbstractGCEvent(com.tagtraum.perf.gcviewer.model.AbstractGCEvent) IOException(java.io.IOException) GCEvent(com.tagtraum.perf.gcviewer.model.GCEvent) AbstractGCEvent(com.tagtraum.perf.gcviewer.model.AbstractGCEvent) GCModel(com.tagtraum.perf.gcviewer.model.GCModel)

Example 10 with GCEvent

use of com.tagtraum.perf.gcviewer.model.GCEvent in project GCViewer by chewiebug.

the class DataReaderSun1_2_2 method read.

public GCModel read() throws IOException {
    if (getLogger().isLoggable(Level.INFO))
        getLogger().info("Reading Sun 1.2.2 format...");
    try {
        GCModel model = new GCModel();
        model.setFormat(GCModel.Format.SUN_1_2_2VERBOSE_GC);
        String line = null;
        boolean timeline = false;
        AbstractGCEvent<GCEvent> lastEvent = new GCEvent();
        GCEvent event = null;
        while ((line = in.readLine()) != null && shouldContinue()) {
            if (!timeline) {
                if (line.endsWith("milliseconds since last GC>")) {
                    timeline = true;
                    double time = Integer.parseInt(line.substring(5, line.indexOf(' ', 5)));
                    event = new GCEvent();
                    event.setTimestamp(lastEvent.getTimestamp() + (time / 1000.0d));
                }
            } else {
                timeline = false;
                // we have a time, so now we expect a either expansion or freed objects
                if (line.indexOf("expanded object space by") != -1) {
                    // expansion
                    int endIndex = line.indexOf(' ', "<GC: expanded object space by ".length());
                    //int incBy = Integer.parseInt(line.substring("<GC: expanded object space by ".length(), endIndex));
                    int beginIndex = endIndex + " to ".length();
                    int incTo = Integer.parseInt(line.substring(beginIndex, line.indexOf(' ', beginIndex)));
                    int percentUsed = Integer.parseInt(line.substring(line.length() - "XX% free>".length(), line.length() - "% free>".length()));
                    event.setPostUsed((int) ((incTo * percentUsed / 1024L / 100l)));
                    event.setPreUsed(event.getPostUsed());
                    event.setTotal((int) (incTo / 1024L));
                    event.setType(AbstractGCEvent.Type.GC);
                    event.setPause(0);
                    model.add(event);
                    lastEvent = event;
                } else if (line.indexOf(" freed ") != -1 && line.indexOf(" objects, ") != -1) {
                    // freed objects
                    int startIndex = line.indexOf(',') + 2;
                    int endIndex = line.indexOf(' ', startIndex);
                    int freed = Integer.parseInt(line.substring(startIndex, endIndex));
                    startIndex = line.indexOf("in ") + 3;
                    endIndex = line.indexOf(' ', startIndex);
                    int pause = Integer.parseInt(line.substring(startIndex, endIndex));
                    startIndex = line.indexOf('(') + 1;
                    endIndex = line.indexOf('/', startIndex);
                    int postFree = Integer.parseInt(line.substring(startIndex, endIndex));
                    startIndex = line.indexOf('/') + 1;
                    endIndex = line.indexOf(')', startIndex);
                    int total = Integer.parseInt(line.substring(startIndex, endIndex));
                    event.setPostUsed((total - postFree) / 1024);
                    event.setPreUsed((total - postFree + freed) / 1024);
                    //event.setPostUsed(event.getPreUsed());
                    event.setTotal(total / 1024);
                    event.setType(AbstractGCEvent.Type.GC);
                    event.setPause((pause) / 1000.0d);
                    model.add(event);
                    lastEvent = event;
                /*
                        event = new GCEvent();
                        event.setTimestamp(lastEvent.getTimestamp() + lastEvent.getPause());
                        event.setPostUsed((total - postFree) / 1024L);
                        event.setPreUsed(lastEvent.getPostUsed());
                        event.setTotal(total / 1024L);
                        event.setType(GCEvent.Type.GC);
                        event.setPause(0);
                        model.add(event);
                        lastEvent = event;
                        */
                } else {
                // hm. what now...?
                }
            }
        }
        return model;
    } finally {
        if (in != null)
            try {
                in.close();
            } catch (IOException ioe) {
            }
        if (getLogger().isLoggable(Level.INFO))
            getLogger().info("Done reading.");
    }
}
Also used : IOException(java.io.IOException) GCEvent(com.tagtraum.perf.gcviewer.model.GCEvent) AbstractGCEvent(com.tagtraum.perf.gcviewer.model.AbstractGCEvent) GCModel(com.tagtraum.perf.gcviewer.model.GCModel)

Aggregations

GCEvent (com.tagtraum.perf.gcviewer.model.GCEvent)60 GCModel (com.tagtraum.perf.gcviewer.model.GCModel)45 Test (org.junit.Test)33 AbstractGCEvent (com.tagtraum.perf.gcviewer.model.AbstractGCEvent)26 GcResourceFile (com.tagtraum.perf.gcviewer.model.GcResourceFile)21 GCResource (com.tagtraum.perf.gcviewer.model.GCResource)13 IOException (java.io.IOException)11 ByteArrayInputStream (java.io.ByteArrayInputStream)5 SimpleDateFormat (java.text.SimpleDateFormat)3 StringTokenizer (java.util.StringTokenizer)3 Paint (java.awt.Paint)2 StartElement (javax.xml.stream.events.StartElement)2 XMLEvent (javax.xml.stream.events.XMLEvent)2 Before (org.junit.Before)2 Type (com.tagtraum.perf.gcviewer.model.AbstractGCEvent.Type)1 ConcurrentGCEvent (com.tagtraum.perf.gcviewer.model.ConcurrentGCEvent)1 VmOperationEvent (com.tagtraum.perf.gcviewer.model.VmOperationEvent)1 GradientPaint (java.awt.GradientPaint)1 InputStream (java.io.InputStream)1 UnsupportedEncodingException (java.io.UnsupportedEncodingException)1