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.Collections;
37 import java.util.Comparator;
38 import java.util.HashMap;
39 import java.util.LinkedHashMap;
40 import java.util.Stack;
41 import javax.xml.parsers.SAXParser;
42 import javax.xml.parsers.SAXParserFactory;
43 import org.xml.sax.Attributes;
44 import org.xml.sax.ErrorHandler;
45 import org.xml.sax.InputSource;
46 import org.xml.sax.helpers.DefaultHandler;
47
48 public class LogParser extends DefaultHandler implements ErrorHandler, Constants {
49
50 static final HashMap<String, String> typeMap;
51 static {
52 typeMap = new HashMap<String, String>();
53 typeMap.put("[I", "int[]");
54 typeMap.put("[C", "char[]");
55 typeMap.put("[Z", "boolean[]");
56 typeMap.put("[L", "Object[]");
57 typeMap.put("[B", "byte[]");
58 }
59
60 static Comparator<LogEvent> sortByStart = new Comparator<LogEvent>() {
61
62 public int compare(LogEvent a, LogEvent b) {
63 double difference = (a.getStart() - b.getStart());
64 if (difference < 0) {
65 return -1;
66 }
67 if (difference > 0) {
68 return 1;
69 }
70 return 0;
71 }
72
73 @Override
74 public boolean equals(Object other) {
75 return false;
76 }
77
78 @Override
79 public int hashCode() {
80 return 7;
81 }
82 };
83 static Comparator<LogEvent> sortByNameAndStart = new Comparator<LogEvent>() {
84
85 public int compare(LogEvent a, LogEvent b) {
86 Compilation c1 = a.getCompilation();
87 Compilation c2 = b.getCompilation();
88 if (c1 != null && c2 != null) {
89 int result = c1.getMethod().toString().compareTo(c2.getMethod().toString());
90 if (result != 0) {
91 return result;
92 }
93 }
94 double difference = (a.getStart() - b.getStart());
95 if (difference < 0) {
96 return -1;
97 }
98 if (difference > 0) {
99 return 1;
100 }
101 return 0;
102 }
103
104 public boolean equals(Object other) {
105 return false;
106 }
107
108 @Override
109 public int hashCode() {
110 return 7;
111 }
112 };
113 static Comparator<LogEvent> sortByElapsed = new Comparator<LogEvent>() {
114
115 public int compare(LogEvent a, LogEvent b) {
116 double difference = (a.getElapsedTime() - b.getElapsedTime());
117 if (difference < 0) {
118 return -1;
119 }
120 if (difference > 0) {
121 return 1;
122 }
123 return 0;
124 }
125
126 @Override
127 public boolean equals(Object other) {
128 return false;
129 }
130
131 @Override
132 public int hashCode() {
133 return 7;
134 }
135 };
136
137 class Jvms {
138 Jvms(Method method, int bci) {
139 this.method = method;
140 this.bci = bci;
141 }
142 final public Method method;
143 final public int bci;
144 final public String toString() {
145 return "@" + bci + " " + method;
146 }
147 }
148
149 class LockElimination extends BasicLogEvent {
150
151 ArrayList<Jvms> jvms = new ArrayList<Jvms>(1);
152 final String kind;
153 final String classId;
154 final String tagName;
155 LockElimination(String tagName, double start, String id, String kind, String classId) {
156 super(start, id);
157 this.kind = kind;
158 this.classId = classId;
159 this.tagName = tagName;
160 }
161
162 @Override
163 public void print(PrintStream stream) {
164 stream.printf("%s %s %s %s %.3f ", getId(), tagName, kind, classId, getStart());
165 stream.print(jvms.toString());
166 stream.print("\n");
167 }
168
169 void addJVMS(Method method, int bci) {
170 jvms.add(new Jvms(method, bci));
171 }
172
173 }
174
175 private ArrayList<LogEvent> events = new ArrayList<LogEvent>();
176
177 private HashMap<String, String> types = new HashMap<String, String>();
178 private HashMap<String, Method> methods = new HashMap<String, Method>();
179 private LinkedHashMap<String, NMethod> nmethods = new LinkedHashMap<String, NMethod>();
180 private HashMap<String, Compilation> compiles = new HashMap<String, Compilation>();
181 private String failureReason;
182 private int bci;
183 private Stack<CallSite> scopes = new Stack<CallSite>();
184 private Compilation compile;
185 private CallSite site;
186 private CallSite methodHandleSite;
187 private Stack<Phase> phaseStack = new Stack<Phase>();
188 private LockElimination currentLockElimination;
189 private UncommonTrapEvent currentTrap;
190 private Stack<CallSite> lateInlineScope;
191 private boolean lateInlining;
192
193
194 long parseLong(String l) {
195 try {
196 return Long.decode(l).longValue();
197 } catch (NumberFormatException nfe) {
198 int split = l.length() - 8;
199 String s1 = "0x" + l.substring(split);
200 String s2 = l.substring(0, split);
201 long v1 = Long.decode(s1).longValue() & 0xffffffffL;
202 long v2 = (Long.decode(s2).longValue() & 0xffffffffL) << 32;
203 if (!l.equals("0x" + Long.toHexString(v1 + v2))) {
204 System.out.println(l);
205 System.out.println(s1);
206 System.out.println(s2);
207 System.out.println(v1);
208 System.out.println(v2);
209 System.out.println(Long.toHexString(v1 + v2));
210 throw new InternalError("bad conversion");
211 }
212 return v1 + v2;
213 }
214 }
215
216 public static ArrayList<LogEvent> parse(String file, boolean cleanup) throws Exception {
217 return parse(new FileReader(file), cleanup);
218 }
219
220 public static ArrayList<LogEvent> parse(Reader reader, boolean cleanup) throws Exception {
221 // Create the XML input factory
222 SAXParserFactory factory = SAXParserFactory.newInstance();
223
224 // Create the XML LogEvent reader
225 SAXParser p = factory.newSAXParser();
226
227 if (cleanup) {
228 // some versions of the log have slightly malformed XML, so clean it
229 // up before passing it to SAX
230 reader = new LogCleanupReader(reader);
231 }
232
233 LogParser log = new LogParser();
234 try {
235 p.parse(new InputSource(reader), log);
236 } catch (Throwable th) {
237 th.printStackTrace();
238 // Carry on with what we've got...
239 }
240
241 // Associate compilations with their NMethods
242 for (NMethod nm : log.nmethods.values()) {
243 Compilation c = log.compiles.get(nm.getId());
244 nm.setCompilation(c);
245 // Native wrappers for methods don't have a compilation
246 if (c != null) {
247 c.setNMethod(nm);
248 }
249 }
250
251 // Initially we want the LogEvent log sorted by timestamp
252 Collections.sort(log.events, sortByStart);
253
254 return log.events;
255 }
256
257 String search(Attributes attr, String name) {
258 String result = attr.getValue(name);
259 if (result != null) {
260 return result;
261 } else {
262 throw new InternalError("can't find " + name);
263 }
264 }
265
266 String search(Attributes attr, String name, String defaultValue) {
267 String result = attr.getValue(name);
268 if (result != null) {
269 return result;
270 }
271 return defaultValue;
272 }
273 int indent = 0;
274
275 String type(String id) {
276 String result = types.get(id);
277 if (result == null) {
278 throw new InternalError(id);
279 }
280 String remapped = typeMap.get(result);
281 if (remapped != null) {
282 return remapped;
283 }
284 return result;
285 }
286
287 void type(String id, String name) {
288 assert type(id) == null;
289 types.put(id, name);
290 }
291
292 Method method(String id) {
293 Method result = methods.get(id);
294 if (result == null) {
295 throw new InternalError(id);
296 }
297 return result;
298 }
299
300 public String makeId(Attributes atts) {
301 String id = atts.getValue("compile_id");
302 String kind = atts.getValue("kind");
303 if (kind != null && kind.equals("osr")) {
304 id += "%";
305 }
306 return id;
307 }
308
309 @Override
310 public void startElement(String uri,
311 String localName,
312 String qname,
313 Attributes atts) {
314 if (qname.equals("phase")) {
315 Phase p = new Phase(search(atts, "name"),
316 Double.parseDouble(search(atts, "stamp")),
317 Integer.parseInt(search(atts, "nodes", "0")),
318 Integer.parseInt(search(atts, "live", "0")));
319 phaseStack.push(p);
320 } else if (qname.equals("phase_done")) {
321 Phase p = phaseStack.pop();
322 String phaseName = search(atts, "name", null);
323 if (phaseName != null && !p.getId().equals(phaseName)) {
324 System.out.println("phase: " + p.getId());
325 throw new InternalError("phase name mismatch");
326 }
327 p.setEnd(Double.parseDouble(search(atts, "stamp")));
328 p.setEndNodes(Integer.parseInt(search(atts, "nodes", "0")));
329 p.setEndLiveNodes(Integer.parseInt(search(atts, "live", "0")));
330 compile.getPhases().add(p);
331 } else if (qname.equals("task")) {
332 compile = new Compilation(Integer.parseInt(search(atts, "compile_id", "-1")));
333 compile.setStart(Double.parseDouble(search(atts, "stamp")));
334 compile.setICount(search(atts, "count", "0"));
335 compile.setBCount(search(atts, "backedge_count", "0"));
336
337 String method = atts.getValue("method");
338 int space = method.indexOf(' ');
339 method = method.substring(0, space) + "::" +
340 method.substring(space + 1, method.indexOf(' ', space + 1) + 1);
341 String compiler = atts.getValue("compiler");
342 if (compiler == null) {
343 compiler = "";
344 }
345 String kind = atts.getValue("compile_kind");
346 if (kind == null) {
347 kind = "normal";
348 }
349 if (kind.equals("osr")) {
350 compile.setOsr(true);
351 compile.setOsr_bci(Integer.parseInt(search(atts, "osr_bci")));
352 } else if (kind.equals("c2i")) {
353 compile.setSpecial("--- adapter " + method);
354 } else {
355 compile.setSpecial(compile.getId() + " " + method + " (0 bytes)");
356 }
357 events.add(compile);
358 compiles.put(makeId(atts), compile);
359 site = compile.getCall();
360 } else if (qname.equals("type")) {
361 type(search(atts, "id"), search(atts, "name"));
362 } else if (qname.equals("bc")) {
363 bci = Integer.parseInt(search(atts, "bci"));
364 } else if (qname.equals("klass")) {
365 type(search(atts, "id"), search(atts, "name"));
366 } else if (qname.equals("method")) {
367 String id = search(atts, "id");
368 Method m = new Method();
369 m.setHolder(type(search(atts, "holder")));
370 m.setName(search(atts, "name"));
371 m.setReturnType(type(search(atts, "return")));
372 m.setArguments(search(atts, "arguments", "void"));
373
374 if (search(atts, "unloaded", "0").equals("0")) {
375 m.setBytes(search(atts, "bytes"));
376 m.setIICount(search(atts, "iicount"));
377 m.setFlags(search(atts, "flags"));
378 }
379 methods.put(id, m);
380 } else if (qname.equals("call")) {
381 if (methodHandleSite != null) {
382 methodHandleSite = null;
383 }
384 Method m = method(search(atts, "method"));
385 if (lateInlining && scopes.size() == 0) {
386 // re-attempting already seen call site (late inlining for MH invokes)
387 if (m != site.getMethod()) {
388 if (bci != site.getBci()) {
389 System.out.println(m + " bci: " + bci);
390 System.out.println(site.getMethod() + " bci: " + site.getBci());
391 throw new InternalError("bci mismatch after late inlining");
392 }
393 site.setMethod(m);
394 }
395 } else {
396 site = new CallSite(bci, m);
397 }
398 site.setCount(Integer.parseInt(search(atts, "count", "0")));
399 String receiver = atts.getValue("receiver");
400 if (receiver != null) {
401 site.setReceiver(type(receiver));
402 site.setReceiver_count(Integer.parseInt(search(atts, "receiver_count")));
403 }
404 int methodHandle = Integer.parseInt(search(atts, "method_handle_intrinsic", "0"));
405 if (lateInlining && scopes.size() == 0) {
406 // The call was added before this round of late inlining
407 } else if (methodHandle == 0) {
408 scopes.peek().add(site);
409 } else {
410 // method handle call site can be followed by another
411 // call (in case it is inlined). If that happens we
412 // discard the method handle call site. So we keep
413 // track of it but don't add it to the list yet.
414 methodHandleSite = site;
415 }
416 } else if (qname.equals("regalloc")) {
417 compile.setAttempts(Integer.parseInt(search(atts, "attempts")));
418 } else if (qname.equals("inline_fail")) {
419 if (methodHandleSite != null) {
420 scopes.peek().add(methodHandleSite);
421 methodHandleSite = null;
422 }
423 if (lateInlining && scopes.size() == 0) {
424 site.setReason(search(atts, "reason"));
425 lateInlining = false;
426 } else {
427 scopes.peek().last().setReason(search(atts, "reason"));
428 }
429 } else if (qname.equals("inline_success")) {
430 if (methodHandleSite != null) {
431 throw new InternalError("method handle site should have been replaced");
432 }
433 if (lateInlining && scopes.size() == 0) {
434 site.setReason(null);
435 }
436 } else if (qname.equals("failure")) {
437 failureReason = search(atts, "reason");
438 } else if (qname.equals("task_done")) {
439 compile.setEnd(Double.parseDouble(search(atts, "stamp")));
440 if (Integer.parseInt(search(atts, "success")) == 0) {
441 compile.setFailureReason(failureReason);
442 failureReason = null;
443 }
444 } else if (qname.equals("make_not_entrant")) {
445 String id = makeId(atts);
446 NMethod nm = nmethods.get(id);
447 if (nm == null) throw new InternalError();
448 LogEvent e = new MakeNotEntrantEvent(Double.parseDouble(search(atts, "stamp")), id,
449 atts.getValue("zombie") != null, nm);
450 events.add(e);
451 } else if (qname.equals("uncommon_trap")) {
452 String id = atts.getValue("compile_id");
453 if (id != null) {
454 id = makeId(atts);
455 currentTrap = new UncommonTrapEvent(Double.parseDouble(search(atts, "stamp")),
456 id,
457 atts.getValue("reason"),
458 atts.getValue("action"),
459 Integer.parseInt(search(atts, "count", "0")));
460 events.add(currentTrap);
461 } else {
462 // uncommon trap inserted during parsing.
463 // ignore for now
464 }
465 } else if (qname.startsWith("eliminate_lock")) {
466 String id = atts.getValue("compile_id");
467 if (id != null) {
468 id = makeId(atts);
469 String kind = atts.getValue("kind");
470 String classId = atts.getValue("class_id");
471 currentLockElimination = new LockElimination(qname, Double.parseDouble(search(atts, "stamp")), id, kind, classId);
472 events.add(currentLockElimination);
473 }
474 } else if (qname.equals("late_inline")) {
475 long inlineId = 0;
476 try {
477 Long.parseLong(search(atts, "inline_id"));
478 } catch (InternalError ex) {
479 // 0 is an acceptable default value.
480 }
481 lateInlineScope = new Stack<CallSite>();
482 site = new CallSite(-999, method(search(atts, "method")));
483 site.setInlineId(inlineId);
484 lateInlineScope.push(site);
485 } else if (qname.equals("jvms")) {
486 // <jvms bci='4' method='java/io/DataInputStream readChar ()C' bytes='40' count='5815' iicount='20815'/>
487 if (currentTrap != null) {
488 currentTrap.addJVMS(atts.getValue("method"), Integer.parseInt(atts.getValue("bci")));
489 } else if (currentLockElimination != null) {
490 currentLockElimination.addJVMS(method(atts.getValue("method")), Integer.parseInt(atts.getValue("bci")));
491 } else if (lateInlineScope != null) {
492 bci = Integer.parseInt(search(atts, "bci"));
493 site = new CallSite(bci, method(search(atts, "method")));
494 lateInlineScope.push(site);
495 } else {
496 // Ignore <eliminate_allocation type='667'>,
497 // <eliminate_lock lock='1'>,
498 // <replace_string_concat arguments='2' string_alloc='0' multiple='0'>
499 }
500 } else if (qname.equals("inline_id")) {
501 if (methodHandleSite != null) {
502 throw new InternalError("method handle site should have been replaced");
503 }
504 long id = Long.parseLong(search(atts, "id"));
505 site.setInlineId(id);
506 } else if (qname.equals("nmethod")) {
507 String id = makeId(atts);
508 NMethod nm = new NMethod(Double.parseDouble(search(atts, "stamp")),
509 id,
510 parseLong(atts.getValue("address")),
511 parseLong(atts.getValue("size")));
512 nmethods.put(id, nm);
513 events.add(nm);
514 } else if (qname.equals("parse")) {
515 if (failureReason != null && scopes.size() == 0 && !lateInlining) {
516 failureReason = null;
517 compile.reset();
518 site = compile.getCall();
519 }
520
521 if (methodHandleSite != null) {
522 throw new InternalError("method handle site should have been replaced");
523 }
524 Method m = method(search(atts, "method"));
525 if (lateInlining && scopes.size() == 0) {
526 if (site.getMethod() != m) {
527 System.out.println(site.getMethod());
528 System.out.println(m);
529 throw new InternalError("Unexpected method mismatch during late inlining");
530 }
531 }
532 if (scopes.size() == 0 && !lateInlining) {
533 compile.setMethod(m);
534 scopes.push(site);
535 } else {
536 if (site.getMethod() == m) {
537 scopes.push(site);
538 } else if (scopes.peek().getCalls().size() > 2 && m == scopes.peek().last(-2).getMethod()) {
539 scopes.push(scopes.peek().last(-2));
540 } else {
541 // C1 prints multiple method tags during inlining when it narrows method being inlinied.
542 // Example:
543 // ...
544 // <method id="813" holder="694" name="toString" return="695" flags="1" bytes="36" iicount="1"/>
545 // <call method="813" instr="invokevirtual"/>
546 // <inline_success reason="receiver is statically known"/>
547 // <method id="814" holder="792" name="toString" return="695" flags="1" bytes="5" iicount="3"/>
548 // <parse method="814">
549 // ...
550 site.setMethod(m);
551 scopes.push(site);
552 }
553 }
554 } else if (qname.equals("parse_done")) {
555 CallSite call = scopes.pop();
556 call.setEndNodes(Integer.parseInt(search(atts, "nodes", "0")));
557 call.setEndLiveNodes(Integer.parseInt(search(atts, "live", "0")));
558 call.setTimeStamp(Double.parseDouble(search(atts, "stamp")));
559 scopes.push(call);
560 }
561 }
562
563 @Override
564 public void endElement(String uri,
565 String localName,
566 String qname) {
567 if (qname.equals("parse")) {
568 indent -= 2;
569 scopes.pop();
570 if (scopes.size() == 0) {
571 lateInlining = false;
572 }
573 } else if (qname.equals("uncommon_trap")) {
574 currentTrap = null;
575 } else if (qname.startsWith("eliminate_lock")) {
576 currentLockElimination = null;
577 } else if (qname.equals("late_inline")) {
578 // Populate late inlining info.
579 if (scopes.size() != 0) {
580 throw new InternalError("scopes should be empty for late inline");
581 }
582 // late inline scopes are specified in reverse order:
583 // compiled method should be on top of stack.
584 CallSite caller = lateInlineScope.pop();
585 Method m = compile.getMethod();
586 if (m != caller.getMethod()) {
587 System.err.println(m);
588 System.err.println(caller.getMethod() + " bci: " + bci);
589 throw new InternalError("call site and late_inline info don't match");
590 }
591
592 // late_inline contains caller+bci info, convert it
593 // to bci+callee info used by LogCompilation.
594 CallSite lateInlineSite = compile.getLateInlineCall();
595 ArrayDeque<CallSite> thisCallScopes = new ArrayDeque<CallSite>();
596 do {
597 bci = caller.getBci();
598 // Next inlined call.
599 caller = lateInlineScope.pop();
600 CallSite callee = new CallSite(bci, caller.getMethod());
601 callee.setInlineId(caller.getInlineId());
602 thisCallScopes.addLast(callee);
603 lateInlineSite.add(callee);
604 lateInlineSite = callee;
605 } while (!lateInlineScope.empty());
606
607 site = compile.getCall().findCallSite(thisCallScopes);
608 if (site == null) {
609 System.out.println("call scopes:");
610 for (CallSite c : thisCallScopes) {
611 System.out.println(c.getMethod() + " " + c.getBci() + " " + c.getInlineId());
612 }
613 CallSite c = thisCallScopes.getLast();
614 if (c.getInlineId() != 0) {
615 System.out.println("Looking for call site in entire tree:");
616 ArrayDeque<CallSite> stack = compile.getCall().findCallSite2(c);
617 for (CallSite c2 : stack) {
618 System.out.println(c2.getMethod() + " " + c2.getBci() + " " + c2.getInlineId());
619 }
620 }
621 System.out.println(caller.getMethod() + " bci: " + bci);
622 throw new InternalError("couldn't find call site");
623 }
624 lateInlining = true;
625
626 if (caller.getBci() != -999) {
627 System.out.println(caller.getMethod());
628 throw new InternalError("broken late_inline info");
629 }
630 if (site.getMethod() != caller.getMethod()) {
631 if (site.getInlineId() == caller.getInlineId()) {
632 site.setMethod(caller.getMethod());
633 } else {
634 System.out.println(site.getMethod());
635 System.out.println(caller.getMethod());
636 throw new InternalError("call site and late_inline info don't match");
637 }
638 }
639 // late_inline is followed by parse with scopes.size() == 0,
640 // 'site' will be pushed to scopes.
641 lateInlineScope = null;
642 } else if (qname.equals("task")) {
643 types.clear();
644 methods.clear();
645 site = null;
646 }
647 }
648
649 @Override
650 public void warning(org.xml.sax.SAXParseException e) {
651 System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber());
652 e.printStackTrace();
653 }
654
655 @Override
656 public void error(org.xml.sax.SAXParseException e) {
657 System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber());
658 e.printStackTrace();
659 }
660
661 @Override
662 public void fatalError(org.xml.sax.SAXParseException e) {
663 System.err.println(e.getMessage() + " at line " + e.getLineNumber() + ", column " + e.getColumnNumber());
664 e.printStackTrace();
665 }
666 }