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 }