< prev index next >

src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogCompilation.java

Print this page
rev 8632 : 6900757: minor bug fixes to LogCompilation tool
* improve internal error reporting (point to XML element causing trouble)
* fix comparator for sorting by name and start
* make tool more robust wrt. incorrect options and files not found
* make inlining decision output more clear
* adopt uncommon traps history printing
* properly mention compiler in generated logs
* add options for printing time stamps and omitting compilation IDs
* add option for comparing compilation logs
* overall code cleanup and API documentation

*** 1,7 **** /* ! * Copyright (c) 2009, 2011, Oracle and/or its affiliates. All rights reserved. * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. * * This code is free software; you can redistribute it and/or modify it * under the terms of the GNU General Public License version 2 only, as * published by the Free Software Foundation. --- 1,7 ---- /* ! * Copyright (c) 2009, 2015, Oracle and/or its affiliates. All rights reserved. * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. * * This code is free software; you can redistribute it and/or modify it * under the terms of the GNU General Public License version 2 only, as * published by the Free Software Foundation.
*** 20,122 **** * or visit www.oracle.com if you need additional information or have any * questions. * */ - /** - * The main command line driver of a parser for LogCompilation output. - * @author never - */ - package com.sun.hotspot.tools.compiler; import java.io.PrintStream; import java.util.*; import org.xml.sax.*; import org.xml.sax.helpers.*; ! public class LogCompilation extends DefaultHandler implements ErrorHandler, Constants { public static void usage(int exitcode) { System.out.println("Usage: LogCompilation [ -v ] [ -c ] [ -s ] [ -e | -n ] file1 ..."); System.out.println(" -c: clean up malformed 1.5 xml"); System.out.println(" -i: print inlining decisions"); System.out.println(" -S: print compilation statistics"); ! System.out.println(" -s: sort events by start time"); System.out.println(" -e: sort events by elapsed time"); System.out.println(" -n: sort events by name and start"); System.exit(exitcode); } public static void main(String[] args) throws Exception { ! Comparator<LogEvent> defaultSort = LogParser.sortByStart; boolean statistics = false; boolean printInlining = false; boolean cleanup = false; int index = 0; while (args.length > index) { ! if (args[index].equals("-e")) { ! defaultSort = LogParser.sortByElapsed; index++; ! } else if (args[index].equals("-n")) { ! defaultSort = LogParser.sortByNameAndStart; index++; ! } else if (args[index].equals("-s")) { ! defaultSort = LogParser.sortByStart; index++; ! } else if (args[index].equals("-c")) { cleanup = true; index++; ! } else if (args[index].equals("-S")) { statistics = true; index++; ! } else if (args[index].equals("-h")) { usage(0); ! } else if (args[index].equals("-i")) { printInlining = true; index++; } else { break; } } if (index >= args.length) { usage(1); } while (index < args.length) { ! ArrayList<LogEvent> events = LogParser.parse(args[index], cleanup); if (statistics) { printStatistics(events, System.out); } else { - Collections.sort(events, defaultSort); for (LogEvent c : events) { ! if (printInlining && c instanceof Compilation) { ! Compilation comp = (Compilation)c; ! comp.print(System.out, true); } else { ! c.print(System.out); } } } index++; } } public static void printStatistics(ArrayList<LogEvent> events, PrintStream out) { long cacheSize = 0; long maxCacheSize = 0; int nmethodsCreated = 0; int nmethodsLive = 0; int[] attempts = new int[32]; - double regallocTime = 0; int maxattempts = 0; ! LinkedHashMap<String, Double> phaseTime = new LinkedHashMap<String, Double>(7); ! LinkedHashMap<String, Integer> phaseNodes = new LinkedHashMap<String, Integer>(7); double elapsed = 0; for (LogEvent e : events) { if (e instanceof Compilation) { Compilation c = (Compilation) e; --- 20,193 ---- * or visit www.oracle.com if you need additional information or have any * questions. * */ package com.sun.hotspot.tools.compiler; + import java.io.ByteArrayOutputStream; + import java.io.File; + import java.io.FileNotFoundException; + import java.io.FileOutputStream; import java.io.PrintStream; import java.util.*; + import org.xml.sax.*; import org.xml.sax.helpers.*; ! /** ! * The LogCompilation tool parses log files generated by HotSpot using the ! * {@code -XX:+LogCompilation} command line flag, and outputs the data ! * collected therein in a nicely formatted way. There are various sorting ! * options available, as well as options that select specific compilation ! * events (such as inlining decisions) for inclusion in the output. ! * ! * The tool is also capable of fixing broken compilation logs as sometimes ! * generated by Java 1.5 JVMs. ! */ ! public class LogCompilation extends DefaultHandler implements ErrorHandler { + /** + * Print usage information and terminate with a given exit code. + */ public static void usage(int exitcode) { System.out.println("Usage: LogCompilation [ -v ] [ -c ] [ -s ] [ -e | -n ] file1 ..."); + System.out.println("By default, the tool will print the logged compilations ordered by start time."); System.out.println(" -c: clean up malformed 1.5 xml"); System.out.println(" -i: print inlining decisions"); System.out.println(" -S: print compilation statistics"); ! System.out.println(" -U: print uncommon trap statistics"); ! System.out.println(" -t: print with time stamps"); ! System.out.println(" -s: sort events by start time (default)"); System.out.println(" -e: sort events by elapsed time"); System.out.println(" -n: sort events by name and start"); + System.out.println(" -C: compare logs (give files to compare on command line)"); + System.out.println(" -d: do not print compilation IDs"); System.exit(exitcode); } + /** + * Process command line arguments, parse log files and trigger desired + * functionality. + */ public static void main(String[] args) throws Exception { ! Comparator<LogEvent> sort = LogParser.sortByStart; boolean statistics = false; boolean printInlining = false; boolean cleanup = false; + boolean trapHistory = false; + boolean printTimeStamps = false; + boolean compare = false; + boolean printID = true; int index = 0; while (args.length > index) { ! String a = args[index]; ! if (a.equals("-e")) { ! sort = LogParser.sortByElapsed; index++; ! } else if (a.equals("-n")) { ! sort = LogParser.sortByNameAndStart; index++; ! } else if (a.equals("-s")) { ! sort = LogParser.sortByStart; index++; ! } else if (a.equals("-t")) { ! printTimeStamps = true; ! index++; ! } else if (a.equals("-c")) { cleanup = true; index++; ! } else if (a.equals("-S")) { statistics = true; index++; ! } else if (a.equals("-U")) { ! trapHistory = true; ! index++; ! } else if (a.equals("-h")) { usage(0); ! } else if (a.equals("-i")) { printInlining = true; index++; + } else if (a.equals("-C")) { + compare = true; + index++; + } else if (a.equals("-d")) { + printID = false; + index++; } else { + if (a.charAt(0) == '-') { + System.out.println("Unknown option '" + a + "', assuming file name."); + } break; } } if (index >= args.length) { usage(1); } + if (compare) { + compareLogs(index, args); + return; + } + while (index < args.length) { ! ArrayList<LogEvent> events = null; ! try { ! events = LogParser.parse(args[index], cleanup); ! } catch (FileNotFoundException fnfe) { ! System.out.println("File not found: " + args[index]); ! System.exit(1); ! } ! ! Collections.sort(events, sort); if (statistics) { printStatistics(events, System.out); + } else if (trapHistory) { + printTrapHistory(events, System.out); } else { for (LogEvent c : events) { ! if (c instanceof NMethod) { ! // skip these ! continue; ! } ! if (printTimeStamps) { ! System.out.print(c.getStart() + ": "); ! } ! if (c instanceof Compilation) { ! Compilation comp = (Compilation) c; ! comp.print(System.out, printID, printInlining); } else { ! c.print(System.out, printID); } } } index++; } } + /** + * Print extensive statistics from parsed log files. + */ public static void printStatistics(ArrayList<LogEvent> events, PrintStream out) { + // track code cache size long cacheSize = 0; long maxCacheSize = 0; + // track number of nmethods int nmethodsCreated = 0; int nmethodsLive = 0; + // track how many compilations were attempted multiple times + // (indexed by attempts, mapping to number of compilations) int[] attempts = new int[32]; int maxattempts = 0; ! // track time spent in compiler phases ! LinkedHashMap<String, Double> phaseTime = new LinkedHashMap<>(7); ! // track nodes created per phase ! LinkedHashMap<String, Integer> phaseNodes = new LinkedHashMap<>(7); double elapsed = 0; for (LogEvent e : events) { if (e instanceof Compilation) { Compilation c = (Compilation) e;
*** 135,156 **** Integer v2 = phaseNodes.get(phase.getName()); if (v2 == null) { v2 = Integer.valueOf(0); } phaseNodes.put(phase.getName(), Integer.valueOf(v2.intValue() + phase.getNodes())); ! /* Print phase name, elapsed time, nodes at the start of the phase, ! nodes created in the phase, live nodes at the start of the phase, ! live nodes added in the phase. ! */ ! out.printf("\t%s %6.4f %d %d %d %d\n", phase.getName(), phase.getElapsedTime(), phase.getStartNodes(), phase.getNodes(), phase.getStartLiveNodes(), phase.getLiveNodes()); } } else if (e instanceof MakeNotEntrantEvent) { MakeNotEntrantEvent mne = (MakeNotEntrantEvent) e; NMethod nm = mne.getNMethod(); if (mne.isZombie()) { if (nm == null) { ! System.err.println(mne.getId()); } cacheSize -= nm.getSize(); nmethodsLive--; } } else if (e instanceof NMethod) { --- 206,226 ---- Integer v2 = phaseNodes.get(phase.getName()); if (v2 == null) { v2 = Integer.valueOf(0); } phaseNodes.put(phase.getName(), Integer.valueOf(v2.intValue() + phase.getNodes())); ! // Print phase name, elapsed time, nodes at the start of ! // the phase, nodes created in the phase, live nodes at the ! // start of the phase, live nodes added in the phase. ! out.printf("\t%s %6.4f %d %d %d %d\n", phase.getName(), phase.getElapsedTime(), phase.getStartNodes(), phase.getNodes(), phase.getStartLiveNodes(), phase.getAddedLiveNodes()); } } else if (e instanceof MakeNotEntrantEvent) { MakeNotEntrantEvent mne = (MakeNotEntrantEvent) e; NMethod nm = mne.getNMethod(); if (mne.isZombie()) { if (nm == null) { ! System.err.println("zombie make not entrant event without nmethod: " + mne.getId()); } cacheSize -= nm.getSize(); nmethodsLive--; } } else if (e instanceof NMethod) {
*** 159,170 **** NMethod nm = (NMethod) e; cacheSize += nm.getSize(); maxCacheSize = Math.max(cacheSize, maxCacheSize); } } ! out.printf("NMethods: %d created %d live %d bytes (%d peak) in the code cache\n", ! nmethodsCreated, nmethodsLive, cacheSize, maxCacheSize); out.println("Phase times:"); for (String name : phaseTime.keySet()) { Double v = phaseTime.get(name); Integer v2 = phaseNodes.get(name); out.printf("%20s %6.4f %d\n", name, v.doubleValue(), v2.intValue()); --- 229,239 ---- NMethod nm = (NMethod) e; cacheSize += nm.getSize(); maxCacheSize = Math.max(cacheSize, maxCacheSize); } } ! out.printf("NMethods: %d created %d live %d bytes (%d peak) in the code cache\n", nmethodsCreated, nmethodsLive, cacheSize, maxCacheSize); out.println("Phase times:"); for (String name : phaseTime.keySet()) { Double v = phaseTime.get(name); Integer v2 = phaseNodes.get(name); out.printf("%20s %6.4f %d\n", name, v.doubleValue(), v2.intValue());
*** 176,181 **** --- 245,511 ---- for (int i = 0; i <= maxattempts; i++) { out.printf("%2d %8d\n", i, attempts[i]); } } } + + /** + * Container class for a pair of a method and a bytecode instruction index + * used by a compiler. This is used in + * {@linkplain #compareLogs() comparing logs}. + */ + static class MethodBCIPair { + public MethodBCIPair(Method m, int b, String c) { + method = m; + bci = b; + compiler = c; + } + + Method method; + int bci; + String compiler; + + public boolean equals(Object other) { + if (!(other instanceof MethodBCIPair)) { + return false; + } + MethodBCIPair otherp = (MethodBCIPair)other; + return (otherp.bci == bci && + otherp.method.equals(method) && + otherp.compiler.equals(compiler)); + } + + public int hashCode() { + return method.hashCode() + bci; + } + + public String toString() { + if (bci != -1) { + return method + "@" + bci + " (" + compiler + ")"; + } else { + return method + " (" + compiler + ")"; + } + } + } + + /** + * Compare a number of compilation log files. Each of the logs is parsed, + * and all compilations found therein are written to a sorted file (prefix + * {@code sorted-}. A summary is written to a new file {@code summary.txt}. + * + * @param index the index in the command line arguments at which to start + * looking for files to compare. + * @param args the command line arguments with which {@link LogCompilation} + * was originally invoked. + * + * @throws Exception in case any exceptions are thrown in the called + * methods. + */ + @SuppressWarnings("unchecked") + static void compareLogs(int index, String[] args) throws Exception { + HashMap<MethodBCIPair,MethodBCIPair> methods = new HashMap<>(); + ArrayList<HashMap<MethodBCIPair,Object>> logs = new ArrayList<>(); + PrintStream[] outs = new PrintStream[args.length - index]; + PrintStream summary = new PrintStream(new FileOutputStream("summary.txt")); + int o = 0; + // Process all logs given on the command line: collect compilation + // data; in particular, method/bci pairs. + while (index < args.length) { + String basename = new File(args[index]).getName(); + String outname = "sorted-" + basename; + System.out.println("Sorting " + basename + " to " + outname); + outs[o] = new PrintStream(new FileOutputStream(outname)); + o++; + System.out.println("Parsing " + args[index]); + ArrayList<LogEvent> events = LogParser.parse(args[index], false); + HashMap<MethodBCIPair,Object> compiles = new HashMap<>(); + logs.add(compiles); + for (LogEvent c : events) { + if (c instanceof Compilation) { + Compilation comp = (Compilation) c; + MethodBCIPair key = new MethodBCIPair(comp.getMethod(), comp.getBCI(), + comp.getCompiler()); + MethodBCIPair e = methods.get(key); + if (e == null) { + methods.put(key, key); + } else { + key = e; + } + Object other = compiles.get(key); + if (other == null) { + compiles.put(key, comp); + } else { + if (!(other instanceof List)) { + List<Object> l = new LinkedList<>(); + l.add(other); + l.add(comp); + compiles.put(key, l); + } else { + List<Object> l = (List<Object>) other; + l.add(comp); + } + } + } + } + index++; + } + + // Process the collected method/bci pairs and write the output. + for (MethodBCIPair pair : methods.keySet()) { + summary.print(pair + " "); + int base = -1; + String first = null; + boolean mismatch = false; + boolean different = false; + String[] output = new String[outs.length]; + o = 0; + for (HashMap<MethodBCIPair,Object> set : logs) { + Object e = set.get(pair); + String thisone = null; + Compilation lastc = null; + int n; + if (e == null) { + n = 0; + } else if (e instanceof Compilation) { + n = 1; + lastc = (Compilation) e; + } else { + // Compare the last compilation that was done for this method + n = ((List<Object>) e).size(); + lastc = (Compilation) ((List<Object>) e).get(n - 1); + } + if (lastc != null) { + n = 1; + ByteArrayOutputStream baos = new ByteArrayOutputStream(); + PrintStream ps = new PrintStream(baos); + lastc.print(ps, false); + ps.close(); + thisone = new String(baos.toByteArray()); + } + if (base == -1) { + base = n; + } else if (base != n) { + mismatch = true; + } + output[o++] = thisone; + if (thisone != null) { + if (first == null) { + first = thisone; + } else { + if (!first.equals(thisone)) { + different = true; + } + } + } + if (different) { + summary.print(n + "d "); + } else { + summary.print(n + " "); + } + } + if (mismatch) { + summary.print("mismatch"); + } + summary.println(); + if (different) { + for (int i = 0; i < outs.length; i++) { + if (output[i] != null) { + outs[i].println(output[i]); + } + } + } + } + for (int i = 0; i < outs.length; i++) { + outs[i].close(); + } + if (summary != System.out) { + summary.close(); + } + } + + /** + * Print the history of uncommon trap events. + */ + public static void printTrapHistory(ArrayList<LogEvent> events, PrintStream out) { + // map method names to a list of log events + LinkedHashMap<String, ArrayList<LogEvent>> traps = new LinkedHashMap<>(); + // map compilation IDs to compilations + HashMap<Integer, Compilation> comps = new HashMap<>(); + + // First, iterate over all logged events, collecting data about + // uncommon trap events. + for (LogEvent e : events) { + if (e instanceof NMethod) { + // skip these + continue; + } + if (e instanceof Compilation) { + Compilation c = (Compilation) e; + String name = c.getMethod().getFullName(); + ArrayList<LogEvent> elist = traps.get(name); + if (elist != null && comps.get(c.getId()) == null) { + comps.put(c.getId(), c); + // If there were previous events for the method + // then keep track of later compiles too. + elist.add(c); + } + continue; + } + if (e instanceof BasicLogEvent) { + BasicLogEvent ble = (BasicLogEvent) e; + Compilation c = ble.getCompilation(); + if (c == null) { + if (!(ble instanceof NMethod)) { + throw new InternalError("only nmethods should have a null compilation; here's a " + ble.getClass()); + } + continue; + } + String name = c.getMethod().getFullName(); + ArrayList<LogEvent> elist = traps.get(name); + if (elist == null) { + elist = new ArrayList<LogEvent>(); + traps.put(name, elist); + } + int bleId = Integer.parseInt(ble.getId()); + if (comps.get(bleId) == null) { + comps.put(bleId, c); + // Add the associated compile to the list. It + // will likely go at the end but we need to search + // backwards for the proper insertion point. + double start = c.getStart(); + int ipoint = 0; + while (ipoint < elist.size() && elist.get(ipoint).getStart() < start) { + ipoint++; + } + if (ipoint == elist.size()) { + elist.add(c); + } else { + elist.add(ipoint, c); + } + } + elist.add(ble); + } + } + + // Second, iterate over collected traps and output information. + for (String c: traps.keySet()) { + ArrayList<LogEvent> elist = traps.get(c); + String name = ((Compilation) elist.get(0)).getMethod().getFullName(); + System.out.println(name); + double start = 0; + for (LogEvent e: elist) { + if (start > e.getStart() && e.getStart() != 0) { + throw new InternalError("wrong sorting order for traps"); + } + start = e.getStart(); + out.print(e.getStart() + ": "); + if (e instanceof Compilation) { + ((Compilation) e).print(out, true, true, true); + } else { + e.print(out, true); + } + } + out.println(); + } + } + }
< prev index next >