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