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 package com.sun.hotspot.tools.compiler;
26
27 import java.io.ByteArrayOutputStream;
28 import java.io.File;
29 import java.io.FileNotFoundException;
30 import java.io.FileOutputStream;
31 import java.io.PrintStream;
32 import java.util.*;
33
34 import org.xml.sax.*;
35 import org.xml.sax.helpers.*;
36
37 /**
38 * The LogCompilation tool parses log files generated by HotSpot using the
39 * {@code -XX:+LogCompilation} command line flag, and outputs the data
40 * collected therein in a nicely formatted way. There are various sorting
41 * options available, as well as options that select specific compilation
42 * events (such as inlining decisions) for inclusion in the output.
43 *
44 * The tool is also capable of fixing broken compilation logs as sometimes
45 * generated by Java 1.5 JVMs.
46 */
47 public class LogCompilation extends DefaultHandler implements ErrorHandler {
48
49 /**
50 * Print usage information and terminate with a given exit code.
51 */
52 public static void usage(int exitcode) {
53 System.out.println("Usage: LogCompilation [ -v ] [ -c ] [ -s ] [ -e | -n ] file1 ...");
54 System.out.println("By default, the tool will print the logged compilations ordered by start time.");
55 System.out.println(" -c: clean up malformed 1.5 xml");
56 System.out.println(" -i: print inlining decisions");
57 System.out.println(" -S: print compilation statistics");
58 System.out.println(" -U: print uncommon trap statistics");
59 System.out.println(" -t: print with time stamps");
60 System.out.println(" -s: sort events by start time (default)");
61 System.out.println(" -e: sort events by elapsed time");
62 System.out.println(" -n: sort events by name and start");
63 System.out.println(" -C: compare logs (give files to compare on command line)");
64 System.out.println(" -d: do not print compilation IDs");
65 System.exit(exitcode);
66 }
67
68 /**
69 * Process command line arguments, parse log files and trigger desired
70 * functionality.
71 */
72 public static void main(String[] args) throws Exception {
73 Comparator<LogEvent> sort = LogParser.sortByStart;
74 boolean statistics = false;
75 boolean printInlining = false;
76 boolean cleanup = false;
77 boolean trapHistory = false;
78 boolean printTimeStamps = false;
79 boolean compare = false;
80 boolean printID = true;
81 int index = 0;
82
83 while (args.length > index) {
84 String a = args[index];
85 if (a.equals("-e")) {
86 sort = LogParser.sortByElapsed;
87 index++;
88 } else if (a.equals("-n")) {
89 sort = LogParser.sortByNameAndStart;
90 index++;
91 } else if (a.equals("-s")) {
92 sort = LogParser.sortByStart;
93 index++;
94 } else if (a.equals("-t")) {
95 printTimeStamps = true;
96 index++;
97 } else if (a.equals("-c")) {
98 cleanup = true;
99 index++;
100 } else if (a.equals("-S")) {
101 statistics = true;
102 index++;
103 } else if (a.equals("-U")) {
104 trapHistory = true;
105 index++;
106 } else if (a.equals("-h")) {
107 usage(0);
108 } else if (a.equals("-i")) {
109 printInlining = true;
110 index++;
111 } else if (a.equals("-C")) {
112 compare = true;
113 index++;
114 } else if (a.equals("-d")) {
115 printID = false;
116 index++;
117 } else {
118 if (a.charAt(0) == '-') {
119 System.out.println("Unknown option '" + a + "', assuming file name.");
120 }
121 break;
122 }
123 }
124
125 if (index >= args.length) {
126 usage(1);
127 }
128
129 if (compare) {
130 compareLogs(index, args);
131 return;
132 }
133
134 while (index < args.length) {
135 ArrayList<LogEvent> events = null;
136 try {
137 events = LogParser.parse(args[index], cleanup);
138 } catch (FileNotFoundException fnfe) {
139 System.out.println("File not found: " + args[index]);
140 System.exit(1);
141 }
142
143 Collections.sort(events, sort);
144
145 if (statistics) {
146 printStatistics(events, System.out);
147 } else if (trapHistory) {
148 printTrapHistory(events, System.out);
149 } else {
150 for (LogEvent c : events) {
151 if (c instanceof NMethod) {
152 // skip these
153 continue;
154 }
155 if (printTimeStamps) {
156 System.out.print(c.getStart() + ": ");
157 }
158 if (c instanceof Compilation) {
159 Compilation comp = (Compilation) c;
160 comp.print(System.out, printID, printInlining);
161 } else {
162 c.print(System.out, printID);
163 }
164 }
165 }
166 index++;
167 }
168 }
169
170 /**
171 * Print extensive statistics from parsed log files.
172 */
173 public static void printStatistics(ArrayList<LogEvent> events, PrintStream out) {
174 // track code cache size
175 long cacheSize = 0;
176 long maxCacheSize = 0;
177 // track number of nmethods
178 int nmethodsCreated = 0;
179 int nmethodsLive = 0;
180 // track how many compilations were attempted multiple times
181 // (indexed by attempts, mapping to number of compilations)
182 int[] attempts = new int[32];
183 int maxattempts = 0;
184
185 // track time spent in compiler phases
186 LinkedHashMap<String, Double> phaseTime = new LinkedHashMap<>(7);
187 // track nodes created per phase
188 LinkedHashMap<String, Integer> phaseNodes = new LinkedHashMap<>(7);
189 double elapsed = 0;
190
191 for (LogEvent e : events) {
192 if (e instanceof Compilation) {
193 Compilation c = (Compilation) e;
194 c.printShort(out);
195 out.printf(" %6.4f\n", c.getElapsedTime());
196 attempts[c.getAttempts()]++;
197 maxattempts = Math.max(maxattempts,c.getAttempts());
198 elapsed += c.getElapsedTime();
199 for (Phase phase : c.getPhases()) {
200 Double v = phaseTime.get(phase.getName());
201 if (v == null) {
202 v = Double.valueOf(0.0);
203 }
204 phaseTime.put(phase.getName(), Double.valueOf(v.doubleValue() + phase.getElapsedTime()));
205
206 Integer v2 = phaseNodes.get(phase.getName());
207 if (v2 == null) {
208 v2 = Integer.valueOf(0);
209 }
210 phaseNodes.put(phase.getName(), Integer.valueOf(v2.intValue() + phase.getNodes()));
211 // Print phase name, elapsed time, nodes at the start of
212 // the phase, nodes created in the phase, live nodes at the
213 // start of the phase, live nodes added in the phase.
214 out.printf("\t%s %6.4f %d %d %d %d\n", phase.getName(), phase.getElapsedTime(), phase.getStartNodes(), phase.getNodes(), phase.getStartLiveNodes(), phase.getAddedLiveNodes());
215 }
216 } else if (e instanceof MakeNotEntrantEvent) {
217 MakeNotEntrantEvent mne = (MakeNotEntrantEvent) e;
218 NMethod nm = mne.getNMethod();
219 if (mne.isZombie()) {
220 if (nm == null) {
221 System.err.println("zombie make not entrant event without nmethod: " + mne.getId());
222 }
223 cacheSize -= nm.getSize();
224 nmethodsLive--;
225 }
226 } else if (e instanceof NMethod) {
227 nmethodsLive++;
228 nmethodsCreated++;
229 NMethod nm = (NMethod) e;
230 cacheSize += nm.getSize();
231 maxCacheSize = Math.max(cacheSize, maxCacheSize);
232 }
233 }
234 out.printf("NMethods: %d created %d live %d bytes (%d peak) in the code cache\n", nmethodsCreated, nmethodsLive, cacheSize, maxCacheSize);
235 out.println("Phase times:");
236 for (String name : phaseTime.keySet()) {
237 Double v = phaseTime.get(name);
238 Integer v2 = phaseNodes.get(name);
239 out.printf("%20s %6.4f %d\n", name, v.doubleValue(), v2.intValue());
240 }
241 out.printf("%20s %6.4f\n", "total", elapsed);
242
243 if (maxattempts > 0) {
244 out.println("Distribution of regalloc passes:");
245 for (int i = 0; i <= maxattempts; i++) {
246 out.printf("%2d %8d\n", i, attempts[i]);
247 }
248 }
249 }
250
251 /**
252 * Container class for a pair of a method and a bytecode instruction index
253 * used by a compiler. This is used in
254 * {@linkplain #compareLogs() comparing logs}.
255 */
256 static class MethodBCIPair {
257 public MethodBCIPair(Method m, int b, String c) {
258 method = m;
259 bci = b;
260 compiler = c;
261 }
262
263 Method method;
264 int bci;
265 String compiler;
266
267 public boolean equals(Object other) {
268 if (!(other instanceof MethodBCIPair)) {
269 return false;
270 }
271 MethodBCIPair otherp = (MethodBCIPair)other;
272 return (otherp.bci == bci &&
273 otherp.method.equals(method) &&
274 otherp.compiler.equals(compiler));
275 }
276
277 public int hashCode() {
278 return method.hashCode() + bci;
279 }
280
281 public String toString() {
282 if (bci != -1) {
283 return method + "@" + bci + " (" + compiler + ")";
284 } else {
285 return method + " (" + compiler + ")";
286 }
287 }
288 }
289
290 /**
291 * Compare a number of compilation log files. Each of the logs is parsed,
292 * and all compilations found therein are written to a sorted file (prefix
293 * {@code sorted-}. A summary is written to a new file {@code summary.txt}.
294 *
295 * @param index the index in the command line arguments at which to start
296 * looking for files to compare.
297 * @param args the command line arguments with which {@link LogCompilation}
298 * was originally invoked.
299 *
300 * @throws Exception in case any exceptions are thrown in the called
301 * methods.
302 */
303 @SuppressWarnings("unchecked")
304 static void compareLogs(int index, String[] args) throws Exception {
305 HashMap<MethodBCIPair,MethodBCIPair> methods = new HashMap<>();
306 ArrayList<HashMap<MethodBCIPair,Object>> logs = new ArrayList<>();
307 PrintStream[] outs = new PrintStream[args.length - index];
308 PrintStream summary = new PrintStream(new FileOutputStream("summary.txt"));
309 int o = 0;
310 // Process all logs given on the command line: collect compilation
311 // data; in particular, method/bci pairs.
312 while (index < args.length) {
313 String basename = new File(args[index]).getName();
314 String outname = "sorted-" + basename;
315 System.out.println("Sorting " + basename + " to " + outname);
316 outs[o] = new PrintStream(new FileOutputStream(outname));
317 o++;
318 System.out.println("Parsing " + args[index]);
319 ArrayList<LogEvent> events = LogParser.parse(args[index], false);
320 HashMap<MethodBCIPair,Object> compiles = new HashMap<>();
321 logs.add(compiles);
322 for (LogEvent c : events) {
323 if (c instanceof Compilation) {
324 Compilation comp = (Compilation) c;
325 MethodBCIPair key = new MethodBCIPair(comp.getMethod(), comp.getBCI(),
326 comp.getCompiler());
327 MethodBCIPair e = methods.get(key);
328 if (e == null) {
329 methods.put(key, key);
330 } else {
331 key = e;
332 }
333 Object other = compiles.get(key);
334 if (other == null) {
335 compiles.put(key, comp);
336 } else {
337 if (!(other instanceof List)) {
338 List<Object> l = new LinkedList<>();
339 l.add(other);
340 l.add(comp);
341 compiles.put(key, l);
342 } else {
343 List<Object> l = (List<Object>) other;
344 l.add(comp);
345 }
346 }
347 }
348 }
349 index++;
350 }
351
352 // Process the collected method/bci pairs and write the output.
353 for (MethodBCIPair pair : methods.keySet()) {
354 summary.print(pair + " ");
355 int base = -1;
356 String first = null;
357 boolean mismatch = false;
358 boolean different = false;
359 String[] output = new String[outs.length];
360 o = 0;
361 for (HashMap<MethodBCIPair,Object> set : logs) {
362 Object e = set.get(pair);
363 String thisone = null;
364 Compilation lastc = null;
365 int n;
366 if (e == null) {
367 n = 0;
368 } else if (e instanceof Compilation) {
369 n = 1;
370 lastc = (Compilation) e;
371 } else {
372 // Compare the last compilation that was done for this method
373 n = ((List<Object>) e).size();
374 lastc = (Compilation) ((List<Object>) e).get(n - 1);
375 }
376 if (lastc != null) {
377 n = 1;
378 ByteArrayOutputStream baos = new ByteArrayOutputStream();
379 PrintStream ps = new PrintStream(baos);
380 lastc.print(ps, false);
381 ps.close();
382 thisone = new String(baos.toByteArray());
383 }
384 if (base == -1) {
385 base = n;
386 } else if (base != n) {
387 mismatch = true;
388 }
389 output[o++] = thisone;
390 if (thisone != null) {
391 if (first == null) {
392 first = thisone;
393 } else {
394 if (!first.equals(thisone)) {
395 different = true;
396 }
397 }
398 }
399 if (different) {
400 summary.print(n + "d ");
401 } else {
402 summary.print(n + " ");
403 }
404 }
405 if (mismatch) {
406 summary.print("mismatch");
407 }
408 summary.println();
409 if (different) {
410 for (int i = 0; i < outs.length; i++) {
411 if (output[i] != null) {
412 outs[i].println(output[i]);
413 }
414 }
415 }
416 }
417 for (int i = 0; i < outs.length; i++) {
418 outs[i].close();
419 }
420 if (summary != System.out) {
421 summary.close();
422 }
423 }
424
425 /**
426 * Print the history of uncommon trap events.
427 */
428 public static void printTrapHistory(ArrayList<LogEvent> events, PrintStream out) {
429 // map method names to a list of log events
430 LinkedHashMap<String, ArrayList<LogEvent>> traps = new LinkedHashMap<>();
431 // map compilation IDs to compilations
432 HashMap<Integer, Compilation> comps = new HashMap<>();
433
434 // First, iterate over all logged events, collecting data about
435 // uncommon trap events.
436 for (LogEvent e : events) {
437 if (e instanceof NMethod) {
438 // skip these
439 continue;
440 }
441 if (e instanceof Compilation) {
442 Compilation c = (Compilation) e;
443 String name = c.getMethod().getFullName();
444 ArrayList<LogEvent> elist = traps.get(name);
445 if (elist != null && comps.get(c.getId()) == null) {
446 comps.put(c.getId(), c);
447 // If there were previous events for the method
448 // then keep track of later compiles too.
449 elist.add(c);
450 }
451 continue;
452 }
453 if (e instanceof BasicLogEvent) {
454 BasicLogEvent ble = (BasicLogEvent) e;
455 Compilation c = ble.getCompilation();
456 if (c == null) {
457 if (!(ble instanceof NMethod)) {
458 throw new InternalError("only nmethods should have a null compilation; here's a " + ble.getClass());
459 }
460 continue;
461 }
462 String name = c.getMethod().getFullName();
463 ArrayList<LogEvent> elist = traps.get(name);
464 if (elist == null) {
465 elist = new ArrayList<LogEvent>();
466 traps.put(name, elist);
467 }
468 int bleId = Integer.parseInt(ble.getId());
469 if (comps.get(bleId) == null) {
470 comps.put(bleId, c);
471 // Add the associated compile to the list. It
472 // will likely go at the end but we need to search
473 // backwards for the proper insertion point.
474 double start = c.getStart();
475 int ipoint = 0;
476 while (ipoint < elist.size() && elist.get(ipoint).getStart() < start) {
477 ipoint++;
478 }
479 if (ipoint == elist.size()) {
480 elist.add(c);
481 } else {
482 elist.add(ipoint, c);
483 }
484 }
485 elist.add(ble);
486 }
487 }
488
489 // Second, iterate over collected traps and output information.
490 for (String c: traps.keySet()) {
491 ArrayList<LogEvent> elist = traps.get(c);
492 String name = ((Compilation) elist.get(0)).getMethod().getFullName();
493 System.out.println(name);
494 double start = 0;
495 for (LogEvent e: elist) {
496 if (start > e.getStart() && e.getStart() != 0) {
497 throw new InternalError("wrong sorting order for traps");
498 }
499 start = e.getStart();
500 out.print(e.getStart() + ": ");
501 if (e instanceof Compilation) {
502 ((Compilation) e).print(out, true, true, true);
503 } else {
504 e.print(out, true);
505 }
506 }
507 out.println();
508 }
509 }
510
511 }