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 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 }