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 29package com.sun.hotspot.tools.compiler; 30 31import java.io.FileReader; 32import java.io.PrintStream; 33import java.io.Reader; 34import java.util.ArrayDeque; 35import java.util.ArrayList; 36import java.util.Comparator; 37import java.util.Deque; 38import java.util.HashMap; 39import java.util.LinkedHashMap; 40import java.util.regex.Pattern; 41 42import javax.xml.parsers.SAXParser; 43import javax.xml.parsers.SAXParserFactory; 44 45import org.xml.sax.Attributes; 46import org.xml.sax.ErrorHandler; 47import org.xml.sax.InputSource; 48import org.xml.sax.Locator; 49import 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 */ 56public 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("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 if (scopes.size() == 0) { 1029 reportInternalError("scope underflow"); 1030 } 1031 scopes.peek().add(new UncommonTrap(Integer.parseInt(search(atts, "bci")), 1032 search(atts, "reason"), 1033 search(atts, "action"), 1034 bytecodes[current_bytecode])); 1035 } catch (Error e) { 1036 e.printStackTrace(); 1037 } 1038 } 1039 } else if (qname.startsWith("eliminate_lock")) { 1040 String id = atts.getValue("compile_id"); 1041 if (id != null) { 1042 id = makeId(atts); 1043 String kind = atts.getValue("kind"); 1044 String classId = atts.getValue("class_id"); 1045 currentLockElimination = new LockElimination(qname, Double.parseDouble(search(atts, "stamp")), id, kind, classId); 1046 events.add(currentLockElimination); 1047 } 1048 } else if (qname.equals("late_inline")) { 1049 long inlineId = 0; 1050 try { 1051 inlineId = Long.parseLong(search(atts, "inline_id")); 1052 } catch (InternalError ex) { 1053 // Log files from older hotspots may lack inline_id, 1054 // and zero is an acceptable substitute that allows processing to continue. 1055 } 1056 lateInlineScope = new ArrayDeque<>(); 1057 Method m = method(search(atts, "method")); 1058 site = new CallSite(-999, m); 1059 site.setInlineId(inlineId); 1060 lateInlineScope.push(site); 1061 } else if (qname.equals("jvms")) { 1062 // <jvms bci='4' method='java/io/DataInputStream readChar ()C' bytes='40' count='5815' iicount='20815'/> 1063 if (currentTrap != null) { 1064 String[] parts = spacePattern.split(atts.getValue("method")); 1065 currentTrap.addMethodAndBCI(parts[0].replace('/', '.') + '.' + parts[1] + parts[2], Integer.parseInt(atts.getValue("bci"))); 1066 } else if (currentLockElimination != null) { 1067 currentLockElimination.addJVMS(method(atts.getValue("method")), Integer.parseInt(atts.getValue("bci"))); 1068 } else if (lateInlineScope != null) { 1069 current_bci = Integer.parseInt(search(atts, "bci")); 1070 Method m = method(search(atts, "method")); 1071 site = new CallSite(current_bci, m); 1072 lateInlineScope.push(site); 1073 } else { 1074 // Ignore <eliminate_allocation type='667'>, 1075 // <replace_string_concat arguments='2' string_alloc='0' multiple='0'> 1076 } 1077 } else if (qname.equals("inline_id")) { 1078 if (methodHandleSite != null) { 1079 reportInternalError("method handle site should have been replaced"); 1080 } 1081 long id = Long.parseLong(search(atts, "id")); 1082 site.setInlineId(id); 1083 } else if (qname.equals("nmethod")) { 1084 String id = makeId(atts); 1085 NMethod nm = new NMethod(Double.parseDouble(search(atts, "stamp")), 1086 id, 1087 parseLong(atts.getValue("address")), 1088 parseLong(atts.getValue("size"))); 1089 nmethods.put(id, nm); 1090 events.add(nm); 1091 } else if (qname.equals("parse")) { 1092 if (failureReason != null && scopes.size() == 0 && !lateInlining) { 1093 // A compilation just failed, and we're back at a top 1094 // compilation scope. 1095 failureReason = null; 1096 compile.reset(); 1097 site = compile.getCall(); 1098 } 1099 1100 // Error checking. 1101 if (methodHandleSite != null) { 1102 reportInternalError("method handle site should have been replaced"); 1103 } 1104 Method m = method(search(atts, "method")); // this is the method being parsed 1105 if (lateInlining && scopes.size() == 0) { 1106 if (site.getMethod() != m) { 1107 reportInternalError("Unexpected method mismatch during late inlining (method at call site: " + 1108 site.getMethod() + ", method being parsed: " + m + ")"); 1109 } 1110 } 1111 1112 if (scopes.size() == 0 && !lateInlining) { 1113 // The method being parsed is actually the method being 1114 // compiled; i.e., we're dealing with a compilation top scope, 1115 // which we must consequently push to the scopes stack. 1116 compile.setMethod(m); 1117 scopes.push(site); 1118 } else { 1119 // The method being parsed is *not* the current compilation's 1120 // top scope; i.e., we're dealing with an actual call site 1121 // in the top scope or somewhere further down a call stack. 1122 if (site.getMethod() == m) { 1123 // We're dealing with monomorphic inlining that didn't have 1124 // to be narrowed down, because the receiver was known 1125 // beforehand. 1126 scopes.push(site); 1127 } else if (scopes.peek().getCalls().size() > 2 && m == scopes.peek().lastButOne().getMethod()) { 1128 // We're dealing with an at least bimorphic call site, and 1129 // the compiler has now decided to parse the last-but-one 1130 // method. The last one may already have been parsed for 1131 // inlining. 1132 scopes.push(scopes.peek().lastButOne()); 1133 } else { 1134 // The method has been narrowed down to the one we're now 1135 // going to parse, which is inlined here. It's monomorphic 1136 // inlining, but was not immediately clear as such. 1137 // 1138 // C1 prints multiple method tags during inlining when it 1139 // narrows the method being inlined. Example: 1140 // ... 1141 // <method id="813" holder="694" name="toString" return="695" flags="1" bytes="36" iicount="1"/> 1142 // <call method="813" instr="invokevirtual"/> 1143 // <inline_success reason="receiver is statically known"/> 1144 // <method id="814" holder="792" name="toString" return="695" flags="1" bytes="5" iicount="3"/> 1145 // <parse method="814"> 1146 // ... 1147 site.setMethod(m); 1148 scopes.push(site); 1149 } 1150 } 1151 } else if (qname.equals("parse_done")) { 1152 // Attach collected information about IR nodes to the current 1153 // parsing scope before it's popped off the stack in endElement() 1154 // (see where the parse tag is handled). 1155 CallSite call = scopes.peek(); 1156 call.setEndNodes(Integer.parseInt(search(atts, "nodes", "0"))); 1157 call.setEndLiveNodes(Integer.parseInt(search(atts, "live", "0"))); 1158 call.setTimeStamp(Double.parseDouble(search(atts, "stamp"))); 1159 } 1160 } 1161 1162 /** 1163 * Process the end of a compilation log XML element.<ul> 1164 * <li><b>parse:</b> finish transforming a Java method's bytecode 1165 * instructions to an initial compiler IR graph.</li> 1166 * <li><b>uncommon_trap:</b> record the end of processing an uncommon trap, 1167 * resetting {@link #currentTrap}.</li> 1168 * <li><b>eliminate_lock:</b> record the end of a lock elimination, 1169 * resetting {@link #currentLockElimination}.</li> 1170 * <li><b>late_inline:</b> the closing tag for late_inline does not denote 1171 * the end of a late inlining operation, but the end of the descriptive log 1172 * data given at its beginning. That is, we're now in the position to 1173 * assemble details about the inlining chain (bytecode instruction index in 1174 * caller, called method). The {@link #lateInlining} flag is set to 1175 * {@code true} here. (It will be reset when parsing the inlined methods is 1176 * done; this happens for the successful case in this method as well, when 1177 * {@code parse} elements are processed; and for inlining failures, in 1178 * {@link #startElement()}, when {@code inline_fail} elements are 1179 * processed.)</li> 1180 * <li><b>task:</b> perform cleanup at the end of a compilation. Note that 1181 * the explicit {@code task_done} event is handled in 1182 * {@link #startElement()}.</li> 1183 * </ul> 1184 */ 1185 @Override 1186 public void endElement(String uri, String localName, String qname) { 1187 try { 1188 if (qname.equals("parse")) { 1189 // Finish dealing with the current call scope. If no more are 1190 // left, no late inlining can be going on. 1191 scopes.pop(); 1192 if (scopes.size() == 0) { 1193 lateInlining = false; 1194 } 1195 } else if (qname.equals("uncommon_trap")) { 1196 currentTrap = null; 1197 } else if (qname.startsWith("eliminate_lock")) { 1198 currentLockElimination = null; 1199 } else if (qname.equals("late_inline")) { 1200 // Populate late inlining info. 1201 if (scopes.size() != 0) { 1202 reportInternalError("scopes should be empty for late inline"); 1203 } 1204 // late inline scopes are specified in reverse order: 1205 // compiled method should be on top of stack. 1206 CallSite caller = lateInlineScope.pop(); 1207 Method m = compile.getMethod(); 1208 if (!m.equals(caller.getMethod())) { 1209 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)); 1210 } 1211 1212 // Walk down the inlining chain and assemble bci+callee info. 1213 // This needs to be converted from caller+bci info contained in 1214 // the late_inline data. 1215 CallSite lateInlineSite = compile.getLateInlineCall(); 1216 ArrayDeque<CallSite> thisCallScopes = new ArrayDeque<>(); 1217 do { 1218 current_bci = caller.getBci(); 1219 // Next inlined call. 1220 caller = lateInlineScope.pop(); 1221 CallSite callee = new CallSite(current_bci, caller.getMethod()); 1222 callee.setInlineId(caller.getInlineId()); 1223 thisCallScopes.addLast(callee); 1224 lateInlineSite.add(callee); 1225 lateInlineSite = callee; 1226 } while (!lateInlineScope.isEmpty()); 1227 1228 site = compile.getCall().findCallSite(thisCallScopes); 1229 if (site == null) { 1230 // Call site could not be found - report the problem in detail. 1231 System.err.println("call scopes:"); 1232 for (CallSite c : thisCallScopes) { 1233 System.err.println(c.getMethod() + " " + c.getBci() + " " + c.getInlineId()); 1234 } 1235 CallSite c = thisCallScopes.getLast(); 1236 if (c.getInlineId() != 0) { 1237 System.err.println("Looking for call site in entire tree:"); 1238 ArrayDeque<CallSite> stack = compile.getCall().findCallSite2(c); 1239 for (CallSite c2 : stack) { 1240 System.err.println(c2.getMethod() + " " + c2.getBci() + " " + c2.getInlineId()); 1241 } 1242 } 1243 System.err.println(caller.getMethod() + " bci: " + current_bci); 1244 reportInternalError("couldn't find call site"); 1245 } 1246 lateInlining = true; 1247 1248 if (caller.getBci() != -999) { 1249 System.out.println(caller.getMethod()); 1250 reportInternalError("broken late_inline info"); 1251 } 1252 if (site.getMethod() != caller.getMethod()) { 1253 if (site.getInlineId() == caller.getInlineId()) { 1254 site.setMethod(caller.getMethod()); 1255 } else { 1256 System.out.println(site.getMethod()); 1257 System.out.println(caller.getMethod()); 1258 reportInternalError("call site and late_inline info don't match"); 1259 } 1260 } 1261 // late_inline is followed by parse with scopes.size() == 0, 1262 // 'site' will be pushed to scopes. 1263 lateInlineScope = null; 1264 } else if (qname.equals("task")) { 1265 types.clear(); 1266 methods.clear(); 1267 site = null; 1268 } 1269 } catch (Exception e) { 1270 reportInternalError("exception while processing end element", e); 1271 } 1272 } 1273 1274 // 1275 // Handlers for problems that occur in XML parsing itself. 1276 // 1277 1278 @Override 1279 public void warning(org.xml.sax.SAXParseException e) { 1280 System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber()); 1281 e.printStackTrace(); 1282 } 1283 1284 @Override 1285 public void error(org.xml.sax.SAXParseException e) { 1286 System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber()); 1287 e.printStackTrace(); 1288 } 1289 1290 @Override 1291 public void fatalError(org.xml.sax.SAXParseException e) { 1292 System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber()); 1293 e.printStackTrace(); 1294 } 1295} 1296