1 /*
   2  * Copyright (c) 2009, 2015, Oracle and/or its affiliates. All rights reserved.
   3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   4  *
   5  * This code is free software; you can redistribute it and/or modify it
   6  * under the terms of the GNU General Public License version 2 only, as
   7  * published by the Free Software Foundation.
   8  *
   9  * This code is distributed in the hope that it will be useful, but WITHOUT
  10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  12  * version 2 for more details (a copy is included in the LICENSE file that
  13  * accompanied this code).
  14  *
  15  * You should have received a copy of the GNU General Public License version
  16  * 2 along with this work; if not, write to the Free Software Foundation,
  17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
  18  *
  19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
  20  * or visit www.oracle.com if you need additional information or have any
  21  * questions.
  22  *
  23  */
  24 
  25 /**
  26  * A SAX based parser of LogCompilation output from HotSpot.  It takes a complete
  27  */
  28 
  29 package com.sun.hotspot.tools.compiler;
  30 
  31 import java.io.FileReader;
  32 import java.io.PrintStream;
  33 import java.io.Reader;
  34 import java.util.ArrayDeque;
  35 import java.util.ArrayList;
  36 import java.util.Comparator;
  37 import java.util.Deque;
  38 import java.util.HashMap;
  39 import java.util.LinkedHashMap;
  40 import java.util.regex.Pattern;
  41 
  42 import javax.xml.parsers.SAXParser;
  43 import javax.xml.parsers.SAXParserFactory;
  44 
  45 import org.xml.sax.Attributes;
  46 import org.xml.sax.ErrorHandler;
  47 import org.xml.sax.InputSource;
  48 import org.xml.sax.Locator;
  49 import org.xml.sax.helpers.DefaultHandler;
  50 
  51 /**
  52  * A SAX parser for HotSpot compilation logs. The bulk of the parsing and event
  53  * maintenance work is done in the {@link #startElement(String,String,String,Attributes)}
  54  * and {@link #endElement(String,String,String)} methods.
  55  */
  56 public class LogParser extends DefaultHandler implements ErrorHandler {
  57 
  58     static final Pattern spacePattern = Pattern.compile(" ");
  59 
  60     /**
  61      * Map internal array type descriptors to Java names.
  62      */
  63     static final HashMap<String, String> type2printableMap;
  64 
  65     /**
  66      * Map Java primitive type names to internal type descriptors.
  67      */
  68     static final HashMap<String, String> type2vmtypeMap;
  69 
  70     static {
  71         type2printableMap = new HashMap<>();
  72         type2printableMap.put("[I", "int[]");
  73         type2printableMap.put("[C", "char[]");
  74         type2printableMap.put("[Z", "boolean[]");
  75         type2printableMap.put("[L", "Object[]");
  76         type2printableMap.put("[B", "byte[]");
  77 
  78         type2vmtypeMap = new HashMap<>();
  79         type2vmtypeMap.put("void", "V");
  80         type2vmtypeMap.put("boolean", "Z");
  81         type2vmtypeMap.put("byte", "B");
  82         type2vmtypeMap.put("char", "C");
  83         type2vmtypeMap.put("short", "S");
  84         type2vmtypeMap.put("int", "I");
  85         type2vmtypeMap.put("long", "J");
  86         type2vmtypeMap.put("float", "F");
  87         type2vmtypeMap.put("double", "D");
  88     }
  89 
  90     static String[] bytecodes = new String[] {
  91         "nop",
  92         "aconst_null",
  93         "iconst_m1",
  94         "iconst_0",
  95         "iconst_1",
  96         "iconst_2",
  97         "iconst_3",
  98         "iconst_4",
  99         "iconst_5",
 100         "lconst_0",
 101         "lconst_1",
 102         "fconst_0",
 103         "fconst_1",
 104         "fconst_2",
 105         "dconst_0",
 106         "dconst_1",
 107         "bipush",
 108         "sipush",
 109         "ldc",
 110         "ldc_w",
 111         "ldc2_w",
 112         "iload",
 113         "lload",
 114         "fload",
 115         "dload",
 116         "aload",
 117         "iload_0",
 118         "iload_1",
 119         "iload_2",
 120         "iload_3",
 121         "lload_0",
 122         "lload_1",
 123         "lload_2",
 124         "lload_3",
 125         "fload_0",
 126         "fload_1",
 127         "fload_2",
 128         "fload_3",
 129         "dload_0",
 130         "dload_1",
 131         "dload_2",
 132         "dload_3",
 133         "aload_0",
 134         "aload_1",
 135         "aload_2",
 136         "aload_3",
 137         "iaload",
 138         "laload",
 139         "faload",
 140         "daload",
 141         "aaload",
 142         "baload",
 143         "caload",
 144         "saload",
 145         "istore",
 146         "lstore",
 147         "fstore",
 148         "dstore",
 149         "astore",
 150         "istore_0",
 151         "istore_1",
 152         "istore_2",
 153         "istore_3",
 154         "lstore_0",
 155         "lstore_1",
 156         "lstore_2",
 157         "lstore_3",
 158         "fstore_0",
 159         "fstore_1",
 160         "fstore_2",
 161         "fstore_3",
 162         "dstore_0",
 163         "dstore_1",
 164         "dstore_2",
 165         "dstore_3",
 166         "astore_0",
 167         "astore_1",
 168         "astore_2",
 169         "astore_3",
 170         "iastore",
 171         "lastore",
 172         "fastore",
 173         "dastore",
 174         "aastore",
 175         "bastore",
 176         "castore",
 177         "sastore",
 178         "pop",
 179         "pop2",
 180         "dup",
 181         "dup_x1",
 182         "dup_x2",
 183         "dup2",
 184         "dup2_x1",
 185         "dup2_x2",
 186         "swap",
 187         "iadd",
 188         "ladd",
 189         "fadd",
 190         "dadd",
 191         "isub",
 192         "lsub",
 193         "fsub",
 194         "dsub",
 195         "imul",
 196         "lmul",
 197         "fmul",
 198         "dmul",
 199         "idiv",
 200         "ldiv",
 201         "fdiv",
 202         "ddiv",
 203         "irem",
 204         "lrem",
 205         "frem",
 206         "drem",
 207         "ineg",
 208         "lneg",
 209         "fneg",
 210         "dneg",
 211         "ishl",
 212         "lshl",
 213         "ishr",
 214         "lshr",
 215         "iushr",
 216         "lushr",
 217         "iand",
 218         "land",
 219         "ior",
 220         "lor",
 221         "ixor",
 222         "lxor",
 223         "iinc",
 224         "i2l",
 225         "i2f",
 226         "i2d",
 227         "l2i",
 228         "l2f",
 229         "l2d",
 230         "f2i",
 231         "f2l",
 232         "f2d",
 233         "d2i",
 234         "d2l",
 235         "d2f",
 236         "i2b",
 237         "i2c",
 238         "i2s",
 239         "lcmp",
 240         "fcmpl",
 241         "fcmpg",
 242         "dcmpl",
 243         "dcmpg",
 244         "ifeq",
 245         "ifne",
 246         "iflt",
 247         "ifge",
 248         "ifgt",
 249         "ifle",
 250         "if_icmpeq",
 251         "if_icmpne",
 252         "if_icmplt",
 253         "if_icmpge",
 254         "if_icmpgt",
 255         "if_icmple",
 256         "if_acmpeq",
 257         "if_acmpne",
 258         "goto",
 259         "jsr",
 260         "ret",
 261         "tableswitch",
 262         "lookupswitch",
 263         "ireturn",
 264         "lreturn",
 265         "freturn",
 266         "dreturn",
 267         "areturn",
 268         "return",
 269         "getstatic",
 270         "putstatic",
 271         "getfield",
 272         "putfield",
 273         "invokevirtual",
 274         "invokespecial",
 275         "invokestatic",
 276         "invokeinterface",
 277         "invokedynamic",
 278         "new",
 279         "newarray",
 280         "anewarray",
 281         "arraylength",
 282         "athrow",
 283         "checkcast",
 284         "instanceof",
 285         "monitorenter",
 286         "monitorexit",
 287         "wide",
 288         "multianewarray",
 289         "ifnull",
 290         "ifnonnull",
 291         "goto_w",
 292         "jsr_w",
 293         "breakpoint"
 294     };
 295 
 296     /**
 297      * Sort log events by start time.
 298      */
 299     static Comparator<LogEvent> sortByStart = new Comparator<LogEvent>() {
 300 
 301         public int compare(LogEvent a, LogEvent b) {
 302             double difference = (a.getStart() - b.getStart());
 303             if (difference < 0) {
 304                 return -1;
 305             }
 306             if (difference > 0) {
 307                 return 1;
 308             }
 309             return 0;
 310         }
 311 
 312         @Override
 313         public boolean equals(Object other) {
 314             return false;
 315         }
 316 
 317         @Override
 318         public int hashCode() {
 319             return 7;
 320         }
 321     };
 322 
 323     /**
 324      * Sort log events first by the name of the compiled method, then by start
 325      * time. In case one of the events has no associated compilation (or the
 326      * associated compilation has no method name), the event with a compilation
 327      * and/or name is considered the larger one.
 328      */
 329     static Comparator<LogEvent> sortByNameAndStart = new Comparator<LogEvent>() {
 330 
 331         public int compare(LogEvent a, LogEvent b) {
 332             Compilation c1 = a.getCompilation();
 333             Compilation c2 = b.getCompilation();
 334             if (c1 != null && c1.getMethod() != null && c2 != null && c2.getMethod() != null) {
 335                 int result = c1.getMethod().toString().compareTo(c2.getMethod().toString());
 336                 if (result != 0) {
 337                     return result;
 338                 }
 339             } else if ((c1 == null || c1.getMethod() == null) && c2 != null && c2.getMethod() != null) {
 340                 return -1;
 341             } else if ((c2 == null || c2.getMethod() == null) && c1 != null && c1.getMethod() != null) {
 342                 return 1;
 343             }
 344             return Double.compare(a.getStart(), b.getStart());
 345         }
 346 
 347         public boolean equals(Object other) {
 348             return false;
 349         }
 350 
 351         @Override
 352         public int hashCode() {
 353             return 7;
 354         }
 355     };
 356 
 357     /**
 358      * Sort log events by duration.
 359      */
 360     static Comparator<LogEvent> sortByElapsed = new Comparator<LogEvent>() {
 361 
 362         public int compare(LogEvent a, LogEvent b) {
 363             double difference = (a.getElapsedTime() - b.getElapsedTime());
 364             if (difference < 0) {
 365                 return -1;
 366             }
 367             if (difference > 0) {
 368                 return 1;
 369             }
 370             return 0;
 371         }
 372 
 373         @Override
 374         public boolean equals(Object other) {
 375             return false;
 376         }
 377 
 378         @Override
 379         public int hashCode() {
 380             return 7;
 381         }
 382     };
 383 
 384     /**
 385      * Shrink-wrapped representation of a JVMState (tailored to meet this
 386      * tool's needs). It only records a method and bytecode instruction index.
 387      */
 388     class Jvms {
 389         Jvms(Method method, int bci) {
 390             this.method = method;
 391             this.bci = bci;
 392         }
 393         final public Method method;
 394         final public int bci;
 395         final public String toString() {
 396             return "@" + bci + " " + method;
 397         }
 398     }
 399 
 400     /**
 401      * Representation of a lock elimination. Locks, corresponding to
 402      * synchronized blocks and method calls, may be eliminated if the object in
 403      * question is guaranteed to be used thread-locally.
 404      */
 405     class LockElimination extends BasicLogEvent {
 406 
 407         /**
 408          * Track all locations from which this lock was eliminated.
 409          */
 410         ArrayList<Jvms> jvms = new ArrayList<>(1);
 411 
 412         /**
 413          * The kind of lock (coarsened, nested, non-escaping, unknown).
 414          */
 415         final String kind;
 416 
 417         /**
 418          * The lock class (unlock, lock, unknown).
 419          */
 420         final String classId;
 421 
 422         /**
 423          * The precise type of lock.
 424          */
 425         final String tagName;
 426 
 427         LockElimination(String tagName, double start, String id, String kind, String classId) {
 428             super(start, id);
 429             this.kind = kind;
 430             this.classId = classId;
 431             this.tagName = tagName;
 432         }
 433 
 434         @Override
 435         public void print(PrintStream stream, boolean printID) {
 436             if (printID) {
 437                 stream.printf("%s ", getId());
 438             }
 439             stream.printf("%s %s %s  %.3f ", tagName, kind, classId, getStart());
 440             stream.print(jvms.toString());
 441             stream.print("\n");
 442         }
 443 
 444         void addJVMS(Method method, int bci) {
 445             jvms.add(new Jvms(method, bci));
 446         }
 447 
 448     }
 449 
 450     /**
 451      * A list of log events. This is populated with the events found in the
 452      * compilation log file during parsing.
 453      */
 454     private ArrayList<LogEvent> events = new ArrayList<>();
 455 
 456     /**
 457      * Map compilation log IDs to type names.
 458      */
 459     private HashMap<String, String> types = new HashMap<>();
 460 
 461     /**
 462      * Map compilation log IDs to methods.
 463      */
 464     private HashMap<String, Method> methods = new HashMap<>();
 465 
 466     /**
 467      * Map compilation IDs ({@see #makeId()}) to newly created nmethods.
 468      */
 469     private LinkedHashMap<String, NMethod> nmethods = new LinkedHashMap<>();
 470 
 471     /**
 472      * Map compilation task IDs {@see #makeId()}) to {@link Compilation}
 473      * objects.
 474      */
 475     private HashMap<String, Compilation> compiles = new HashMap<>();
 476 
 477     /**
 478      * Track compilation failure reasons.
 479      */
 480     private String failureReason;
 481 
 482     /**
 483      * The current bytecode instruction index.
 484      */
 485     private int current_bci;
 486 
 487     /**
 488      * The current bytecode instruction.
 489      */
 490     private int current_bytecode;
 491 
 492     /**
 493      * A sequence of {@link CallSite}s representing a call stack. A scope
 494      * typically holds several {@link CallSite}s that represent calls
 495      * originating from that scope.
 496      *
 497      * New scopes are typically pushed when parse log events are encountered
 498      * ({@see #startElement()}) and popped when parsing of a given Java method
 499      * is done ({@see #endElement()}). Parsing events can be nested. Several
 500      * other events add information to scopes ({@see #startElement()}).
 501      */
 502     private Deque<CallSite> scopes = new ArrayDeque<>();
 503 
 504     /**
 505      * The current compilation.
 506      */
 507     private Compilation compile;
 508 
 509     /**
 510      * The {@linkplain CallSite compilation scope} currently in focus.
 511      */
 512     private CallSite site;
 513 
 514     /**
 515      * The {@linkplain CallSite method handle call site} currently under
 516      * observation.
 517      */
 518     private CallSite methodHandleSite;
 519 
 520     /**
 521      * Keep track of potentially nested compiler {@linkplain Phase phases}.
 522      */
 523     private Deque<Phase> phaseStack = new ArrayDeque<>();
 524 
 525     /**
 526      * The {@linkplain LockElimination lock elimination event} currently being
 527      * processed.
 528      */
 529     private LockElimination currentLockElimination;
 530 
 531     /**
 532      * The {@linkplain UncommonTrapEvent uncommon trap event} currently being
 533      * processed.
 534      */
 535     private UncommonTrapEvent currentTrap;
 536 
 537     /**
 538      * During the processing of a late inline event, this stack holds the
 539      * {@link CallSite}s that represent the inlining event's call stack.
 540      */
 541     private Deque<CallSite> lateInlineScope;
 542 
 543     /**
 544      * Denote whether a late inlining event is currently being processed.
 545      */
 546     private boolean lateInlining;
 547 
 548     /**
 549      * A document locator to provide better error messages: this allows the
 550      * tool to display in which line of the log file the problem occurred.
 551      */
 552     private Locator locator;
 553 
 554     /**
 555      * Callback for the SAX framework to set the document locator.
 556      */
 557     @Override
 558     public void setDocumentLocator(Locator locator) {
 559         this.locator = locator;
 560     }
 561 
 562     /**
 563      * Report an internal error explicitly raised, i.e., not derived from an
 564      * exception.
 565      *
 566      * @param msg The error message to report.
 567      */
 568     private void reportInternalError(String msg) {
 569         reportInternalError(msg, null);
 570     }
 571 
 572     /**
 573      * Report an internal error derived from an exception.
 574      *
 575      * @param msg The beginning of the error message to report. The message
 576      * from the exception will be appended to this.
 577      * @param e The exception that led to the internal error.
 578      */
 579     private void reportInternalError(String msg, Exception e) {
 580         if (locator != null) {
 581             msg += " at " + locator.getLineNumber() + ":" + locator.getColumnNumber();
 582             if (e != null) {
 583                 msg += " - " + e.getMessage();
 584             }
 585         }
 586         if (e != null) {
 587             throw new Error(msg, e);
 588         } else {
 589             throw new Error(msg);
 590         }
 591     }
 592 
 593     /**
 594      * Parse a long hexadecimal address into a {@code long} value. As Java only
 595      * supports positive {@code long} values, extra error handling and parsing
 596      * logic is provided.
 597      */
 598     long parseLong(String l) {
 599         try {
 600             return Long.decode(l).longValue();
 601         } catch (NumberFormatException nfe) {
 602             int split = l.length() - 8;
 603             String s1 = "0x" + l.substring(split);
 604             String s2 = l.substring(0, split);
 605             long v1 = Long.decode(s1).longValue() & 0xffffffffL;
 606             long v2 = (Long.decode(s2).longValue() & 0xffffffffL) << 32;
 607             if (!l.equals("0x" + Long.toHexString(v1 + v2))) {
 608                 System.out.println(l);
 609                 System.out.println(s1);
 610                 System.out.println(s2);
 611                 System.out.println(v1);
 612                 System.out.println(v2);
 613                 System.out.println(Long.toHexString(v1 + v2));
 614                 reportInternalError("bad conversion");
 615             }
 616             return v1 + v2;
 617         }
 618     }
 619 
 620     /**
 621      * Entry point for log file parsing with a file name.
 622      *
 623      * @param file The name of the log file to parse.
 624      * @param cleanup Whether to perform bad XML cleanup during parsing (this
 625      * is relevant for some log files generated by the 1.5 JVM).
 626      * @return a list of {@link LogEvent} instances describing the events found
 627      * in the log file.
 628      */
 629     public static ArrayList<LogEvent> parse(String file, boolean cleanup) throws Exception {
 630         return parse(new FileReader(file), cleanup);
 631     }
 632 
 633     /**
 634      * Entry point for log file parsing with a file reader.
 635      * {@see #parse(String,boolean)}
 636      */
 637     public static ArrayList<LogEvent> parse(Reader reader, boolean cleanup) throws Exception {
 638         // Create the XML input factory
 639         SAXParserFactory factory = SAXParserFactory.newInstance();
 640 
 641         // Create the XML LogEvent reader
 642         SAXParser p = factory.newSAXParser();
 643 
 644         if (cleanup) {
 645             // some versions of the log have slightly malformed XML, so clean it
 646             // up before passing it to SAX
 647             reader = new LogCleanupReader(reader);
 648         }
 649 
 650         LogParser log = new LogParser();
 651         try {
 652             p.parse(new InputSource(reader), log);
 653         } catch (Throwable th) {
 654             th.printStackTrace();
 655             // Carry on with what we've got...
 656         }
 657 
 658         // Associate compilations with their NMethods and other kinds of events
 659         for (LogEvent e : log.events) {
 660             if (e instanceof BasicLogEvent) {
 661                 BasicLogEvent ble = (BasicLogEvent) e;
 662                 Compilation c = log.compiles.get(ble.getId());
 663                 if (c == null) {
 664                     if (!(ble instanceof NMethod)) {
 665                         throw new InternalError("only nmethods should have a null compilation, here's a " + ble.getClass());
 666                     }
 667                     continue;
 668                 }
 669                 ble.setCompilation(c);
 670                 if (ble instanceof NMethod) {
 671                     c.setNMethod((NMethod) ble);
 672                 }
 673             }
 674         }
 675 
 676         return log.events;
 677     }
 678 
 679     /**
 680      * Retrieve a given attribute's value from a collection of XML tag
 681      * attributes. Report an error if the requested attribute is not found.
 682      *
 683      * @param attr A collection of XML tag attributes.
 684      * @param name The name of the attribute the value of which is to be found.
 685      * @return The value of the requested attribute, or {@code null} if it was
 686      * not found.
 687      */
 688     String search(Attributes attr, String name) {
 689         String result = attr.getValue(name);
 690         if (result != null) {
 691             return result;
 692         } else {
 693             reportInternalError("can't find " + name);
 694             return null;
 695         }
 696     }
 697 
 698     /**
 699      * Retrieve a given attribute's value from a collection of XML tag
 700      * attributes. Return a default value if the requested attribute is not
 701      * found.
 702      *
 703      * @param attr A collection of XML tag attributes.
 704      * @param name The name of the attribute the value of which is to be found.
 705      * @param defaultValue The default value to return if the attribute is not
 706      * found.
 707      * @return The value of the requested attribute, or the default value if it
 708      * was not found.
 709      */
 710     String search(Attributes attr, String name, String defaultValue) {
 711         String result = attr.getValue(name);
 712         if (result != null) {
 713             return result;
 714         }
 715         return defaultValue;
 716     }
 717 
 718     /**
 719      * Map a type ID from the compilation log to an actual type name. In case
 720      * the type represents an internal array type descriptor, return a
 721      * Java-level name. If the type ID cannot be mapped to a name, raise an
 722      * error.
 723      */
 724     String type(String id) {
 725         String result = types.get(id);
 726         if (result == null) {
 727             reportInternalError(id);
 728         }
 729         String remapped = type2printableMap.get(result);
 730         if (remapped != null) {
 731             return remapped;
 732         }
 733         return result;
 734     }
 735 
 736     /**
 737      * Register a mapping from log file type ID to type name.
 738      */
 739     void type(String id, String name) {
 740         assert type(id) == null;
 741         types.put(id, name);
 742     }
 743 
 744     /**
 745      * Map a log file type ID to an internal type declarator.
 746      */
 747     String sigtype(String id) {
 748         String result = types.get(id);
 749         String remapped = type2vmtypeMap.get(result);
 750         if (remapped != null) {
 751             return remapped;
 752         }
 753         if (result == null) {
 754             reportInternalError(id);
 755         }
 756         if (result.charAt(0) == '[') {
 757             return result;
 758         }
 759         return "L" + result + ";";
 760     }
 761 
 762     /**
 763      * Retrieve a method based on the log file ID it was registered under.
 764      * Raise an error if the ID does not map to a method.
 765      */
 766     Method method(String id) {
 767         Method result = methods.get(id);
 768         if (result == null) {
 769             reportInternalError(id);
 770         }
 771         return result;
 772     }
 773 
 774     /**
 775      * From a compilation ID and kind, assemble a compilation ID for inclusion
 776      * in the output.
 777      *
 778      * @param atts A collection of XML attributes from which the required
 779      * attributes are retrieved.
 780      */
 781     public String makeId(Attributes atts) {
 782         String id = atts.getValue("compile_id");
 783         String kind = atts.getValue("kind");
 784         if (kind != null && kind.equals("osr")) {
 785             id += "%";
 786         }
 787         return id;
 788     }
 789 
 790     /**
 791      * Process the start of a compilation log XML element.<ul>
 792      * <li><b>phase:</b> record the beginning of a compilation phase, pushing
 793      * it on the {@linkplain #phaseStack phase stack} and collecting
 794      * information about the compiler graph.</li>
 795      * <li><b>phase_done:</b> record the end of a compilation phase, popping it
 796      * off the {@linkplain #phaseStack phase stack} and collecting information
 797      * about the compiler graph (number of nodes and live nodes).</li>
 798      * <li><b>task:</b> register the start of a new compilation.</li>
 799      * <li><b>type:</b> register a type.</li>
 800      * <li><b>bc:</b> note the current bytecode index and instruction name,
 801      * updating {@link #current_bci} and {@link #current_bytecode}.</li>
 802      * <li><b>klass:</b> register a type (class).</li>
 803      * <li><b>method:</b> register a Java method.</li>
 804      * <li><b>call:</b> process a call, populating {@link #site} with the
 805      * appropriate data.</li>
 806      * <li><b>regalloc:</b> record the register allocator's trip count in the
 807      * {@linkplain #compile current compilation}.</li>
 808      * <li><b>inline_fail:</b> record the reason for a failed inline
 809      * operation.</li>
 810      * <li><b>inline_success:</b> record a successful inlining operation,
 811      * noting the success reason in the {@linkplain #site call site}.</li>
 812      * <li><b>failure:</b> note a compilation failure, storing the reason
 813      * description in {@link #failureReason}.</li>
 814      * <li><b>task_done:</b> register the end of a compilation, recording time
 815      * stamp and success information.</li>
 816      * <li><b>make_not_entrant:</b> deal with making a native method
 817      * non-callable (e.g., during an OSR compilation, if there are still
 818      * activations) or a zombie (when the method can be deleted).</li>
 819      * <li><b>uncommon_trap:</b> process an uncommon trap, setting the
 820      * {@link #currentTrap} field.</li>
 821      * <li><b>eliminate_lock:</b> record the start of a lock elimination,
 822      * setting the {@link #currentLockElimination} event.</li>
 823      * <li><b>late_inline:</b> start processing a late inline decision:
 824      * initialize the {@linkplain #lateInlineScope inline scope stack}, create
 825      * an {@linkplain #site initial scope} with a bogus bytecode index and the
 826      * right inline ID, and push the scope with the inline ID attached. Note
 827      * that most of late inlining processing happens in
 828      * {@link #endElement()}.</li>
 829      * <li><b>jvms:</b> record a {@linkplain Jvms JVMState}. Depending on the
 830      * context in which this event is encountered, this can mean adding
 831      * information to the currently being processed trap, lock elimination, or
 832      * inlining operation.</li>
 833      * <li><b>inline_id:</b> set the inline ID in the
 834      * {@linkplain #site current call site}.</li>
 835      * <li><b>nmethod:</b> record the creation of a new {@link NMethod} and
 836      * store it in the {@link #nmethods} map.</li>
 837      * <li><b>parse:</b> begin parsing a Java method's bytecode and
 838      * transforming it into an initial compiler IR graph.</li>
 839      * <li><b>parse_done:</b> finish parsing a Java method's bytecode.</li>
 840      * </ul>
 841      */
 842     @Override
 843     public void startElement(String uri, String localName, String qname, Attributes atts) {
 844         if (qname.equals("phase")) {
 845             Phase p = new Phase(search(atts, "name"),
 846                     Double.parseDouble(search(atts, "stamp")),
 847                     Integer.parseInt(search(atts, "nodes", "0")),
 848                     Integer.parseInt(search(atts, "live", "0")));
 849             phaseStack.push(p);
 850         } else if (qname.equals("phase_done")) {
 851             Phase p = phaseStack.pop();
 852             String phaseName = search(atts, "name", null);
 853             if (phaseName != null && !p.getId().equals(phaseName)) {
 854                 System.out.println("phase: " + p.getId());
 855                 reportInternalError("phase name mismatch");
 856             }
 857             p.setEnd(Double.parseDouble(search(atts, "stamp")));
 858             p.setEndNodes(Integer.parseInt(search(atts, "nodes", "0")));
 859             p.setEndLiveNodes(Integer.parseInt(search(atts, "live", "0")));
 860             compile.getPhases().add(p);
 861         } else if (qname.equals("task")) {
 862             String id = makeId(atts);
 863 
 864             // Create the new Compilation instance and populate it with readily
 865             // available data.
 866             compile = new Compilation(Integer.parseInt(search(atts, "compile_id", "-1")));
 867             compile.setStart(Double.parseDouble(search(atts, "stamp")));
 868             compile.setICount(search(atts, "count", "0"));
 869             compile.setBCount(search(atts, "backedge_count", "0"));
 870             compile.setBCI(Integer.parseInt(search(atts, "osr_bci", "-1")));
 871             String compiler = atts.getValue("compiler");
 872             if (compiler == null) {
 873                 compiler = "";
 874             }
 875             compile.setCompiler(compiler);
 876 
 877             // Extract the name of the compiled method.
 878             String[] parts = spacePattern.split(atts.getValue("method"));
 879             String methodName = parts[0] + "::" + parts[1];
 880 
 881             // Continue collecting compilation meta-data.
 882             String kind = atts.getValue("compile_kind");
 883             if (kind == null) {
 884                 kind = "normal";
 885             }
 886             if (kind.equals("osr")) {
 887                 compile.setOsr(true);
 888             } else if (kind.equals("c2i")) {
 889                 compile.setSpecial("--- adapter " + methodName);
 890             } else {
 891                 compile.setSpecial(compile.getId() + " " + methodName + " (0 bytes)");
 892             }
 893 
 894             // Build a dummy method to stuff in the Compilation at the
 895             // beginning.
 896             Method m = new Method();
 897             m.setHolder(parts[0]);
 898             m.setName(parts[1]);
 899             m.setSignature(parts[2]);
 900             m.setFlags("0");
 901             m.setBytes(search(atts, "bytes", "unknown"));
 902             compile.setMethod(m);
 903             events.add(compile);
 904             compiles.put(id, compile);
 905             site = compile.getCall();
 906         } else if (qname.equals("type")) {
 907             type(search(atts, "id"), search(atts, "name"));
 908         } else if (qname.equals("bc")) {
 909             current_bci = Integer.parseInt(search(atts, "bci"));
 910             current_bytecode = Integer.parseInt(search(atts, "code"));
 911         } else if (qname.equals("klass")) {
 912             type(search(atts, "id"), search(atts, "name"));
 913         } else if (qname.equals("method")) {
 914             String id = search(atts, "id");
 915             Method m = new Method();
 916             m.setHolder(type(search(atts, "holder")));
 917             m.setName(search(atts, "name"));
 918             m.setReturnType(type(search(atts, "return")));
 919             String arguments = atts.getValue("arguments");;
 920             if (arguments == null) {
 921                 m.setSignature("()" + sigtype(atts.getValue("return")));
 922             } else {
 923                 String[] args = spacePattern.split(arguments);
 924                 StringBuilder sb = new StringBuilder("(");
 925                 for (int i = 0; i < args.length; i++) {
 926                     sb.append(sigtype(args[i]));
 927                 }
 928                 sb.append(")");
 929                 sb.append(sigtype(atts.getValue("return")));
 930                 m.setSignature(sb.toString());
 931             }
 932 
 933             if (search(atts, "unloaded", "0").equals("0")) {
 934                m.setBytes(search(atts, "bytes"));
 935                m.setIICount(search(atts, "iicount"));
 936                m.setFlags(search(atts, "flags"));
 937             }
 938             methods.put(id, m);
 939         } else if (qname.equals("call")) {
 940             if (methodHandleSite != null) {
 941                 methodHandleSite = null;
 942             }
 943             Method m = method(search(atts, "method"));
 944             if (lateInlining && scopes.size() == 0) {
 945                 // re-attempting already seen call site (late inlining for MH invokes)
 946                 if (m != site.getMethod()) {
 947                     if (current_bci != site.getBci()) {
 948                         System.err.println(m + " bci: " + current_bci);
 949                         System.err.println(site.getMethod() +  " bci: " + site.getBci());
 950                         reportInternalError("bci mismatch after late inlining");
 951                     }
 952                     site.setMethod(m);
 953                 }
 954             } else {
 955                 // We're dealing with a new call site; the called method is
 956                 // likely to be parsed next.
 957                 site = new CallSite(current_bci, m);
 958             }
 959             site.setCount(Integer.parseInt(search(atts, "count", "0")));
 960             String receiver = atts.getValue("receiver");
 961             if (receiver != null) {
 962                 site.setReceiver(type(receiver));
 963                 site.setReceiver_count(Integer.parseInt(search(atts, "receiver_count")));
 964             }
 965             int methodHandle = Integer.parseInt(search(atts, "method_handle_intrinsic", "0"));
 966             if (lateInlining && scopes.size() == 0) {
 967                 // The call was already added before this round of late
 968                 // inlining. Ignore.
 969             } else if (methodHandle == 0) {
 970                 scopes.peek().add(site);
 971             } else {
 972                 // method handle call site can be followed by another
 973                 // call (in case it is inlined). If that happens we
 974                 // discard the method handle call site. So we keep
 975                 // track of it but don't add it to the list yet.
 976                 methodHandleSite = site;
 977             }
 978         } else if (qname.equals("regalloc")) {
 979             compile.setAttempts(Integer.parseInt(search(atts, "attempts")));
 980         } else if (qname.equals("inline_fail")) {
 981             if (methodHandleSite != null) {
 982                 scopes.peek().add(methodHandleSite);
 983                 methodHandleSite = null;
 984             }
 985             if (lateInlining && scopes.size() == 0) {
 986                 site.setReason("fail: " + search(atts, "reason"));
 987                 lateInlining = false;
 988             } else {
 989                 scopes.peek().last().setReason("fail: " + search(atts, "reason"));
 990             }
 991         } else if (qname.equals("inline_success")) {
 992             if (methodHandleSite != null) {
 993                 reportInternalError("method handle site should have been replaced");
 994             }
 995             site.setReason("succeed: " + search(atts, "reason"));
 996         } else if (qname.equals("failure")) {
 997             failureReason = search(atts, "reason");
 998         } else if (qname.equals("task_done")) {
 999             compile.setEnd(Double.parseDouble(search(atts, "stamp")));
1000             if (Integer.parseInt(search(atts, "success")) == 0) {
1001                 compile.setFailureReason(failureReason);
1002                 failureReason = null;
1003             }
1004         } else if (qname.equals("make_not_entrant")) {
1005             String id = makeId(atts);
1006             NMethod nm = nmethods.get(id);
1007             if (nm == null) reportInternalError("nm == null");
1008             LogEvent e = new MakeNotEntrantEvent(Double.parseDouble(search(atts, "stamp")), id,
1009                                                  atts.getValue("zombie") != null, nm);
1010             events.add(e);
1011         } else if (qname.equals("uncommon_trap")) {
1012             String id = atts.getValue("compile_id");
1013             if (id != null) {
1014                 id = makeId(atts);
1015                 currentTrap = new UncommonTrapEvent(Double.parseDouble(search(atts, "stamp")),
1016                         id,
1017                         atts.getValue("reason"),
1018                         atts.getValue("action"),
1019                         Integer.parseInt(search(atts, "count", "0")));
1020                 events.add(currentTrap);
1021             } else {
1022                 if (atts.getValue("method") != null) {
1023                     // These are messages from ciTypeFlow that don't
1024                     // actually correspond to generated code.
1025                     return;
1026                 }
1027                 try {
1028                     UncommonTrap unc = new UncommonTrap(Integer.parseInt(search(atts, "bci")),
1029                             search(atts, "reason"),
1030                             search(atts, "action"),
1031                             bytecodes[current_bytecode]);
1032                     if (scopes.size() == 0) {
1033                         // There may be a dangling site not yet in scopes after a late_inline
1034                         if (site != null) {
1035                             site.add(unc);
1036                         } else {
1037                             reportInternalError("scope underflow");
1038                         }
1039                     } else {
1040                         scopes.peek().add(unc);
1041                     }
1042                 } catch (Error e) {
1043                     e.printStackTrace();
1044                 }
1045             }
1046         } else if (qname.startsWith("eliminate_lock")) {
1047             String id = atts.getValue("compile_id");
1048             if (id != null) {
1049                 id = makeId(atts);
1050                 String kind = atts.getValue("kind");
1051                 String classId = atts.getValue("class_id");
1052                 currentLockElimination = new LockElimination(qname, Double.parseDouble(search(atts, "stamp")), id, kind, classId);
1053                 events.add(currentLockElimination);
1054             }
1055         } else if (qname.equals("late_inline")) {
1056             long inlineId = 0;
1057             try {
1058                 inlineId = Long.parseLong(search(atts, "inline_id"));
1059             } catch (InternalError ex) {
1060                 // Log files from older hotspots may lack inline_id,
1061                 // and zero is an acceptable substitute that allows processing to continue.
1062             }
1063             lateInlineScope = new ArrayDeque<>();
1064             Method m = method(search(atts, "method"));
1065             site = new CallSite(-999, m);
1066             site.setInlineId(inlineId);
1067             lateInlineScope.push(site);
1068         } else if (qname.equals("jvms")) {
1069             // <jvms bci='4' method='java/io/DataInputStream readChar ()C' bytes='40' count='5815' iicount='20815'/>
1070             if (currentTrap != null) {
1071                 String[] parts = spacePattern.split(atts.getValue("method"));
1072                 currentTrap.addMethodAndBCI(parts[0].replace('/', '.') + '.' + parts[1] + parts[2], Integer.parseInt(atts.getValue("bci")));
1073             } else if (currentLockElimination != null) {
1074                   currentLockElimination.addJVMS(method(atts.getValue("method")), Integer.parseInt(atts.getValue("bci")));
1075             } else if (lateInlineScope != null) {
1076                 current_bci = Integer.parseInt(search(atts, "bci"));
1077                 Method m = method(search(atts, "method"));
1078                 site = new CallSite(current_bci, m);
1079                 lateInlineScope.push(site);
1080             } else {
1081                 // Ignore <eliminate_allocation type='667'>,
1082                 //        <replace_string_concat arguments='2' string_alloc='0' multiple='0'>
1083             }
1084         } else if (qname.equals("inline_id")) {
1085             if (methodHandleSite != null) {
1086                 reportInternalError("method handle site should have been replaced");
1087             }
1088             long id = Long.parseLong(search(atts, "id"));
1089             site.setInlineId(id);
1090         } else if (qname.equals("nmethod")) {
1091             String id = makeId(atts);
1092             NMethod nm = new NMethod(Double.parseDouble(search(atts, "stamp")),
1093                     id,
1094                     parseLong(atts.getValue("address")),
1095                     parseLong(atts.getValue("size")));
1096             nmethods.put(id, nm);
1097             events.add(nm);
1098         } else if (qname.equals("parse")) {
1099             if (failureReason != null && scopes.size() == 0 && !lateInlining) {
1100                 // A compilation just failed, and we're back at a top
1101                 // compilation scope.
1102                 failureReason = null;
1103                 compile.reset();
1104                 site = compile.getCall();
1105             }
1106 
1107             // Error checking.
1108             if (methodHandleSite != null) {
1109                 reportInternalError("method handle site should have been replaced");
1110             }
1111             Method m = method(search(atts, "method")); // this is the method being parsed
1112             if (lateInlining && scopes.size() == 0) {
1113                 if (site.getMethod() != m) {
1114                     reportInternalError("Unexpected method mismatch during late inlining (method at call site: " +
1115                         site.getMethod() + ", method being parsed: " + m + ")");
1116                 }
1117             }
1118 
1119             if (scopes.size() == 0 && !lateInlining) {
1120                 // The method being parsed is actually the method being
1121                 // compiled; i.e., we're dealing with a compilation top scope,
1122                 // which we must consequently push to the scopes stack.
1123                 compile.setMethod(m);
1124                 scopes.push(site);
1125             } else {
1126                 // The method being parsed is *not* the current compilation's
1127                 // top scope; i.e., we're dealing with an actual call site
1128                 // in the top scope or somewhere further down a call stack.
1129                 if (site.getMethod() == m) {
1130                     // We're dealing with monomorphic inlining that didn't have
1131                     // to be narrowed down, because the receiver was known
1132                     // beforehand.
1133                     scopes.push(site);
1134                 } else if (scopes.peek().getCalls().size() > 2 && m == scopes.peek().lastButOne().getMethod()) {
1135                     // We're dealing with an at least bimorphic call site, and
1136                     // the compiler has now decided to parse the last-but-one
1137                     // method. The last one may already have been parsed for
1138                     // inlining.
1139                     scopes.push(scopes.peek().lastButOne());
1140                 } else {
1141                     // The method has been narrowed down to the one we're now
1142                     // going to parse, which is inlined here. It's monomorphic
1143                     // inlining, but was not immediately clear as such.
1144                     //
1145                     // C1 prints multiple method tags during inlining when it
1146                     // narrows the method being inlined. Example:
1147                     //   ...
1148                     //   <method id="813" holder="694" name="toString" return="695" flags="1" bytes="36" iicount="1"/>
1149                     //   <call method="813" instr="invokevirtual"/>
1150                     //   <inline_success reason="receiver is statically known"/>
1151                     //   <method id="814" holder="792" name="toString" return="695" flags="1" bytes="5" iicount="3"/>
1152                     //   <parse method="814">
1153                     //   ...
1154                     site.setMethod(m);
1155                     scopes.push(site);
1156                 }
1157             }
1158         } else if (qname.equals("parse_done")) {
1159             // Attach collected information about IR nodes to the current
1160             // parsing scope before it's popped off the stack in endElement()
1161             // (see where the parse tag is handled).
1162             CallSite call = scopes.peek();
1163             call.setEndNodes(Integer.parseInt(search(atts, "nodes", "0")));
1164             call.setEndLiveNodes(Integer.parseInt(search(atts, "live", "0")));
1165             call.setTimeStamp(Double.parseDouble(search(atts, "stamp")));
1166         }
1167     }
1168 
1169     /**
1170      * Process the end of a compilation log XML element.<ul>
1171      * <li><b>parse:</b> finish transforming a Java method's bytecode
1172      * instructions to an initial compiler IR graph.</li>
1173      * <li><b>uncommon_trap:</b> record the end of processing an uncommon trap,
1174      * resetting {@link #currentTrap}.</li>
1175      * <li><b>eliminate_lock:</b> record the end of a lock elimination,
1176      * resetting {@link #currentLockElimination}.</li>
1177      * <li><b>late_inline:</b> the closing tag for late_inline does not denote
1178      * the end of a late inlining operation, but the end of the descriptive log
1179      * data given at its beginning. That is, we're now in the position to
1180      * assemble details about the inlining chain (bytecode instruction index in
1181      * caller, called method). The {@link #lateInlining} flag is set to
1182      * {@code true} here. (It will be reset when parsing the inlined methods is
1183      * done; this happens for the successful case in this method as well, when
1184      * {@code parse} elements are processed; and for inlining failures, in
1185      * {@link #startElement()}, when {@code inline_fail} elements are
1186      * processed.)</li>
1187      * <li><b>task:</b> perform cleanup at the end of a compilation. Note that
1188      * the explicit {@code task_done} event is handled in
1189      * {@link #startElement()}.</li>
1190      * </ul>
1191      */
1192     @Override
1193     public void endElement(String uri, String localName, String qname) {
1194         try {
1195             if (qname.equals("parse")) {
1196                 // Finish dealing with the current call scope. If no more are
1197                 // left, no late inlining can be going on.
1198                 scopes.pop();
1199                 if (scopes.size() == 0) {
1200                     lateInlining = false;
1201                 }
1202             } else if (qname.equals("uncommon_trap")) {
1203                 currentTrap = null;
1204             } else if (qname.startsWith("eliminate_lock")) {
1205                 currentLockElimination = null;
1206             } else if (qname.equals("late_inline")) {
1207                 // Populate late inlining info.
1208                 if (scopes.size() != 0) {
1209                     reportInternalError("scopes should be empty for late inline");
1210                 }
1211                 // late inline scopes are specified in reverse order:
1212                 // compiled method should be on top of stack.
1213                 CallSite caller = lateInlineScope.pop();
1214                 Method m = compile.getMethod();
1215                 if (!m.equals(caller.getMethod())) {
1216                     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));
1217                 }
1218 
1219                 // Walk down the inlining chain and assemble bci+callee info.
1220                 // This needs to be converted from caller+bci info contained in
1221                 // the late_inline data.
1222                 CallSite lateInlineSite = compile.getLateInlineCall();
1223                 ArrayDeque<CallSite> thisCallScopes = new ArrayDeque<>();
1224                 do {
1225                     current_bci = caller.getBci();
1226                     // Next inlined call.
1227                     caller = lateInlineScope.pop();
1228                     CallSite callee = new CallSite(current_bci, caller.getMethod());
1229                     callee.setInlineId(caller.getInlineId());
1230                     thisCallScopes.addLast(callee);
1231                     lateInlineSite.add(callee);
1232                     lateInlineSite = callee;
1233                 } while (!lateInlineScope.isEmpty());
1234 
1235                 site = compile.getCall().findCallSite(thisCallScopes);
1236                 if (site == null) {
1237                     // Call site could not be found - report the problem in detail.
1238                     System.err.println("call scopes:");
1239                     for (CallSite c : thisCallScopes) {
1240                         System.err.println(c.getMethod() + " " + c.getBci() + " " + c.getInlineId());
1241                     }
1242                     CallSite c = thisCallScopes.getLast();
1243                     if (c.getInlineId() != 0) {
1244                         System.err.println("Looking for call site in entire tree:");
1245                         ArrayDeque<CallSite> stack = compile.getCall().findCallSite2(c);
1246                         for (CallSite c2 : stack) {
1247                             System.err.println(c2.getMethod() + " " + c2.getBci() + " " + c2.getInlineId());
1248                         }
1249                     }
1250                     System.err.println(caller.getMethod() + " bci: " + current_bci);
1251                     reportInternalError("couldn't find call site");
1252                 }
1253                 lateInlining = true;
1254 
1255                 if (caller.getBci() != -999) {
1256                     System.out.println(caller.getMethod());
1257                     reportInternalError("broken late_inline info");
1258                 }
1259                 if (site.getMethod() != caller.getMethod()) {
1260                     if (site.getInlineId() == caller.getInlineId()) {
1261                         site.setMethod(caller.getMethod());
1262                     } else {
1263                         System.out.println(site.getMethod());
1264                         System.out.println(caller.getMethod());
1265                         reportInternalError("call site and late_inline info don't match");
1266                     }
1267                 }
1268                 // late_inline is followed by parse with scopes.size() == 0,
1269                 // 'site' will be pushed to scopes.
1270                 lateInlineScope = null;
1271             } else if (qname.equals("task")) {
1272                 types.clear();
1273                 methods.clear();
1274                 site = null;
1275             }
1276         } catch (Exception e) {
1277             reportInternalError("exception while processing end element", e);
1278         }
1279     }
1280 
1281     //
1282     // Handlers for problems that occur in XML parsing itself.
1283     //
1284 
1285     @Override
1286     public void warning(org.xml.sax.SAXParseException e) {
1287         System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber());
1288         e.printStackTrace();
1289     }
1290 
1291     @Override
1292     public void error(org.xml.sax.SAXParseException e) {
1293         System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber());
1294         e.printStackTrace();
1295     }
1296 
1297     @Override
1298     public void fatalError(org.xml.sax.SAXParseException e) {
1299         System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber());
1300         e.printStackTrace();
1301     }
1302 }