Mercurial > hg > jdk9-shenandoah > hotspot
changeset 9462:0fb7705845de
6900757: minor bug fixes to LogCompilation tool
Summary: 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
Reviewed-by: kvn, vlivanov
line wrap: on
line diff
--- a/.hgignore Mon Jul 13 13:22:21 2015 -0700 +++ b/.hgignore Tue Mar 31 21:46:44 2015 +0200 @@ -10,3 +10,4 @@ .igv.log ^.hgtip .DS_Store +\.class$
--- a/src/share/tools/LogCompilation/Makefile Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/Makefile Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ # -# Copyright (c) 2009, Oracle and/or its affiliates. All rights reserved. +# 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 @@ -62,7 +62,7 @@ logc.jar: filelist manifest.mf @mkdir -p $(OUTPUT_DIR) - $(JAVAC) -source 1.5 -deprecation -sourcepath $(SRC_DIR) -d $(OUTPUT_DIR) @filelist + $(JAVAC) -deprecation -sourcepath $(SRC_DIR) -d $(OUTPUT_DIR) @filelist $(JAR) cvfm logc.jar manifest.mf -C $(OUTPUT_DIR) com .PHONY: filelist
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/BasicLogEvent.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/BasicLogEvent.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -27,14 +27,29 @@ import java.io.PrintStream; /** - * - * @author never + * Provide basic data structures and behaviour for {@link LogEvent}s. */ public abstract class BasicLogEvent implements LogEvent { + /** + * The event's ID. This is a number; we represent it as a string for + * convenience. + */ protected final String id; + + /** + * The event's start time. + */ protected final double start; + + /** + * The event's end time. + */ protected double end; + + /** + * The compilation during which this event was signalled. + */ protected Compilation compilation; BasicLogEvent(double start, String id) { @@ -43,33 +58,37 @@ this.id = id; } - public double getStart() { + public final double getStart() { return start; } - public double getEnd() { + public final double getEnd() { return end; } - public void setEnd(double end) { + public final void setEnd(double end) { this.end = end; } - public double getElapsedTime() { + public final double getElapsedTime() { return ((int) ((getEnd() - getStart()) * 1000)) / 1000.0; } - public String getId() { + public final String getId() { return id; } - public Compilation getCompilation() { + public final Compilation getCompilation() { return compilation; } + /** + * Set the compilation for this event. This is not a {@code final} method + * as it is overridden in {@link UncommonTrapEvent}. + */ public void setCompilation(Compilation compilation) { this.compilation = compilation; } - abstract public void print(PrintStream stream); + abstract public void print(PrintStream stream, boolean printID); }
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/CallSite.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/CallSite.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, 2013, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -29,41 +29,119 @@ import java.util.ArrayList; import java.util.List; +/** + * Representation of a compilation scope in a compilation log. This class is a + * hybrid: its instances can represent original scopes of methods being + * compiled, but are also used to represent call sites in given methods. + */ public class CallSite { + /** + * The index of the call in the caller. This will be 0 if this instance + * represents a compilation root. + */ private int bci; + + /** + * The method that is called at this call site. This will be {@code null} + * if this instance represents a compilation root. + */ private Method method; + + /** + * The invocation count for this call site. + */ private int count; + + /** + * The receiver type of the call represented by this instance, if known. + */ private String receiver; + + /** + * In case the {@linkplain receiver receiver type} of the call represented + * by this instance is known, this is how often the type was encountered. + */ private int receiver_count; + + /** + * The reason for a success or failure of an inlining operation at this + * call site. + */ private String reason; + + /** + * A list of all calls in this compilation scope. + */ private List<CallSite> calls; + + /** + * Number of nodes in the graph at the end of parsing this compilation + * scope. + */ private int endNodes; + + /** + * Number of live nodes in the graph at the end of parsing this compilation + * scope. + */ private int endLiveNodes; + + /** + * Time in seconds since VM startup at which parsing this compilation scope + * ended. + */ private double timeStamp; + + /** + * The inline ID in case the call represented by this instance is inlined, + * 0 otherwise. + */ private long inlineId; - CallSite() { - } + /** + * List of uncommon traps in this compilation scope. + */ + private List<UncommonTrap> traps; + /** + * Default constructor: used to create an instance that represents the top + * scope of a compilation. + */ + CallSite() {} + + /** + * Constructor to create an instance that represents an actual method call. + */ CallSite(int bci, Method m) { this.bci = bci; this.method = m; } + /** + * Add a call site to the compilation scope represented by this instance. + */ void add(CallSite site) { if (getCalls() == null) { - setCalls(new ArrayList<CallSite>()); + calls = new ArrayList<>(); } getCalls().add(site); } + /** + * Return the last of the {@linkplain #getCalls() call sites} in this + * compilation scope. + */ CallSite last() { - return last(-1); + return getCalls().get(getCalls().size() - 1); } - CallSite last(int fromEnd) { - return getCalls().get(getCalls().size() + fromEnd); + /** + * Return the last-but-one of the {@linkplain #getCalls() call sites} in + * this compilation scope. + */ + CallSite lastButOne() { + return getCalls().get(getCalls().size() - 2); } public String toString() { @@ -84,7 +162,7 @@ } public void print(PrintStream stream) { - print(stream, 0); + print(stream, 0, true, false); } void emit(PrintStream stream, int indent) { @@ -92,21 +170,14 @@ stream.print(' '); } } - private static boolean compat = true; - public void print(PrintStream stream, int indent) { + public void print(PrintStream stream, int indent, boolean printInlining, boolean printUncommonTraps) { emit(stream, indent); String m = getMethod().getHolder() + "::" + getMethod().getName(); if (getReason() == null) { stream.print(" @ " + getBci() + " " + m + " (" + getMethod().getBytes() + " bytes)"); - } else { - if (isCompat()) { - stream.print(" @ " + getBci() + " " + m + " " + getReason()); - } else { - stream.print("- @ " + getBci() + " " + m + - " (" + getMethod().getBytes() + " bytes) " + getReason()); - } + stream.print(" @ " + getBci() + " " + m + " " + getReason()); } stream.printf(" (end time: %6.4f", getTimeStamp()); if (getEndNodes() > 0) { @@ -116,13 +187,16 @@ if (getReceiver() != null) { emit(stream, indent + 4); - // stream.println("type profile " + method.holder + " -> " + receiver + " (" + - // receiver_count + "/" + count + "," + (receiver_count * 100 / count) + "%)"); stream.println("type profile " + getMethod().getHolder() + " -> " + getReceiver() + " (" + (getReceiverCount() * 100 / getCount()) + "%)"); } - if (getCalls() != null) { + if (printInlining && getCalls() != null) { for (CallSite site : getCalls()) { + site.print(stream, indent + 2, printInlining, printUncommonTraps); + } + } + if (printUncommonTraps && getTraps() != null) { + for (UncommonTrap site : getTraps()) { site.print(stream, indent + 2); } } @@ -180,16 +254,15 @@ return calls; } - public void setCalls(List<CallSite> calls) { - this.calls = calls; + public List<UncommonTrap> getTraps() { + return traps; } - public static boolean isCompat() { - return compat; - } - - public static void setCompat(boolean aCompat) { - compat = aCompat; + void add(UncommonTrap e) { + if (traps == null) { + traps = new ArrayList<UncommonTrap>(); + } + traps.add(e); } void setEndNodes(int n) { @@ -216,21 +289,30 @@ return timeStamp; } + /** + * Check whether this call site matches another. Every late inline call + * site has a unique inline ID. If the call site we're looking for has one, + * then use it; otherwise rely on method name and byte code index. + */ private boolean matches(CallSite other) { - // Every late inline call site has a unique inline id. If the - // call site we're looking for has one then use it other rely - // on method name and bci. if (other.inlineId != 0) { return inlineId == other.inlineId; } return method.equals(other.method) && bci == other.bci; } + /** + * Locate a late inline call site: find, in this instance's + * {@linkplain #calls call sites}, the one furthest down the given call + * stack. + * + * Multiple chains of identical call sites with the same method name / bci + * combination are possible, so we have to try them all until we find the + * late inline call site that has a matching inline ID. + * + * @return a matching call site, or {@code null} if none was found. + */ public CallSite findCallSite(ArrayDeque<CallSite> sites) { - // Locate a late inline call site. Multiple chains of - // identical call sites with the same method name/bci are - // possible so we have to try them all until we find the late - // inline call site that has a matching inline id. if (calls == null) { return null; } @@ -253,6 +335,11 @@ return null; } + /** + * Locate a late inline call site in the tree spanned by all this instance's + * {@linkplain #calls call sites}, and return the sequence of call sites + * (scopes) leading to that late inline call site. + */ public ArrayDeque<CallSite> findCallSite2(CallSite site) { if (calls == null) { return null; @@ -260,7 +347,7 @@ for (CallSite c : calls) { if (c.matches(site)) { - ArrayDeque<CallSite> stack = new ArrayDeque<CallSite>(); + ArrayDeque<CallSite> stack = new ArrayDeque<>(); stack.push(c); return stack; } else {
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Compilation.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Compilation.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, 2012, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -27,22 +27,94 @@ import java.io.PrintStream; import java.util.ArrayList; +/** + * One particular compilation, represented in the compilation log file as a + * {@code task} element. + */ public class Compilation implements LogEvent { + /** + * The compilation ID. + */ private int id; + + /** + * Whether this is a compilation for on-stack replacement (OSR). + */ private boolean osr; + + /** + * The method being compiled. + */ private Method method; + + /** + * The {@linkplain CallSite scope} of this compilation. This is created as + * an empty {@link CallSite} instance, to be filled with data (and + * meaning) later on. + */ private CallSite call = new CallSite(); + + /** + * In case a {@code late_inline} event occurs during the compilation, this + * field holds the information about it. + */ private CallSite lateInlineCall = new CallSite(); - private int osrBci; + + /** + * The bytecode instruction index for on-stack replacement compilations; -1 + * if this is not an OSR compilation. + */ + private int bci; + + /** + * The method under compilation's invocation count. + */ private String icount; + + /** + * The method under compilation's backedge count. + */ private String bcount; + + /** + * Additional information for special compilations (e.g., adapters). + */ private String special; + + /** + * The name of the compiler performing this compilation. + */ + private String compiler; + + /** + * Start time stamp. + */ private double start; + + /** + * End time stamp. + */ private double end; + + /** + * Trip count of the register allocator. + */ private int attempts; + + /** + * The compilation result (a native method). + */ private NMethod nmethod; - private ArrayList<Phase> phases = new ArrayList<Phase>(4); + + /** + * The phases through which this compilation goes. + */ + private ArrayList<Phase> phases = new ArrayList<>(4); + + /** + * In case this compilation fails, the reason for that. + */ private String failureReason; Compilation(int id) { @@ -52,9 +124,17 @@ void reset() { call = new CallSite(); lateInlineCall = new CallSite(); - phases = new ArrayList<Phase>(4); + phases = new ArrayList<>(4); } + /** + * Get a compilation phase by name, or {@code null}. + * + * @param s the name of the phase to retrieve in this compilation. + * + * @return a compilation phase, or {@code null} if no phase with the given + * name is found. + */ Phase getPhase(String s) { for (Phase p : getPhases()) { if (p.getName().equals(s)) { @@ -72,20 +152,32 @@ return start; } + public void setCompiler(String compiler) { + this.compiler = compiler; + } + + public String getCompiler() { + return compiler; + } + @Override public String toString() { StringBuilder sb = new StringBuilder(); sb.append(getId()); sb.append(" "); + sb.append(getCompiler()); + sb.append(" "); sb.append(getMethod()); sb.append(" "); sb.append(getIcount()); sb.append("+"); sb.append(getBcount()); sb.append("\n"); - for (CallSite site : getCall().getCalls()) { - sb.append(site); - sb.append("\n"); + if (getCall() != null && getCall().getCalls() != null) { + for (CallSite site : getCall().getCalls()) { + sb.append(site); + sb.append("\n"); + } } if (getLateInlineCall().getCalls() != null) { sb.append("late inline:\n"); @@ -101,38 +193,50 @@ if (getMethod() == null) { stream.println(getSpecial()); } else { - int bc = isOsr() ? getOsr_bci() : -1; - stream.print(getId() + getMethod().decodeFlags(bc) + getMethod().format(bc)); + int bc = isOsr() ? getBCI() : -1; + stream.print(getId() + getMethod().decodeFlags(bc) + " " + compiler + " " + getMethod().format(bc)); } } - public void print(PrintStream stream) { - print(stream, 0, false); + public void print(PrintStream stream, boolean printID) { + print(stream, 0, printID, true, false); } - public void print(PrintStream stream, boolean printInlining) { - print(stream, 0, printInlining); + public void print(PrintStream stream, boolean printID, boolean printInlining) { + print(stream, 0, printID, printInlining, false); } - public void print(PrintStream stream, int indent, boolean printInlining) { + public void print(PrintStream stream, boolean printID, boolean printInlining, boolean printUncommonTraps) { + print(stream, 0, printID, printInlining, printUncommonTraps); + } + + public void print(PrintStream stream, int indent, boolean printID, boolean printInlining, boolean printUncommonTraps) { if (getMethod() == null) { stream.println(getSpecial()); } else { - int bc = isOsr() ? getOsr_bci() : -1; - stream.print(getId() + getMethod().decodeFlags(bc) + getMethod().format(bc)); + if (printID) { + stream.print(getId()); + } + int bc = isOsr() ? getBCI() : -1; + stream.print(getMethod().decodeFlags(bc) + " " + compiler + " " + getMethod().format(bc)); stream.println(); if (getFailureReason() != null) { - stream.println("COMPILE FAILED " + getFailureReason()); + stream.println("COMPILE SKIPPED: " + getFailureReason() + " (not retryable)"); } if (printInlining && call.getCalls() != null) { for (CallSite site : call.getCalls()) { + site.print(stream, indent + 2, printInlining, printUncommonTraps); + } + } + if (printUncommonTraps && call.getTraps() != null) { + for (UncommonTrap site : call.getTraps()) { site.print(stream, indent + 2); } } if (printInlining && lateInlineCall.getCalls() != null) { stream.println("late inline:"); for (CallSite site : lateInlineCall.getCalls()) { - site.print(stream, indent + 2); + site.print(stream, indent + 2, printInlining, printUncommonTraps); } } } @@ -154,12 +258,12 @@ this.osr = osr; } - public int getOsr_bci() { - return osrBci; + public int getBCI() { + return bci; } - public void setOsr_bci(int osrBci) { - this.osrBci = osrBci; + public void setBCI(int osrBci) { + this.bci = osrBci; } public String getIcount() { @@ -230,9 +334,13 @@ return method; } + /** + * Set the method under compilation. If it is already set, ignore the + * argument to avoid changing the method by post-parse inlining info. + * + * @param method the method under compilation. May be ignored. + */ public void setMethod(Method method) { - // Don't change method if it is already set to avoid changing - // it by post parse inlining info. if (getMethod() == null) { this.method = method; }
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogCleanupReader.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogCleanupReader.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -31,10 +31,9 @@ * This class is a filter class to deal with malformed XML that used * to be produced by the JVM when generating LogCompilation. In 1.6 * and later releases it shouldn't be required. - * @author never */ +class LogCleanupReader extends Reader { -class LogCleanupReader extends Reader { private Reader reader; private char[] buffer = new char[4096]; @@ -55,32 +54,38 @@ reader = r; } - static final private Matcher pattern = Pattern.compile(".+ compile_id='[0-9]+'.*( compile_id='[0-9]+)").matcher(""); - static final private Matcher pattern2 = Pattern.compile("' (C[12]) compile_id=").matcher(""); - static final private Matcher pattern3 = Pattern.compile("'(destroy_vm)/").matcher(""); + static final private Matcher duplicateCompileID = Pattern.compile(".+ compile_id='[0-9]+'.*( compile_id='[0-9]+)").matcher(""); + static final private Matcher compilerName = Pattern.compile("' (C[12]) compile_id=").matcher(""); + static final private Matcher destroyVM = Pattern.compile("'(destroy_vm)/").matcher(""); + /** + * The log cleanup takes place in this method. If any of the three patterns + * ({@link #duplicateCompileID}, {@link #compilerName}, {@link #destroyVM}) + * match, that indicates a problem in the log. The cleanup is performed by + * correcting the input line and writing it back into the {@link #line} + * buffer. + */ private void fill() throws IOException { rawFill(); if (length != -1) { boolean changed = false; String s = new String(line, 0, length); - String orig = s; - pattern2.reset(s); - if (pattern2.find()) { - s = s.substring(0, pattern2.start(1)) + s.substring(pattern2.end(1) + 1); + compilerName.reset(s); + if (compilerName.find()) { + s = s.substring(0, compilerName.start(1)) + s.substring(compilerName.end(1) + 1); changed = true; } - pattern.reset(s); - if (pattern.lookingAt()) { - s = s.substring(0, pattern.start(1)) + s.substring(pattern.end(1) + 1); + duplicateCompileID.reset(s); + if (duplicateCompileID.lookingAt()) { + s = s.substring(0, duplicateCompileID.start(1)) + s.substring(duplicateCompileID.end(1) + 1); changed = true; } - pattern3.reset(s); - if (pattern3.find()) { - s = s.substring(0, pattern3.start(1)) + s.substring(pattern3.end(1)); + destroyVM.reset(s); + if (destroyVM.find()) { + s = s.substring(0, destroyVM.start(1)) + s.substring(destroyVM.end(1)); changed = true; }
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogCompilation.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogCompilation.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, 2011, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -22,60 +22,102 @@ * */ -/** - * The main command line driver of a parser for LogCompilation output. - * @author never - */ - 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.*; -public class LogCompilation extends DefaultHandler implements ErrorHandler, Constants { +/** + * 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(" -s: sort events by start time"); + 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> defaultSort = LogParser.sortByStart; + 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) { - if (args[index].equals("-e")) { - defaultSort = LogParser.sortByElapsed; + String a = args[index]; + if (a.equals("-e")) { + sort = LogParser.sortByElapsed; + index++; + } else if (a.equals("-n")) { + sort = LogParser.sortByNameAndStart; index++; - } else if (args[index].equals("-n")) { - defaultSort = LogParser.sortByNameAndStart; + } else if (a.equals("-s")) { + sort = LogParser.sortByStart; index++; - } else if (args[index].equals("-s")) { - defaultSort = LogParser.sortByStart; + } else if (a.equals("-t")) { + printTimeStamps = true; index++; - } else if (args[index].equals("-c")) { + } else if (a.equals("-c")) { cleanup = true; index++; - } else if (args[index].equals("-S")) { + } else if (a.equals("-S")) { statistics = true; index++; - } else if (args[index].equals("-h")) { + } else if (a.equals("-U")) { + trapHistory = true; + index++; + } else if (a.equals("-h")) { usage(0); - } else if (args[index].equals("-i")) { + } 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; } } @@ -84,19 +126,40 @@ usage(1); } + if (compare) { + compareLogs(index, args); + return; + } + while (index < args.length) { - ArrayList<LogEvent> events = LogParser.parse(args[index], cleanup); + 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 { - Collections.sort(events, defaultSort); for (LogEvent c : events) { - if (printInlining && c instanceof Compilation) { - Compilation comp = (Compilation)c; - comp.print(System.out, true); + 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); + c.print(System.out, printID); } } } @@ -104,17 +167,25 @@ } } + /** + * 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]; - double regallocTime = 0; int maxattempts = 0; - LinkedHashMap<String, Double> phaseTime = new LinkedHashMap<String, Double>(7); - LinkedHashMap<String, Integer> phaseNodes = new LinkedHashMap<String, Integer>(7); + // 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) { @@ -137,18 +208,17 @@ 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()); + // 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(mne.getId()); + System.err.println("zombie make not entrant event without nmethod: " + mne.getId()); } cacheSize -= nm.getSize(); nmethodsLive--; @@ -161,8 +231,7 @@ 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.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); @@ -178,4 +247,265 @@ } } } + + /** + * 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(); + } + } + }
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogEvent.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogEvent.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -25,14 +25,31 @@ package com.sun.hotspot.tools.compiler; import java.io.PrintStream; -import java.util.*; +/** + * The interface of an event from a HotSpot compilation log. Events can have a + * duration, e.g., a compiler {@link Phase} is an event, and so is an entire + * {@link Compilation}. + */ public interface LogEvent { + + /** + * The event's start time. + */ public double getStart(); + /** + * The event's duration in milliseconds. + */ public double getElapsedTime(); + /** + * The compilation during which this event was signalled. + */ public Compilation getCompilation(); - public void print(PrintStream stream); + /** + * Print the event to the given stream. + */ + public void print(PrintStream stream, boolean printID); }
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogParser.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/LogParser.java Tue Mar 31 21:46:44 2015 +0200 @@ -33,30 +33,269 @@ import java.io.Reader; import java.util.ArrayDeque; import java.util.ArrayList; -import java.util.Collections; import java.util.Comparator; +import java.util.Deque; import java.util.HashMap; import java.util.LinkedHashMap; -import java.util.Stack; +import java.util.regex.Pattern; + import javax.xml.parsers.SAXParser; import javax.xml.parsers.SAXParserFactory; + import org.xml.sax.Attributes; import org.xml.sax.ErrorHandler; import org.xml.sax.InputSource; +import org.xml.sax.Locator; import org.xml.sax.helpers.DefaultHandler; -public class LogParser extends DefaultHandler implements ErrorHandler, Constants { +/** + * A SAX parser for HotSpot compilation logs. The bulk of the parsing and event + * maintenance work is done in the {@link #startElement(String,String,String,Attributes)} + * and {@link #endElement(String,String,String)} methods. + */ +public class LogParser extends DefaultHandler implements ErrorHandler { + + static final Pattern spacePattern = Pattern.compile(" "); - static final HashMap<String, String> typeMap; + /** + * Map internal array type descriptors to Java names. + */ + static final HashMap<String, String> type2printableMap; + + /** + * Map Java primitive type names to internal type descriptors. + */ + static final HashMap<String, String> type2vmtypeMap; + static { - typeMap = new HashMap<String, String>(); - typeMap.put("[I", "int[]"); - typeMap.put("[C", "char[]"); - typeMap.put("[Z", "boolean[]"); - typeMap.put("[L", "Object[]"); - typeMap.put("[B", "byte[]"); + type2printableMap = new HashMap<>(); + type2printableMap.put("[I", "int[]"); + type2printableMap.put("[C", "char[]"); + type2printableMap.put("[Z", "boolean[]"); + type2printableMap.put("[L", "Object[]"); + type2printableMap.put("[B", "byte[]"); + + type2vmtypeMap = new HashMap<>(); + type2vmtypeMap.put("void", "V"); + type2vmtypeMap.put("boolean", "Z"); + type2vmtypeMap.put("byte", "B"); + type2vmtypeMap.put("char", "C"); + type2vmtypeMap.put("short", "S"); + type2vmtypeMap.put("int", "I"); + type2vmtypeMap.put("long", "J"); + type2vmtypeMap.put("float", "F"); + type2vmtypeMap.put("double", "D"); } + static String[] bytecodes = new String[] { + "nop", + "aconst_null", + "iconst_m1", + "iconst_0", + "iconst_1", + "iconst_2", + "iconst_3", + "iconst_4", + "iconst_5", + "lconst_0", + "lconst_1", + "fconst_0", + "fconst_1", + "fconst_2", + "dconst_0", + "dconst_1", + "bipush", + "sipush", + "ldc", + "ldc_w", + "ldc2_w", + "iload", + "lload", + "fload", + "dload", + "aload", + "iload_0", + "iload_1", + "iload_2", + "iload_3", + "lload_0", + "lload_1", + "lload_2", + "lload_3", + "fload_0", + "fload_1", + "fload_2", + "fload_3", + "dload_0", + "dload_1", + "dload_2", + "dload_3", + "aload_0", + "aload_1", + "aload_2", + "aload_3", + "iaload", + "laload", + "faload", + "daload", + "aaload", + "baload", + "caload", + "saload", + "istore", + "lstore", + "fstore", + "dstore", + "astore", + "istore_0", + "istore_1", + "istore_2", + "istore_3", + "lstore_0", + "lstore_1", + "lstore_2", + "lstore_3", + "fstore_0", + "fstore_1", + "fstore_2", + "fstore_3", + "dstore_0", + "dstore_1", + "dstore_2", + "dstore_3", + "astore_0", + "astore_1", + "astore_2", + "astore_3", + "iastore", + "lastore", + "fastore", + "dastore", + "aastore", + "bastore", + "castore", + "sastore", + "pop", + "pop2", + "dup", + "dup_x1", + "dup_x2", + "dup2", + "dup2_x1", + "dup2_x2", + "swap", + "iadd", + "ladd", + "fadd", + "dadd", + "isub", + "lsub", + "fsub", + "dsub", + "imul", + "lmul", + "fmul", + "dmul", + "idiv", + "ldiv", + "fdiv", + "ddiv", + "irem", + "lrem", + "frem", + "drem", + "ineg", + "lneg", + "fneg", + "dneg", + "ishl", + "lshl", + "ishr", + "lshr", + "iushr", + "lushr", + "iand", + "land", + "ior", + "lor", + "ixor", + "lxor", + "iinc", + "i2l", + "i2f", + "i2d", + "l2i", + "l2f", + "l2d", + "f2i", + "f2l", + "f2d", + "d2i", + "d2l", + "d2f", + "i2b", + "i2c", + "i2s", + "lcmp", + "fcmpl", + "fcmpg", + "dcmpl", + "dcmpg", + "ifeq", + "ifne", + "iflt", + "ifge", + "ifgt", + "ifle", + "if_icmpeq", + "if_icmpne", + "if_icmplt", + "if_icmpge", + "if_icmpgt", + "if_icmple", + "if_acmpeq", + "if_acmpne", + "goto", + "jsr", + "ret", + "tableswitch", + "lookupswitch", + "ireturn", + "lreturn", + "freturn", + "dreturn", + "areturn", + "return", + "getstatic", + "putstatic", + "getfield", + "putfield", + "invokevirtual", + "invokespecial", + "invokestatic", + "invokeinterface", + "invokedynamic", + "new", + "newarray", + "anewarray", + "arraylength", + "athrow", + "checkcast", + "instanceof", + "monitorenter", + "monitorexit", + "wide", + "multianewarray", + "ifnull", + "ifnonnull", + "goto_w", + "jsr_w", + "breakpoint" + }; + + /** + * Sort log events by start time. + */ static Comparator<LogEvent> sortByStart = new Comparator<LogEvent>() { public int compare(LogEvent a, LogEvent b) { @@ -80,25 +319,29 @@ return 7; } }; + + /** + * Sort log events first by the name of the compiled method, then by start + * time. In case one of the events has no associated compilation (or the + * associated compilation has no method name), the event with a compilation + * and/or name is considered the larger one. + */ static Comparator<LogEvent> sortByNameAndStart = new Comparator<LogEvent>() { public int compare(LogEvent a, LogEvent b) { Compilation c1 = a.getCompilation(); Compilation c2 = b.getCompilation(); - if (c1 != null && c2 != null) { + if (c1 != null && c1.getMethod() != null && c2 != null && c2.getMethod() != null) { int result = c1.getMethod().toString().compareTo(c2.getMethod().toString()); if (result != 0) { return result; } - } - double difference = (a.getStart() - b.getStart()); - if (difference < 0) { + } else if ((c1 == null || c1.getMethod() == null) && c2 != null && c2.getMethod() != null) { return -1; - } - if (difference > 0) { + } else if ((c2 == null || c2.getMethod() == null) && c1 != null && c1.getMethod() != null) { return 1; } - return 0; + return Double.compare(a.getStart(), b.getStart()); } public boolean equals(Object other) { @@ -110,6 +353,10 @@ return 7; } }; + + /** + * Sort log events by duration. + */ static Comparator<LogEvent> sortByElapsed = new Comparator<LogEvent>() { public int compare(LogEvent a, LogEvent b) { @@ -134,6 +381,10 @@ } }; + /** + * Shrink-wrapped representation of a JVMState (tailored to meet this + * tool's needs). It only records a method and bytecode instruction index. + */ class Jvms { Jvms(Method method, int bci) { this.method = method; @@ -146,12 +397,33 @@ } } + /** + * Representation of a lock elimination. Locks, corresponding to + * synchronized blocks and method calls, may be eliminated if the object in + * question is guaranteed to be used thread-locally. + */ class LockElimination extends BasicLogEvent { - ArrayList<Jvms> jvms = new ArrayList<Jvms>(1); + /** + * Track all locations from which this lock was eliminated. + */ + ArrayList<Jvms> jvms = new ArrayList<>(1); + + /** + * The kind of lock (coarsened, nested, non-escaping, unknown). + */ final String kind; + + /** + * The lock class (unlock, lock, unknown). + */ final String classId; + + /** + * The precise type of lock. + */ final String tagName; + LockElimination(String tagName, double start, String id, String kind, String classId) { super(start, id); this.kind = kind; @@ -160,8 +432,11 @@ } @Override - public void print(PrintStream stream) { - stream.printf("%s %s %s %s %.3f ", getId(), tagName, kind, classId, getStart()); + public void print(PrintStream stream, boolean printID) { + if (printID) { + stream.printf("%s ", getId()); + } + stream.printf("%s %s %s %.3f ", tagName, kind, classId, getStart()); stream.print(jvms.toString()); stream.print("\n"); } @@ -172,25 +447,154 @@ } - private ArrayList<LogEvent> events = new ArrayList<LogEvent>(); + /** + * A list of log events. This is populated with the events found in the + * compilation log file during parsing. + */ + private ArrayList<LogEvent> events = new ArrayList<>(); + + /** + * Map compilation log IDs to type names. + */ + private HashMap<String, String> types = new HashMap<>(); - private HashMap<String, String> types = new HashMap<String, String>(); - private HashMap<String, Method> methods = new HashMap<String, Method>(); - private LinkedHashMap<String, NMethod> nmethods = new LinkedHashMap<String, NMethod>(); - private HashMap<String, Compilation> compiles = new HashMap<String, Compilation>(); + /** + * Map compilation log IDs to methods. + */ + private HashMap<String, Method> methods = new HashMap<>(); + + /** + * Map compilation IDs ({@see #makeId()}) to newly created nmethods. + */ + private LinkedHashMap<String, NMethod> nmethods = new LinkedHashMap<>(); + + /** + * Map compilation task IDs {@see #makeId()}) to {@link Compilation} + * objects. + */ + private HashMap<String, Compilation> compiles = new HashMap<>(); + + /** + * Track compilation failure reasons. + */ private String failureReason; - private int bci; - private Stack<CallSite> scopes = new Stack<CallSite>(); + + /** + * The current bytecode instruction index. + */ + private int current_bci; + + /** + * The current bytecode instruction. + */ + private int current_bytecode; + + /** + * A sequence of {@link CallSite}s representing a call stack. A scope + * typically holds several {@link CallSite}s that represent calls + * originating from that scope. + * + * New scopes are typically pushed when parse log events are encountered + * ({@see #startElement()}) and popped when parsing of a given Java method + * is done ({@see #endElement()}). Parsing events can be nested. Several + * other events add information to scopes ({@see #startElement()}). + */ + private Deque<CallSite> scopes = new ArrayDeque<>(); + + /** + * The current compilation. + */ private Compilation compile; + + /** + * The {@linkplain CallSite compilation scope} currently in focus. + */ private CallSite site; + + /** + * The {@linkplain CallSite method handle call site} currently under + * observation. + */ private CallSite methodHandleSite; - private Stack<Phase> phaseStack = new Stack<Phase>(); + + /** + * Keep track of potentially nested compiler {@linkplain Phase phases}. + */ + private Deque<Phase> phaseStack = new ArrayDeque<>(); + + /** + * The {@linkplain LockElimination lock elimination event} currently being + * processed. + */ private LockElimination currentLockElimination; + + /** + * The {@linkplain UncommonTrapEvent uncommon trap event} currently being + * processed. + */ private UncommonTrapEvent currentTrap; - private Stack<CallSite> lateInlineScope; + + /** + * During the processing of a late inline event, this stack holds the + * {@link CallSite}s that represent the inlining event's call stack. + */ + private Deque<CallSite> lateInlineScope; + + /** + * Denote whether a late inlining event is currently being processed. + */ private boolean lateInlining; + /** + * A document locator to provide better error messages: this allows the + * tool to display in which line of the log file the problem occurred. + */ + private Locator locator; + /** + * Callback for the SAX framework to set the document locator. + */ + @Override + public void setDocumentLocator(Locator locator) { + this.locator = locator; + } + + /** + * Report an internal error explicitly raised, i.e., not derived from an + * exception. + * + * @param msg The error message to report. + */ + private void reportInternalError(String msg) { + reportInternalError(msg, null); + } + + /** + * Report an internal error derived from an exception. + * + * @param msg The beginning of the error message to report. The message + * from the exception will be appended to this. + * @param e The exception that led to the internal error. + */ + private void reportInternalError(String msg, Exception e) { + if (locator != null) { + msg += " at " + locator.getLineNumber() + ":" + locator.getColumnNumber(); + if (e != null) { + msg += " - " + e.getMessage(); + } + } + if (e != null) { + throw new Error(msg, e); + } else { + throw new Error(msg); + } + } + + /** + * Parse a long hexadecimal address into a {@code long} value. As Java only + * supports positive {@code long} values, extra error handling and parsing + * logic is provided. + */ long parseLong(String l) { try { return Long.decode(l).longValue(); @@ -207,16 +611,29 @@ System.out.println(v1); System.out.println(v2); System.out.println(Long.toHexString(v1 + v2)); - throw new InternalError("bad conversion"); + reportInternalError("bad conversion"); } return v1 + v2; } } + /** + * Entry point for log file parsing with a file name. + * + * @param file The name of the log file to parse. + * @param cleanup Whether to perform bad XML cleanup during parsing (this + * is relevant for some log files generated by the 1.5 JVM). + * @return a list of {@link LogEvent} instances describing the events found + * in the log file. + */ public static ArrayList<LogEvent> parse(String file, boolean cleanup) throws Exception { return parse(new FileReader(file), cleanup); } + /** + * Entry point for log file parsing with a file reader. + * {@see #parse(String,boolean)} + */ public static ArrayList<LogEvent> parse(Reader reader, boolean cleanup) throws Exception { // Create the XML input factory SAXParserFactory factory = SAXParserFactory.newInstance(); @@ -238,31 +655,58 @@ // Carry on with what we've got... } - // Associate compilations with their NMethods - for (NMethod nm : log.nmethods.values()) { - Compilation c = log.compiles.get(nm.getId()); - nm.setCompilation(c); - // Native wrappers for methods don't have a compilation - if (c != null) { - c.setNMethod(nm); + // Associate compilations with their NMethods and other kinds of events + for (LogEvent e : log.events) { + if (e instanceof BasicLogEvent) { + BasicLogEvent ble = (BasicLogEvent) e; + Compilation c = log.compiles.get(ble.getId()); + if (c == null) { + if (!(ble instanceof NMethod)) { + throw new InternalError("only nmethods should have a null compilation, here's a " + ble.getClass()); + } + continue; + } + ble.setCompilation(c); + if (ble instanceof NMethod) { + c.setNMethod((NMethod) ble); + } } } - // Initially we want the LogEvent log sorted by timestamp - Collections.sort(log.events, sortByStart); - return log.events; } + /** + * Retrieve a given attribute's value from a collection of XML tag + * attributes. Report an error if the requested attribute is not found. + * + * @param attr A collection of XML tag attributes. + * @param name The name of the attribute the value of which is to be found. + * @return The value of the requested attribute, or {@code null} if it was + * not found. + */ String search(Attributes attr, String name) { String result = attr.getValue(name); if (result != null) { return result; } else { - throw new InternalError("can't find " + name); + reportInternalError("can't find " + name); + return null; } } + /** + * Retrieve a given attribute's value from a collection of XML tag + * attributes. Return a default value if the requested attribute is not + * found. + * + * @param attr A collection of XML tag attributes. + * @param name The name of the attribute the value of which is to be found. + * @param defaultValue The default value to return if the attribute is not + * found. + * @return The value of the requested attribute, or the default value if it + * was not found. + */ String search(Attributes attr, String name, String defaultValue) { String result = attr.getValue(name); if (result != null) { @@ -270,33 +714,70 @@ } return defaultValue; } - int indent = 0; + /** + * Map a type ID from the compilation log to an actual type name. In case + * the type represents an internal array type descriptor, return a + * Java-level name. If the type ID cannot be mapped to a name, raise an + * error. + */ String type(String id) { String result = types.get(id); if (result == null) { - throw new InternalError(id); + reportInternalError(id); } - String remapped = typeMap.get(result); + String remapped = type2printableMap.get(result); if (remapped != null) { return remapped; } return result; } + /** + * Register a mapping from log file type ID to type name. + */ void type(String id, String name) { assert type(id) == null; types.put(id, name); } + /** + * Map a log file type ID to an internal type declarator. + */ + String sigtype(String id) { + String result = types.get(id); + String remapped = type2vmtypeMap.get(result); + if (remapped != null) { + return remapped; + } + if (result == null) { + reportInternalError(id); + } + if (result.charAt(0) == '[') { + return result; + } + return "L" + result + ";"; + } + + /** + * Retrieve a method based on the log file ID it was registered under. + * Raise an error if the ID does not map to a method. + */ Method method(String id) { Method result = methods.get(id); if (result == null) { - throw new InternalError(id); + reportInternalError(id); } return result; } + /** + * From a compilation ID and kind, assemble a compilation ID for inclusion + * in the output. + * + * @param atts A collection of XML attributes from which the required + * attributes are retrieved. + */ public String makeId(Attributes atts) { String id = atts.getValue("compile_id"); String kind = atts.getValue("kind"); @@ -306,11 +787,60 @@ return id; } + /** + * Process the start of a compilation log XML element.<ul> + * <li><b>phase:</b> record the beginning of a compilation phase, pushing + * it on the {@linkplain #phaseStack phase stack} and collecting + * information about the compiler graph.</li> + * <li><b>phase_done:</b> record the end of a compilation phase, popping it + * off the {@linkplain #phaseStack phase stack} and collecting information + * about the compiler graph (number of nodes and live nodes).</li> + * <li><b>task:</b> register the start of a new compilation.</li> + * <li><b>type:</b> register a type.</li> + * <li><b>bc:</b> note the current bytecode index and instruction name, + * updating {@link #current_bci} and {@link #current_bytecode}.</li> + * <li><b>klass:</b> register a type (class).</li> + * <li><b>method:</b> register a Java method.</li> + * <li><b>call:</b> process a call, populating {@link #site} with the + * appropriate data.</li> + * <li><b>regalloc:</b> record the register allocator's trip count in the + * {@linkplain #compile current compilation}.</li> + * <li><b>inline_fail:</b> record the reason for a failed inline + * operation.</li> + * <li><b>inline_success:</b> record a successful inlining operation, + * noting the success reason in the {@linkplain #site call site}.</li> + * <li><b>failure:</b> note a compilation failure, storing the reason + * description in {@link #failureReason}.</li> + * <li><b>task_done:</b> register the end of a compilation, recording time + * stamp and success information.</li> + * <li><b>make_not_entrant:</b> deal with making a native method + * non-callable (e.g., during an OSR compilation, if there are still + * activations) or a zombie (when the method can be deleted).</li> + * <li><b>uncommon_trap:</b> process an uncommon trap, setting the + * {@link #currentTrap} field.</li> + * <li><b>eliminate_lock:</b> record the start of a lock elimination, + * setting the {@link #currentLockElimination} event.</li> + * <li><b>late_inline:</b> start processing a late inline decision: + * initialize the {@linkplain #lateInlineScope inline scope stack}, create + * an {@linkplain #site initial scope} with a bogus bytecode index and the + * right inline ID, and push the scope with the inline ID attached. Note + * that most of late inlining processing happens in + * {@link #endElement()}.</li> + * <li><b>jvms:</b> record a {@linkplain Jvms JVMState}. Depending on the + * context in which this event is encountered, this can mean adding + * information to the currently being processed trap, lock elimination, or + * inlining operation.</li> + * <li><b>inline_id:</b> set the inline ID in the + * {@linkplain #site current call site}.</li> + * <li><b>nmethod:</b> record the creation of a new {@link NMethod} and + * store it in the {@link #nmethods} map.</li> + * <li><b>parse:</b> begin parsing a Java method's bytecode and + * transforming it into an initial compiler IR graph.</li> + * <li><b>parse_done:</b> finish parsing a Java method's bytecode.</li> + * </ul> + */ @Override - public void startElement(String uri, - String localName, - String qname, - Attributes atts) { + public void startElement(String uri, String localName, String qname, Attributes atts) { if (qname.equals("phase")) { Phase p = new Phase(search(atts, "name"), Double.parseDouble(search(atts, "stamp")), @@ -322,45 +852,62 @@ String phaseName = search(atts, "name", null); if (phaseName != null && !p.getId().equals(phaseName)) { System.out.println("phase: " + p.getId()); - throw new InternalError("phase name mismatch"); + reportInternalError("phase name mismatch"); } p.setEnd(Double.parseDouble(search(atts, "stamp"))); p.setEndNodes(Integer.parseInt(search(atts, "nodes", "0"))); p.setEndLiveNodes(Integer.parseInt(search(atts, "live", "0"))); compile.getPhases().add(p); } else if (qname.equals("task")) { + String id = makeId(atts); + + // Create the new Compilation instance and populate it with readily + // available data. compile = new Compilation(Integer.parseInt(search(atts, "compile_id", "-1"))); compile.setStart(Double.parseDouble(search(atts, "stamp"))); compile.setICount(search(atts, "count", "0")); compile.setBCount(search(atts, "backedge_count", "0")); - - String method = atts.getValue("method"); - int space = method.indexOf(' '); - method = method.substring(0, space) + "::" + - method.substring(space + 1, method.indexOf(' ', space + 1) + 1); + compile.setBCI(Integer.parseInt(search(atts, "osr_bci", "-1"))); String compiler = atts.getValue("compiler"); if (compiler == null) { compiler = ""; } + compile.setCompiler(compiler); + + // Extract the name of the compiled method. + String[] parts = spacePattern.split(atts.getValue("method")); + String methodName = parts[0] + "::" + parts[1]; + + // Continue collecting compilation meta-data. String kind = atts.getValue("compile_kind"); if (kind == null) { kind = "normal"; } if (kind.equals("osr")) { compile.setOsr(true); - compile.setOsr_bci(Integer.parseInt(search(atts, "osr_bci"))); } else if (kind.equals("c2i")) { - compile.setSpecial("--- adapter " + method); + compile.setSpecial("--- adapter " + methodName); } else { - compile.setSpecial(compile.getId() + " " + method + " (0 bytes)"); + compile.setSpecial(compile.getId() + " " + methodName + " (0 bytes)"); } + + // Build a dummy method to stuff in the Compilation at the + // beginning. + Method m = new Method(); + m.setHolder(parts[0]); + m.setName(parts[1]); + m.setSignature(parts[2]); + m.setFlags("0"); + m.setBytes("unknown"); + compile.setMethod(m); events.add(compile); - compiles.put(makeId(atts), compile); + compiles.put(id, compile); site = compile.getCall(); } else if (qname.equals("type")) { type(search(atts, "id"), search(atts, "name")); } else if (qname.equals("bc")) { - bci = Integer.parseInt(search(atts, "bci")); + current_bci = Integer.parseInt(search(atts, "bci")); + current_bytecode = Integer.parseInt(search(atts, "code")); } else if (qname.equals("klass")) { type(search(atts, "id"), search(atts, "name")); } else if (qname.equals("method")) { @@ -369,7 +916,19 @@ m.setHolder(type(search(atts, "holder"))); m.setName(search(atts, "name")); m.setReturnType(type(search(atts, "return"))); - m.setArguments(search(atts, "arguments", "void")); + String arguments = atts.getValue("arguments");; + if (arguments == null) { + m.setSignature("()" + sigtype(atts.getValue("return"))); + } else { + String[] args = spacePattern.split(arguments); + StringBuilder sb = new StringBuilder("("); + for (int i = 0; i < args.length; i++) { + sb.append(sigtype(args[i])); + } + sb.append(")"); + sb.append(sigtype(atts.getValue("return"))); + m.setSignature(sb.toString()); + } if (search(atts, "unloaded", "0").equals("0")) { m.setBytes(search(atts, "bytes")); @@ -385,15 +944,17 @@ if (lateInlining && scopes.size() == 0) { // re-attempting already seen call site (late inlining for MH invokes) if (m != site.getMethod()) { - if (bci != site.getBci()) { - System.out.println(m + " bci: " + bci); - System.out.println(site.getMethod() + " bci: " + site.getBci()); - throw new InternalError("bci mismatch after late inlining"); + if (current_bci != site.getBci()) { + System.err.println(m + " bci: " + current_bci); + System.err.println(site.getMethod() + " bci: " + site.getBci()); + reportInternalError("bci mismatch after late inlining"); } site.setMethod(m); } } else { - site = new CallSite(bci, m); + // We're dealing with a new call site; the called method is + // likely to be parsed next. + site = new CallSite(current_bci, m); } site.setCount(Integer.parseInt(search(atts, "count", "0"))); String receiver = atts.getValue("receiver"); @@ -403,7 +964,8 @@ } int methodHandle = Integer.parseInt(search(atts, "method_handle_intrinsic", "0")); if (lateInlining && scopes.size() == 0) { - // The call was added before this round of late inlining + // The call was already added before this round of late + // inlining. Ignore. } else if (methodHandle == 0) { scopes.peek().add(site); } else { @@ -421,18 +983,16 @@ methodHandleSite = null; } if (lateInlining && scopes.size() == 0) { - site.setReason(search(atts, "reason")); + site.setReason("fail: " + search(atts, "reason")); lateInlining = false; } else { - scopes.peek().last().setReason(search(atts, "reason")); + scopes.peek().last().setReason("fail: " + search(atts, "reason")); } } else if (qname.equals("inline_success")) { if (methodHandleSite != null) { - throw new InternalError("method handle site should have been replaced"); + reportInternalError("method handle site should have been replaced"); } - if (lateInlining && scopes.size() == 0) { - site.setReason(null); - } + site.setReason("succeed: " + search(atts, "reason")); } else if (qname.equals("failure")) { failureReason = search(atts, "reason"); } else if (qname.equals("task_done")) { @@ -444,7 +1004,7 @@ } else if (qname.equals("make_not_entrant")) { String id = makeId(atts); NMethod nm = nmethods.get(id); - if (nm == null) throw new InternalError(); + if (nm == null) reportInternalError("nm == null"); LogEvent e = new MakeNotEntrantEvent(Double.parseDouble(search(atts, "stamp")), id, atts.getValue("zombie") != null, nm); events.add(e); @@ -459,8 +1019,22 @@ Integer.parseInt(search(atts, "count", "0"))); events.add(currentTrap); } else { - // uncommon trap inserted during parsing. - // ignore for now + if (atts.getValue("method") != null) { + // These are messages from ciTypeFlow that don't + // actually correspond to generated code. + return; + } + try { + if (scopes.size() == 0) { + reportInternalError("scope underflow"); + } + scopes.peek().add(new UncommonTrap(Integer.parseInt(search(atts, "bci")), + search(atts, "reason"), + search(atts, "action"), + bytecodes[current_bytecode])); + } catch (Error e) { + e.printStackTrace(); + } } } else if (qname.startsWith("eliminate_lock")) { String id = atts.getValue("compile_id"); @@ -474,24 +1048,27 @@ } else if (qname.equals("late_inline")) { long inlineId = 0; try { - Long.parseLong(search(atts, "inline_id")); + inlineId = Long.parseLong(search(atts, "inline_id")); } catch (InternalError ex) { // Log files from older hotspots may lack inline_id, // and zero is an acceptable substitute that allows processing to continue. } - lateInlineScope = new Stack<CallSite>(); - site = new CallSite(-999, method(search(atts, "method"))); + lateInlineScope = new ArrayDeque<>(); + Method m = method(search(atts, "method")); + site = new CallSite(-999, m); site.setInlineId(inlineId); lateInlineScope.push(site); } else if (qname.equals("jvms")) { // <jvms bci='4' method='java/io/DataInputStream readChar ()C' bytes='40' count='5815' iicount='20815'/> if (currentTrap != null) { - currentTrap.addJVMS(atts.getValue("method"), Integer.parseInt(atts.getValue("bci"))); + String[] parts = spacePattern.split(atts.getValue("method")); + currentTrap.addMethodAndBCI(parts[0].replace('/', '.') + '.' + parts[1] + parts[2], Integer.parseInt(atts.getValue("bci"))); } else if (currentLockElimination != null) { currentLockElimination.addJVMS(method(atts.getValue("method")), Integer.parseInt(atts.getValue("bci"))); } else if (lateInlineScope != null) { - bci = Integer.parseInt(search(atts, "bci")); - site = new CallSite(bci, method(search(atts, "method"))); + current_bci = Integer.parseInt(search(atts, "bci")); + Method m = method(search(atts, "method")); + site = new CallSite(current_bci, m); lateInlineScope.push(site); } else { // Ignore <eliminate_allocation type='667'>, @@ -499,7 +1076,7 @@ } } else if (qname.equals("inline_id")) { if (methodHandleSite != null) { - throw new InternalError("method handle site should have been replaced"); + reportInternalError("method handle site should have been replaced"); } long id = Long.parseLong(search(atts, "id")); site.setInlineId(id); @@ -513,33 +1090,53 @@ events.add(nm); } else if (qname.equals("parse")) { if (failureReason != null && scopes.size() == 0 && !lateInlining) { + // A compilation just failed, and we're back at a top + // compilation scope. failureReason = null; compile.reset(); site = compile.getCall(); } + // Error checking. if (methodHandleSite != null) { - throw new InternalError("method handle site should have been replaced"); + reportInternalError("method handle site should have been replaced"); } - Method m = method(search(atts, "method")); + Method m = method(search(atts, "method")); // this is the method being parsed if (lateInlining && scopes.size() == 0) { if (site.getMethod() != m) { - System.out.println(site.getMethod()); - System.out.println(m); - throw new InternalError("Unexpected method mismatch during late inlining"); + reportInternalError("Unexpected method mismatch during late inlining (method at call site: " + + site.getMethod() + ", method being parsed: " + m + ")"); } } + if (scopes.size() == 0 && !lateInlining) { + // The method being parsed is actually the method being + // compiled; i.e., we're dealing with a compilation top scope, + // which we must consequently push to the scopes stack. compile.setMethod(m); scopes.push(site); } else { + // The method being parsed is *not* the current compilation's + // top scope; i.e., we're dealing with an actual call site + // in the top scope or somewhere further down a call stack. if (site.getMethod() == m) { + // We're dealing with monomorphic inlining that didn't have + // to be narrowed down, because the receiver was known + // beforehand. scopes.push(site); - } else if (scopes.peek().getCalls().size() > 2 && m == scopes.peek().last(-2).getMethod()) { - scopes.push(scopes.peek().last(-2)); + } else if (scopes.peek().getCalls().size() > 2 && m == scopes.peek().lastButOne().getMethod()) { + // We're dealing with an at least bimorphic call site, and + // the compiler has now decided to parse the last-but-one + // method. The last one may already have been parsed for + // inlining. + scopes.push(scopes.peek().lastButOne()); } else { - // C1 prints multiple method tags during inlining when it narrows method being inlinied. - // Example: + // The method has been narrowed down to the one we're now + // going to parse, which is inlined here. It's monomorphic + // inlining, but was not immediately clear as such. + // + // C1 prints multiple method tags during inlining when it + // narrows the method being inlined. Example: // ... // <method id="813" holder="694" name="toString" return="695" flags="1" bytes="36" iicount="1"/> // <call method="813" instr="invokevirtual"/> @@ -552,100 +1149,132 @@ } } } else if (qname.equals("parse_done")) { - CallSite call = scopes.pop(); + // Attach collected information about IR nodes to the current + // parsing scope before it's popped off the stack in endElement() + // (see where the parse tag is handled). + CallSite call = scopes.peek(); call.setEndNodes(Integer.parseInt(search(atts, "nodes", "0"))); call.setEndLiveNodes(Integer.parseInt(search(atts, "live", "0"))); call.setTimeStamp(Double.parseDouble(search(atts, "stamp"))); - scopes.push(call); } } + /** + * Process the end of a compilation log XML element.<ul> + * <li><b>parse:</b> finish transforming a Java method's bytecode + * instructions to an initial compiler IR graph.</li> + * <li><b>uncommon_trap:</b> record the end of processing an uncommon trap, + * resetting {@link #currentTrap}.</li> + * <li><b>eliminate_lock:</b> record the end of a lock elimination, + * resetting {@link #currentLockElimination}.</li> + * <li><b>late_inline:</b> the closing tag for late_inline does not denote + * the end of a late inlining operation, but the end of the descriptive log + * data given at its beginning. That is, we're now in the position to + * assemble details about the inlining chain (bytecode instruction index in + * caller, called method). The {@link #lateInlining} flag is set to + * {@code true} here. (It will be reset when parsing the inlined methods is + * done; this happens for the successful case in this method as well, when + * {@code parse} elements are processed; and for inlining failures, in + * {@link #startElement()}, when {@code inline_fail} elements are + * processed.)</li> + * <li><b>task:</b> perform cleanup at the end of a compilation. Note that + * the explicit {@code task_done} event is handled in + * {@link #startElement()}.</li> + * </ul> + */ @Override - public void endElement(String uri, - String localName, - String qname) { - if (qname.equals("parse")) { - indent -= 2; - scopes.pop(); - if (scopes.size() == 0) { - lateInlining = false; - } - } else if (qname.equals("uncommon_trap")) { - currentTrap = null; - } else if (qname.startsWith("eliminate_lock")) { - currentLockElimination = null; - } else if (qname.equals("late_inline")) { - // Populate late inlining info. - if (scopes.size() != 0) { - throw new InternalError("scopes should be empty for late inline"); - } - // late inline scopes are specified in reverse order: - // compiled method should be on top of stack. - CallSite caller = lateInlineScope.pop(); - Method m = compile.getMethod(); - if (m != caller.getMethod()) { - System.err.println(m); - System.err.println(caller.getMethod() + " bci: " + bci); - throw new InternalError("call site and late_inline info don't match"); - } + public void endElement(String uri, String localName, String qname) { + try { + if (qname.equals("parse")) { + // Finish dealing with the current call scope. If no more are + // left, no late inlining can be going on. + scopes.pop(); + if (scopes.size() == 0) { + lateInlining = false; + } + } else if (qname.equals("uncommon_trap")) { + currentTrap = null; + } else if (qname.startsWith("eliminate_lock")) { + currentLockElimination = null; + } else if (qname.equals("late_inline")) { + // Populate late inlining info. + if (scopes.size() != 0) { + reportInternalError("scopes should be empty for late inline"); + } + // late inline scopes are specified in reverse order: + // compiled method should be on top of stack. + CallSite caller = lateInlineScope.pop(); + Method m = compile.getMethod(); + if (!m.equals(caller.getMethod())) { + reportInternalError(String.format("call site and late_inline info don't match:\n method %s\n caller method %s, bci %d", m, caller.getMethod(), current_bci)); + } - // late_inline contains caller+bci info, convert it - // to bci+callee info used by LogCompilation. - CallSite lateInlineSite = compile.getLateInlineCall(); - ArrayDeque<CallSite> thisCallScopes = new ArrayDeque<CallSite>(); - do { - bci = caller.getBci(); - // Next inlined call. - caller = lateInlineScope.pop(); - CallSite callee = new CallSite(bci, caller.getMethod()); - callee.setInlineId(caller.getInlineId()); - thisCallScopes.addLast(callee); - lateInlineSite.add(callee); - lateInlineSite = callee; - } while (!lateInlineScope.empty()); + // Walk down the inlining chain and assemble bci+callee info. + // This needs to be converted from caller+bci info contained in + // the late_inline data. + CallSite lateInlineSite = compile.getLateInlineCall(); + ArrayDeque<CallSite> thisCallScopes = new ArrayDeque<>(); + do { + current_bci = caller.getBci(); + // Next inlined call. + caller = lateInlineScope.pop(); + CallSite callee = new CallSite(current_bci, caller.getMethod()); + callee.setInlineId(caller.getInlineId()); + thisCallScopes.addLast(callee); + lateInlineSite.add(callee); + lateInlineSite = callee; + } while (!lateInlineScope.isEmpty()); - site = compile.getCall().findCallSite(thisCallScopes); - if (site == null) { - System.out.println("call scopes:"); - for (CallSite c : thisCallScopes) { - System.out.println(c.getMethod() + " " + c.getBci() + " " + c.getInlineId()); + site = compile.getCall().findCallSite(thisCallScopes); + if (site == null) { + // Call site could not be found - report the problem in detail. + System.err.println("call scopes:"); + for (CallSite c : thisCallScopes) { + System.err.println(c.getMethod() + " " + c.getBci() + " " + c.getInlineId()); + } + CallSite c = thisCallScopes.getLast(); + if (c.getInlineId() != 0) { + System.err.println("Looking for call site in entire tree:"); + ArrayDeque<CallSite> stack = compile.getCall().findCallSite2(c); + for (CallSite c2 : stack) { + System.err.println(c2.getMethod() + " " + c2.getBci() + " " + c2.getInlineId()); + } + } + System.err.println(caller.getMethod() + " bci: " + current_bci); + reportInternalError("couldn't find call site"); } - CallSite c = thisCallScopes.getLast(); - if (c.getInlineId() != 0) { - System.out.println("Looking for call site in entire tree:"); - ArrayDeque<CallSite> stack = compile.getCall().findCallSite2(c); - for (CallSite c2 : stack) { - System.out.println(c2.getMethod() + " " + c2.getBci() + " " + c2.getInlineId()); + lateInlining = true; + + if (caller.getBci() != -999) { + System.out.println(caller.getMethod()); + reportInternalError("broken late_inline info"); + } + if (site.getMethod() != caller.getMethod()) { + if (site.getInlineId() == caller.getInlineId()) { + site.setMethod(caller.getMethod()); + } else { + System.out.println(site.getMethod()); + System.out.println(caller.getMethod()); + reportInternalError("call site and late_inline info don't match"); } } - System.out.println(caller.getMethod() + " bci: " + bci); - throw new InternalError("couldn't find call site"); - } - lateInlining = true; - - if (caller.getBci() != -999) { - System.out.println(caller.getMethod()); - throw new InternalError("broken late_inline info"); + // late_inline is followed by parse with scopes.size() == 0, + // 'site' will be pushed to scopes. + lateInlineScope = null; + } else if (qname.equals("task")) { + types.clear(); + methods.clear(); + site = null; } - if (site.getMethod() != caller.getMethod()) { - if (site.getInlineId() == caller.getInlineId()) { - site.setMethod(caller.getMethod()); - } else { - System.out.println(site.getMethod()); - System.out.println(caller.getMethod()); - throw new InternalError("call site and late_inline info don't match"); - } - } - // late_inline is followed by parse with scopes.size() == 0, - // 'site' will be pushed to scopes. - lateInlineScope = null; - } else if (qname.equals("task")) { - types.clear(); - methods.clear(); - site = null; + } catch (Exception e) { + reportInternalError("exception while processing end element", e); } } + // + // Handlers for problems that occur in XML parsing itself. + // + @Override public void warning(org.xml.sax.SAXParseException e) { System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber());
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/MakeNotEntrantEvent.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/MakeNotEntrantEvent.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -21,14 +21,25 @@ * questions. * */ - package com.sun.hotspot.tools.compiler; import java.io.PrintStream; +/** + * In a compilation log, represent the event of making a given compiled method + * not-entrant, e.g., during an OSR compilation. + */ class MakeNotEntrantEvent extends BasicLogEvent { + + /** + * Denote whether the method is marked as a zombie, i.e., no further + * activations exist. + */ private final boolean zombie; + /** + * The method in question. + */ private NMethod nmethod; MakeNotEntrantEvent(double s, String i, boolean z, NMethod nm) { @@ -41,7 +52,7 @@ return nmethod; } - public void print(PrintStream stream) { + public void print(PrintStream stream, boolean printID) { if (isZombie()) { stream.printf("%s make_zombie\n", getId()); } else {
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Method.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Method.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -26,16 +26,58 @@ import java.util.Arrays; -public class Method implements Constants { +import static com.sun.hotspot.tools.compiler.Constants.*; + +/** + * Representation of a Java method in a compilation log. + */ +public class Method { + /** + * The name of the class holding the method. + */ private String holder; + + /** + * The method's name. + */ private String name; + + /** + * The return type of the method, as a fully qualified (source-level) class + * or primitive type name. + */ private String returnType; - private String arguments; + + /** + * The method's signature, in internal form. + */ + private String signature; + + /** + * The length of the method's byte code. + */ private String bytes; + + /** + * The number of times this method was invoked in the interpreter. + */ private String iicount; + + /** + * The method's flags, in the form of a {@code String} representing the + * {@code int} encoding them. + */ private String flags; + /** + * Decode the {@link flags} numerical string to a format for console + * output. The result does not honour all possible flags but includes + * information about OSR compilation. + * + * @param osr_bci the byte code index at which an OSR compilation takes + * place, or -1 if the compilation is not an OSR one. + */ String decodeFlags(int osr_bci) { int f = Integer.parseInt(getFlags()); char[] c = new char[4]; @@ -49,6 +91,12 @@ return new String(c); } + /** + * Format this method for console output. + * + * @param osr_bci the byte code index at which OSR takes place, or -1 if no + * OSR compilation is going on. + */ String format(int osr_bci) { if (osr_bci >= 0) { return getHolder() + "::" + getName() + " @ " + osr_bci + " (" + getBytes() + " bytes)"; @@ -62,6 +110,10 @@ return getHolder() + "::" + getName() + " (" + getBytes() + " bytes)"; } + public String getFullName() { + return getHolder().replace('/', '.') + "." + getName() + signature; + } + public String getHolder() { return holder; } @@ -86,12 +138,16 @@ this.returnType = returnType; } - public String getArguments() { - return arguments; + public String getSignature() { + return signature; } - public void setArguments(String arguments) { - this.arguments = arguments; + public void setSignature(String signature) { + this.signature = signature.replace('/', '.'); + } + + public String getArguments() { + return signature.substring(0, signature.indexOf(')') + 1); } public String getBytes() { @@ -121,10 +177,13 @@ @Override public boolean equals(Object o) { if (o instanceof Method) { - Method other = (Method)o; - return holder.equals(other.holder) && name.equals(other.name) && - arguments.equals(other.arguments) && returnType.equals(other.returnType); + Method other = (Method) o; + return holder.equals(other.holder) && name.equals(other.name) && signature.equals(other.signature); } return false; } + + public int hashCode() { + return holder.hashCode() ^ name.hashCode(); + } }
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/NMethod.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/NMethod.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -26,9 +26,20 @@ import java.io.PrintStream; +/** + * A compilation log event that is signalled whenever a new nmethod (a native + * method, a compilation result) is created. + */ public class NMethod extends BasicLogEvent { + /** + * The nmethod's starting address in memory. + */ private long address; + + /** + * The nmethod's size in bytes. + */ private long size; NMethod(double s, String i, long a, long sz) { @@ -37,7 +48,7 @@ size = sz; } - public void print(PrintStream out) { + public void print(PrintStream out, boolean printID) { // XXX Currently we do nothing // throw new InternalError(); }
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Phase.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/Phase.java Tue Mar 31 21:46:44 2015 +0200 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, 2011, Oracle and/or its affiliates. All rights reserved. + * 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 @@ -26,11 +26,30 @@ import java.io.PrintStream; +/** + * Representation of a compilation phase as a log event. + */ public class Phase extends BasicLogEvent { + /** + * The number of nodes in the compilation at the beginning of this phase. + */ private final int startNodes; + + /** + * The number of nodes in the compilation at the end of this phase. + */ private int endNodes; + + /** + * The number of live nodes in the compilation at the beginning of this + * phase. + */ private final int startLiveNodes; + + /** + * The number of live nodes in the compilation at the end of this phase. + */ private int endLiveNodes; Phase(String n, double s, int nodes, int live) { @@ -58,8 +77,11 @@ public int getEndNodes() { return endNodes; } - /* Number of live nodes added by the phase */ - int getLiveNodes() { + + /** + * The number of live nodes added by this phase. + */ + int getAddedLiveNodes() { return getEndLiveNodes() - getStartLiveNodes(); } @@ -76,7 +98,7 @@ } @Override - public void print(PrintStream stream) { + public void print(PrintStream stream, boolean printID) { throw new UnsupportedOperationException("Not supported yet."); } }
--- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/UncommonTrap.java Tue Mar 31 21:46:44 2015 +0200 @@ -0,0 +1,79 @@ +/* + * 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. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Sun Microsystems, Inc., 4150 Network Circle, Santa Clara, + * CA 95054 USA or visit www.sun.com if you need additional information or + * have any questions. + * + */ +package com.sun.hotspot.tools.compiler; + +import java.io.PrintStream; + +/** + * An instance of this class represents an uncommon trap associated with a + * given bytecode instruction. An uncommon trap is described in terms of its + * reason and action to be taken. An instance of this class is always relative + * to a specific method and only contains the relevant bytecode instruction + * index. + */ +class UncommonTrap { + + private int bci; + private String reason; + private String action; + private String bytecode; + + public UncommonTrap(int b, String r, String a, String bc) { + bci = b; + reason = r; + action = a; + bytecode = bc; + } + + public int getBCI() { + return bci; + } + + public String getReason() { + return reason; + } + + public String getAction() { + return action; + } + + public String getBytecode() { + return bytecode; + } + + void emit(PrintStream stream, int indent) { + for (int i = 0; i < indent; i++) { + stream.print(' '); + } + } + + public void print(PrintStream stream, int indent) { + emit(stream, indent); + stream.println(this); + } + + public String toString() { + return "@ " + bci + " " + getBytecode() + " uncommon trap " + getReason() + " " + getAction(); + } +}
--- a/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/UncommonTrapEvent.java Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/tools/LogCompilation/src/com/sun/hotspot/tools/compiler/UncommonTrapEvent.java Tue Mar 31 21:46:44 2015 +0200 @@ -21,17 +21,33 @@ * questions. * */ - package com.sun.hotspot.tools.compiler; import java.io.PrintStream; +import java.util.ArrayList; +import java.util.List; +/** + * Represents an uncommon trap encountered during a compilation. + */ class UncommonTrapEvent extends BasicLogEvent { private final String reason; private final String action; + + /** + * Denote how many times this trap has been encountered. + */ private int count; - private String jvms = ""; + + /** + * The name of the bytecode instruction at which the trap occurred. + */ + private String bytecode; + + private List<String> jvmsMethods = new ArrayList<>(); + + private List<Integer> jvmsBCIs = new ArrayList<>(); UncommonTrapEvent(double s, String i, String r, String a, int c) { super(s, i); @@ -40,20 +56,26 @@ count = c; } - - public void addJVMS(String method, int bci) { - setJvms(getJvms() + " @" + bci + " " + method + "\n"); - } - public void updateCount(UncommonTrapEvent trap) { setCount(Math.max(getCount(), trap.getCount())); } - public void print(PrintStream stream) { - stream.printf("%s uncommon trap %.3f %s %s\n", getId(), getStart(), getReason(), getAction()); - stream.print(getJvms()); + public void print(PrintStream stream, boolean printID) { + if (printID) { + stream.print(getId() + " "); + } + stream.printf("uncommon trap %s %s %s\n", bytecode, getReason(), getAction()); + int indent = 2; + for (int j = 0; j < jvmsMethods.size(); j++) { + for (int i = 0; i < indent; i++) { + stream.print(' '); + } + stream.println("@ " + jvmsBCIs.get(j) + " " + jvmsMethods.get(j)); + indent += 2; + } } + public String getReason() { return reason; } @@ -70,15 +92,56 @@ this.count = count; } - public String getJvms() { - return jvms; + /** + * Set the compilation for this event. This involves identifying the call + * site to which this uncommon trap event belongs. In addition to setting + * the {@link #compilation} link, this method will consequently also set + * the {@link #bytecode} field. + */ + public void setCompilation(Compilation compilation) { + super.setCompilation(compilation); + // Attempt to associate a bytecode with with this trap + CallSite site = compilation.getCall(); + int i = 0; + try { + List<UncommonTrap> traps = site.getTraps(); + while (i + 1 < jvmsMethods.size()) { + if (!jvmsMethods.get(i).equals(site.getMethod().getFullName())) { + throw new InternalError(jvmsMethods.get(i) + " != " + site.getMethod().getFullName()); + } + CallSite result = null; + for (CallSite call : site.getCalls()) { + if (call.getBci() == jvmsBCIs.get(i) && + call.getMethod().getFullName().equals(jvmsMethods.get(i + 1)) && + call.getReceiver() == null) { + result = call; + i++; + break; + } + } + if (result == null) { + throw new InternalError("couldn't find call site"); + } + site = result; + traps = site.getTraps(); + } + for (UncommonTrap trap : traps) { + if (trap.getBCI() == jvmsBCIs.get(i) && + trap.getReason().equals(getReason()) && + trap.getAction().equals(getAction())) { + bytecode = trap.getBytecode(); + return; + } + } + throw new InternalError("couldn't find bytecode"); + } catch (Exception e) { + bytecode = "<unknown>"; + } } - public void setJvms(String jvms) { - this.jvms = jvms; + public void addMethodAndBCI(String method, int bci) { + jvmsMethods.add(0, method); + jvmsBCIs.add(0, bci); } - public void setCompilation(Compilation compilation) { - this.compilation = compilation; - } }
--- a/src/share/vm/compiler/compileBroker.cpp Mon Jul 13 13:22:21 2015 -0700 +++ b/src/share/vm/compiler/compileBroker.cpp Tue Mar 31 21:46:44 2015 +0200 @@ -501,8 +501,8 @@ methodHandle method(thread, this->method()); ResourceMark rm(thread); - // <task id='9' method='M' osr_bci='X' level='1' blocking='1' stamp='1.234'> - log->print(" compile_id='%d'", _compile_id); + // <task compiler='Cx' id='9' method='M' osr_bci='X' level='1' blocking='1' stamp='1.234'> + log->print(" compiler='%s' compile_id='%d'", _comp_level <= CompLevel_full_profile ? "C1" : "C2", _compile_id); if (_osr_bci != CompileBroker::standard_entry_bci) { log->print(" compile_kind='osr'"); // same as nmethod::compile_kind } // else compile_kind='c2c'