1 /*
2 * Copyright (c) 2012, 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 package org.graalvm.compiler.debug;
24
25 import static java.util.FormattableFlags.LEFT_JUSTIFY;
26 import static java.util.FormattableFlags.UPPERCASE;
27 import static org.graalvm.compiler.debug.DebugOptions.Count;
28 import static org.graalvm.compiler.debug.DebugOptions.Counters;
29 import static org.graalvm.compiler.debug.DebugOptions.Dump;
30 import static org.graalvm.compiler.debug.DebugOptions.DumpOnError;
31 import static org.graalvm.compiler.debug.DebugOptions.DumpOnPhaseChange;
32 import static org.graalvm.compiler.debug.DebugOptions.ListMetrics;
33 import static org.graalvm.compiler.debug.DebugOptions.Log;
34 import static org.graalvm.compiler.debug.DebugOptions.MemUseTrackers;
35 import static org.graalvm.compiler.debug.DebugOptions.Time;
36 import static org.graalvm.compiler.debug.DebugOptions.Timers;
37 import static org.graalvm.compiler.debug.DebugOptions.TrackMemUse;
38
39 import java.io.ByteArrayOutputStream;
40 import java.io.File;
41 import java.io.IOException;
42 import java.io.PrintStream;
43 import java.nio.file.Files;
44 import java.nio.file.Path;
45 import java.nio.file.Paths;
46 import java.nio.file.StandardOpenOption;
47 import java.util.ArrayList;
48 import java.util.Arrays;
49 import java.util.Collection;
50 import java.util.Collections;
51 import java.util.Formatter;
52 import java.util.List;
53 import java.util.Map;
54 import java.util.SortedMap;
55 import java.util.TreeMap;
56
57 import org.graalvm.compiler.options.OptionKey;
58 import org.graalvm.compiler.options.OptionValues;
59 import org.graalvm.util.EconomicMap;
60 import org.graalvm.util.EconomicSet;
61 import org.graalvm.util.Pair;
62
63 import jdk.vm.ci.meta.JavaMethod;
64
65 /**
66 * A facility for logging and dumping as well as a container for values associated with
67 * {@link MetricKey}s.
68 *
69 * A {@code DebugContext} object must only be used on the thread that created it. This means it
70 * needs to be passed around as a parameter. For convenience, it can be encapsulated in a widely
71 * used object that is in scope wherever a {@code DebugContext} is needed. However, care must be
72 * taken when such objects can be exposed to multiple threads (e.g., they are in a non-thread-local
73 * cache).
74 */
75 public final class DebugContext implements AutoCloseable {
76
77 public static final Description NO_DESCRIPTION = null;
78 public static final GlobalMetrics NO_GLOBAL_METRIC_VALUES = null;
79 public static final Iterable<DebugHandlersFactory> NO_CONFIG_CUSTOMIZERS = Collections.emptyList();
80
81 public static final PrintStream DEFAULT_LOG_STREAM = TTY.out;
82
83 /**
84 * Contains the immutable parts of a debug context. This separation allows the immutable parts
85 * to be shared and reduces the overhead of initialization since most immutable fields are
86 * configured by parsing options.
87 */
88 final Immutable immutable;
89
90 /**
91 * Determines whether metrics are enabled.
92 */
93 boolean metricsEnabled;
94
95 DebugConfig currentConfig;
96 ScopeImpl currentScope;
97 CloseableCounter currentTimer;
98 CloseableCounter currentMemUseTracker;
99 Scope lastClosedScope;
100 Throwable lastExceptionThrown;
101
102 /**
103 * Stores the {@link MetricKey} values.
104 */
105 private long[] metricValues;
106
107 /**
108 * Determines if dynamic scopes are enabled.
109 */
110 public boolean areScopesEnabled() {
111 return immutable.scopesEnabled;
112 }
113
114 /**
115 * The immutable configuration that can be shared between {@link DebugContext} objects.
116 */
117 static final class Immutable {
118
119 private static final Immutable[] CACHE = new Immutable[5];
120
121 /**
122 * The options from which this object was configured.
123 */
124 final OptionValues options;
125
126 /**
127 * Specifies if dynamic scopes are enabled.
128 */
129 final boolean scopesEnabled;
130
131 final boolean listMetrics;
132
133 /**
134 * Names of unscoped counters. A counter is unscoped if this set is empty or contains the
135 * counter's name.
136 */
137 final EconomicSet<String> unscopedCounters;
138
139 /**
140 * Names of unscoped timers. A timer is unscoped if this set is empty or contains the
141 * timer's name.
142 */
143 final EconomicSet<String> unscopedTimers;
144
145 /**
146 * Names of unscoped memory usage trackers. A memory usage tracker is unscoped if this set
147 * is empty or contains the memory usage tracker's name.
148 */
149 final EconomicSet<String> unscopedMemUseTrackers;
150
151 private static EconomicSet<String> parseUnscopedMetricSpec(String spec, boolean unconditional, boolean accumulatedKey) {
152 EconomicSet<String> res;
153 if (spec == null) {
154 if (!unconditional) {
155 res = null;
156 } else {
157 res = EconomicSet.create();
158 }
159 } else {
160 res = EconomicSet.create();
161 if (!spec.isEmpty()) {
162 if (!accumulatedKey) {
163 res.addAll(Arrays.asList(spec.split(",")));
164 } else {
165 for (String n : spec.split(",")) {
166 res.add(n + AccumulatedKey.ACCUMULATED_KEY_SUFFIX);
167 res.add(n + AccumulatedKey.FLAT_KEY_SUFFIX);
168 }
169 }
170
171 }
172 }
173 return res;
174 }
175
176 static Immutable create(OptionValues options) {
177 int i = 0;
178 while (i < CACHE.length) {
179 Immutable immutable = CACHE[i];
180 if (immutable == null) {
181 break;
182 }
183 if (immutable.options == options) {
184 return immutable;
185 }
186 i++;
187 }
188 Immutable immutable = new Immutable(options);
189 if (i < CACHE.length) {
190 CACHE[i] = immutable;
191 }
192 return immutable;
193 }
194
195 private static boolean isNotEmpty(OptionKey<String> option, OptionValues options) {
196 return option.getValue(options) != null && !option.getValue(options).isEmpty();
197 }
198
199 private Immutable(OptionValues options) {
200 this.options = options;
201 String timeValue = Time.getValue(options);
202 String trackMemUseValue = TrackMemUse.getValue(options);
203 this.unscopedCounters = parseUnscopedMetricSpec(Counters.getValue(options), "".equals(Count.getValue(options)), false);
204 this.unscopedTimers = parseUnscopedMetricSpec(Timers.getValue(options), "".equals(timeValue), true);
205 this.unscopedMemUseTrackers = parseUnscopedMetricSpec(MemUseTrackers.getValue(options), "".equals(trackMemUseValue), true);
206
207 if (unscopedTimers != null ||
208 unscopedMemUseTrackers != null ||
209 timeValue != null ||
210 trackMemUseValue != null) {
211 try {
212 Class.forName("java.lang.management.ManagementFactory");
213 } catch (ClassNotFoundException ex) {
214 throw new IllegalArgumentException("Time, Timers, MemUseTrackers and TrackMemUse options require java.management module");
215 }
216 }
217
218 this.scopesEnabled = DumpOnError.getValue(options) ||
219 Dump.getValue(options) != null ||
220 Log.getValue(options) != null ||
221 isNotEmpty(DebugOptions.Count, options) ||
222 isNotEmpty(DebugOptions.Time, options) ||
223 isNotEmpty(DebugOptions.TrackMemUse, options) ||
224 DumpOnPhaseChange.getValue(options) != null;
225 this.listMetrics = ListMetrics.getValue(options);
226 }
227
228 private Immutable() {
229 this.options = new OptionValues(EconomicMap.create());
230 this.unscopedCounters = null;
231 this.unscopedTimers = null;
232 this.unscopedMemUseTrackers = null;
233 this.scopesEnabled = false;
234 this.listMetrics = false;
235 }
236
237 public boolean hasUnscopedMetrics() {
238 return unscopedCounters != null || unscopedTimers != null || unscopedMemUseTrackers != null;
239 }
240 }
241
242 /**
243 * Gets the options this debug context was constructed with.
244 */
245 public OptionValues getOptions() {
246 return immutable.options;
247 }
248
249 static class Activated extends ThreadLocal<DebugContext> {
250 }
251
252 private static final Activated activated = new Activated();
253
254 /**
255 * An object used to undo the changes made by DebugContext#activate().
256 */
257 public static class Activation implements AutoCloseable {
258 private final DebugContext parent;
259
260 Activation(DebugContext parent) {
261 this.parent = parent;
262 }
263
264 @Override
265 public void close() {
266 activated.set(parent);
267 }
268 }
269
270 /**
271 * Activates this object as the debug context {@linkplain DebugContext#forCurrentThread for the
272 * current thread}. This method should be used in a try-with-resources statement.
273 *
274 * @return an object that will deactivate the debug context for the current thread when
275 * {@link Activation#close()} is called on it
276 */
277 public Activation activate() {
278 Activation res = new Activation(activated.get());
279 activated.set(this);
280 return res;
281 }
282
283 /**
284 * Shared object used to represent a disabled debug context.
285 */
286 public static final DebugContext DISABLED = new DebugContext(NO_DESCRIPTION, NO_GLOBAL_METRIC_VALUES, DEFAULT_LOG_STREAM, new Immutable(), NO_CONFIG_CUSTOMIZERS);
287
288 /**
289 * Gets the debug context for the current thread. This should only be used when there is no
290 * other reasonable means to get a hold of a debug context.
291 */
292 public static DebugContext forCurrentThread() {
293 DebugContext current = activated.get();
294 if (current == null) {
295 return DISABLED;
296 }
297 return current;
298 }
299
300 private final GlobalMetrics globalMetrics;
301
302 /**
303 * Describes the computation associated with a {@link DebugContext}.
304 */
305 public static class Description {
306 /**
307 * The primary input to the computation.
308 */
309 final Object compilable;
310
311 /**
312 * A runtime based identifier that is most likely to be unique.
313 */
314 final String identifier;
315
316 public Description(Object compilable, String identifier) {
317 this.compilable = compilable;
318 this.identifier = identifier;
319 }
320
321 @Override
322 public String toString() {
323 String compilableName = compilable instanceof JavaMethod ? ((JavaMethod) compilable).format("%H.%n(%p)%R") : String.valueOf(compilable);
324 return identifier + ":" + compilableName;
325 }
326 }
327
328 private final Description description;
329
330 /**
331 * Gets a description of the computation associated with this debug context.
332 *
333 * @return {@code null} if no description is available
334 */
335 public Description getDescription() {
336 return description;
337 }
338
339 /**
340 * Gets the global metrics associated with this debug context.
341 *
342 * @return {@code null} if no global metrics are available
343 */
344 public GlobalMetrics getGlobalMetrics() {
345 return globalMetrics;
346 }
347
348 /**
349 * Creates a {@link DebugContext} based on a given set of option values and {@code factory}.
350 */
351 public static DebugContext create(OptionValues options, DebugHandlersFactory factory) {
352 return new DebugContext(NO_DESCRIPTION, NO_GLOBAL_METRIC_VALUES, DEFAULT_LOG_STREAM, Immutable.create(options), Collections.singletonList(factory));
353 }
354
355 /**
356 * Creates a {@link DebugContext} based on a given set of option values and {@code factories}.
357 * The {@link DebugHandlersFactory#LOADER} can be used for the latter.
358 */
359 public static DebugContext create(OptionValues options, Iterable<DebugHandlersFactory> factories) {
360 return new DebugContext(NO_DESCRIPTION, NO_GLOBAL_METRIC_VALUES, DEFAULT_LOG_STREAM, Immutable.create(options), factories);
361 }
362
363 /**
364 * Creates a {@link DebugContext}.
365 */
366 public static DebugContext create(OptionValues options, Description description, GlobalMetrics globalMetrics, PrintStream logStream, Iterable<DebugHandlersFactory> factories) {
367 return new DebugContext(description, globalMetrics, logStream, Immutable.create(options), factories);
368 }
369
370 private DebugContext(Description description, GlobalMetrics globalMetrics, PrintStream logStream, Immutable immutable, Iterable<DebugHandlersFactory> factories) {
371 this.immutable = immutable;
372 this.description = description;
373 this.globalMetrics = globalMetrics;
374 if (immutable.scopesEnabled) {
375 OptionValues options = immutable.options;
376 List<DebugDumpHandler> dumpHandlers = new ArrayList<>();
377 List<DebugVerifyHandler> verifyHandlers = new ArrayList<>();
378 for (DebugHandlersFactory factory : factories) {
379 for (DebugHandler handler : factory.createHandlers(options)) {
380 if (handler instanceof DebugDumpHandler) {
381 dumpHandlers.add((DebugDumpHandler) handler);
382 } else {
383 assert handler instanceof DebugVerifyHandler;
384 verifyHandlers.add((DebugVerifyHandler) handler);
385 }
386 }
387 }
388 currentConfig = new DebugConfigImpl(options, logStream, dumpHandlers, verifyHandlers);
389 currentScope = new ScopeImpl(this, Thread.currentThread());
390 currentScope.updateFlags(currentConfig);
391 metricsEnabled = true;
392 } else {
393 metricsEnabled = immutable.hasUnscopedMetrics() || immutable.listMetrics;
394 }
395 }
396
397 /**
398 * A special dump level that indicates the dumping machinery is enabled but no dumps will be
399 * produced except through other options.
400 */
401 public static final int ENABLED_LEVEL = 0;
402
403 /**
404 * Basic debug level.
405 *
406 * For HIR dumping, only ~5 graphs per method: after parsing, after inlining, after high tier,
407 * after mid tier, after low tier.
408 *
409 * LIR dumping: After LIR generation, after each pre-allocation, allocation and post allocation
410 * stage, and after code installation.
411 */
412 public static final int BASIC_LEVEL = 1;
413
414 /**
415 * Informational debug level.
416 *
417 * HIR dumping: One graph after each applied top-level phase.
418 *
419 * LIR dumping: After each applied phase.
420 */
421 public static final int INFO_LEVEL = 2;
422
423 /**
424 * Verbose debug level.
425 *
426 * HIR dumping: One graph after each phase (including sub phases).
427 *
428 * LIR dumping: After each phase including sub phases.
429 */
430 public static final int VERBOSE_LEVEL = 3;
431
432 /**
433 * Detailed debug level.
434 *
435 * HIR dumping: Graphs within phases where interesting for a phase, max ~5 per phase.
436 *
437 * LIR dumping: Dump CFG within phases where interesting.
438 */
439 public static final int DETAILED_LEVEL = 4;
440
441 /**
442 * Very detailed debug level.
443 *
444 * HIR dumping: Graphs per node granularity graph change (before/after change).
445 *
446 * LIR dumping: Intermediate CFGs of phases where interesting.
447 */
448 public static final int VERY_DETAILED_LEVEL = 5;
449
450 public boolean isDumpEnabled(int dumpLevel) {
451 return currentScope != null && currentScope.isDumpEnabled(dumpLevel);
452 }
453
454 /**
455 * Determines if verification is enabled for any {@link JavaMethod} in the current scope.
456 *
457 * @see DebugContext#verify(Object, String)
458 */
459 public boolean isVerifyEnabledForMethod() {
460 if (currentScope == null) {
461 return false;
462 }
463 if (currentConfig == null) {
464 return false;
465 }
466 return currentConfig.isVerifyEnabledForMethod(currentScope);
467 }
468
469 /**
470 * Determines if verification is enabled in the current scope.
471 *
472 * @see DebugContext#verify(Object, String)
473 */
474 public boolean isVerifyEnabled() {
475 return currentScope != null && currentScope.isVerifyEnabled();
476 }
477
478 public boolean isCountEnabled() {
479 return currentScope != null && currentScope.isCountEnabled();
480 }
481
482 public boolean isTimeEnabled() {
483 return currentScope != null && currentScope.isTimeEnabled();
484 }
485
486 public boolean isMemUseTrackingEnabled() {
487 return currentScope != null && currentScope.isMemUseTrackingEnabled();
488 }
489
490 public boolean isDumpEnabledForMethod() {
491 if (currentConfig == null) {
492 return false;
493 }
494 return currentConfig.isDumpEnabledForMethod(currentScope);
495 }
496
497 public boolean isLogEnabledForMethod() {
498 if (currentScope == null) {
499 return false;
500 }
501 if (currentConfig == null) {
502 return false;
503 }
504 return currentConfig.isLogEnabledForMethod(currentScope);
505 }
506
507 public boolean isLogEnabled() {
508 return currentScope != null && isLogEnabled(BASIC_LEVEL);
509 }
510
511 public boolean isLogEnabled(int logLevel) {
512 return currentScope != null && currentScope.isLogEnabled(logLevel);
513 }
514
515 /**
516 * Gets a string composed of the names in the current nesting of debug
517 * {@linkplain #scope(Object) scopes} separated by {@code '.'}.
518 */
519 public String getCurrentScopeName() {
520 if (currentScope != null) {
521 return currentScope.getQualifiedName();
522 } else {
523 return "";
524 }
525 }
526
527 /**
528 * Creates and enters a new debug scope which will be a child of the current debug scope.
529 * <p>
530 * It is recommended to use the try-with-resource statement for managing entering and leaving
531 * debug scopes. For example:
532 *
533 * <pre>
534 * try (Scope s = Debug.scope("InliningGraph", inlineeGraph)) {
535 * ...
536 * } catch (Throwable e) {
537 * throw Debug.handle(e);
538 * }
539 * </pre>
540 *
541 * The {@code name} argument is subject to the following type based conversion before having
542 * {@link Object#toString()} called on it:
543 *
544 * <pre>
545 * Type | Conversion
546 * ------------------+-----------------
547 * java.lang.Class | arg.getSimpleName()
548 * |
549 * </pre>
550 *
551 * @param name the name of the new scope
552 * @param contextObjects an array of object to be appended to the {@linkplain #context()
553 * current} debug context
554 * @throws Throwable used to enforce a catch block.
555 * @return the scope entered by this method which will be exited when its {@link Scope#close()}
556 * method is called
557 */
558 public DebugContext.Scope scope(Object name, Object[] contextObjects) throws Throwable {
559 if (currentScope != null) {
560 return enterScope(convertFormatArg(name).toString(), null, contextObjects);
561 } else {
562 return null;
563 }
564 }
565
566 /**
567 * Similar to {@link #scope(Object, Object[])} but without context objects. Therefore the catch
568 * block can be omitted.
569 *
570 * @see #scope(Object, Object[])
571 */
572 public DebugContext.Scope scope(Object name) {
573 if (currentScope != null) {
574 return enterScope(convertFormatArg(name).toString(), null);
575 } else {
576 return null;
577 }
578 }
579
580 private final Invariants invariants = Assertions.assertionsEnabled() ? new Invariants() : null;
581
582 static StackTraceElement[] getStackTrace(Thread thread) {
583 return thread.getStackTrace();
584 }
585
586 /**
587 * Utility for enforcing {@link DebugContext} invariants via assertions.
588 */
589 static class Invariants {
590 private final Thread thread;
591 private final StackTraceElement[] origin;
592
593 Invariants() {
594 thread = Thread.currentThread();
595 origin = getStackTrace(thread);
596 }
597
598 boolean checkNoConcurrentAccess() {
599 Thread currentThread = Thread.currentThread();
600 if (currentThread != thread) {
601 Formatter buf = new Formatter();
602 buf.format("Thread local %s object was created on thread %s but is being accessed by thread %s. The most likely cause is " +
603 "that the object is being retrieved from a non-thread-local cache.",
604 DebugContext.class.getName(), thread, currentThread);
605 int debugContextConstructors = 0;
606 boolean addedHeader = false;
607 for (StackTraceElement e : origin) {
608 if (e.getMethodName().equals("<init>") && e.getClassName().equals(DebugContext.class.getName())) {
609 debugContextConstructors++;
610 } else if (debugContextConstructors != 0) {
611 if (!addedHeader) {
612 addedHeader = true;
613 buf.format(" The object was instantiated here:");
614 }
615 // Distinguish from assertion stack trace by using double indent and
616 // "in" instead of "at" prefix.
617 buf.format("%n\t\tin %s", e);
618 }
619 }
620 if (addedHeader) {
621 buf.format("%n");
622 }
623
624 throw new AssertionError(buf.toString());
625 }
626 return true;
627 }
628 }
629
630 boolean checkNoConcurrentAccess() {
631 assert invariants == null || invariants.checkNoConcurrentAccess();
632 return true;
633 }
634
635 private DebugContext.Scope enterScope(CharSequence name, DebugConfig sandboxConfig, Object... newContextObjects) {
636 assert checkNoConcurrentAccess();
637 currentScope = currentScope.scope(name, sandboxConfig, newContextObjects);
638 return currentScope;
639 }
640
641 /**
642 * @see #scope(Object, Object[])
643 * @param context an object to be appended to the {@linkplain #context() current} debug context
644 */
645 public DebugContext.Scope scope(Object name, Object context) throws Throwable {
646 if (currentScope != null) {
647 return enterScope(convertFormatArg(name).toString(), null, context);
648 } else {
649 return null;
650 }
651 }
652
653 /**
654 * @see #scope(Object, Object[])
655 * @param context1 first object to be appended to the {@linkplain #context() current} debug
656 * context
657 * @param context2 second object to be appended to the {@linkplain #context() current} debug
658 * context
659 */
660 public DebugContext.Scope scope(Object name, Object context1, Object context2) throws Throwable {
661 if (currentScope != null) {
662 return enterScope(convertFormatArg(name).toString(), null, context1, context2);
663 } else {
664 return null;
665 }
666 }
667
668 /**
669 * @see #scope(Object, Object[])
670 * @param context1 first object to be appended to the {@linkplain #context() current} debug
671 * context
672 * @param context2 second object to be appended to the {@linkplain #context() current} debug
673 * context
674 * @param context3 third object to be appended to the {@linkplain #context() current} debug
675 * context
676 */
677 public DebugContext.Scope scope(Object name, Object context1, Object context2, Object context3) throws Throwable {
678 if (currentScope != null) {
679 return enterScope(convertFormatArg(name).toString(), null, context1, context2, context3);
680 } else {
681 return null;
682 }
683 }
684
685 /**
686 * Creates and enters a new debug scope which will be disjoint from the current debug scope.
687 * <p>
688 * It is recommended to use the try-with-resource statement for managing entering and leaving
689 * debug scopes. For example:
690 *
691 * <pre>
692 * try (Scope s = Debug.sandbox("CompilingStub", null, stubGraph)) {
693 * ...
694 * } catch (Throwable e) {
695 * throw Debug.handle(e);
696 * }
697 * </pre>
698 *
699 * @param name the name of the new scope
700 * @param config the debug configuration to use for the new scope or {@code null} to disable the
701 * scoping mechanism within the sandbox scope
702 * @param context objects to be appended to the {@linkplain #context() current} debug context
703 * @return the scope entered by this method which will be exited when its {@link Scope#close()}
704 * method is called
705 */
706 public DebugContext.Scope sandbox(CharSequence name, DebugConfig config, Object... context) throws Throwable {
707 if (config == null) {
708 return disable();
709 }
710 if (currentScope != null) {
711 return enterScope(name, config, context);
712 } else {
713 return null;
714 }
715 }
716
717 /**
718 * Determines if scopes are enabled and this context is in a non-top-level scope.
719 */
720 public boolean inNestedScope() {
721 if (immutable.scopesEnabled) {
722 if (currentScope == null) {
723 // In an active DisabledScope
724 return true;
725 }
726 return !currentScope.isTopLevel();
727 }
728 return immutable.scopesEnabled && currentScope == null;
729 }
730
731 class DisabledScope implements DebugContext.Scope {
732 final boolean savedMetricsEnabled;
733 final ScopeImpl savedScope;
734 final DebugConfig savedConfig;
735
736 DisabledScope() {
737 this.savedMetricsEnabled = metricsEnabled;
738 this.savedScope = currentScope;
739 this.savedConfig = currentConfig;
740 metricsEnabled = false;
741 currentScope = null;
742 currentConfig = null;
743 }
744
745 @Override
746 public String getQualifiedName() {
747 return "";
748 }
749
750 @Override
751 public Iterable<Object> getCurrentContext() {
752 return Collections.emptyList();
753 }
754
755 @Override
756 public void close() {
757 metricsEnabled = savedMetricsEnabled;
758 currentScope = savedScope;
759 currentConfig = savedConfig;
760 lastClosedScope = this;
761 }
762 }
763
764 /**
765 * Disables all metrics and scope related functionality until {@code close()} is called on the
766 * returned object.
767 */
768 public DebugContext.Scope disable() {
769 if (currentScope != null) {
770 return new DisabledScope();
771 } else {
772 return null;
773 }
774 }
775
776 public DebugContext.Scope forceLog() throws Throwable {
777 if (currentConfig != null) {
778 ArrayList<Object> context = new ArrayList<>();
779 for (Object obj : context()) {
780 context.add(obj);
781 }
782 DebugConfigImpl config = new DebugConfigImpl(new OptionValues(currentConfig.getOptions(), DebugOptions.Log, ":1000"));
783 return sandbox("forceLog", config, context.toArray());
784 }
785 return null;
786 }
787
788 /**
789 * Opens a scope in which exception
790 * {@linkplain DebugConfig#interceptException(DebugContext, Throwable) interception} is
791 * disabled. The current state of interception is restored when {@link DebugCloseable#close()}
792 * is called on the returned object.
793 *
794 * This is particularly useful to suppress extraneous output in JUnit tests that are expected to
795 * throw an exception.
796 */
797 public DebugCloseable disableIntercept() {
798 if (currentScope != null) {
799 return currentScope.disableIntercept();
800 }
801 return null;
802 }
803
804 /**
805 * Handles an exception in the context of the debug scope just exited. The just exited scope
806 * must have the current scope as its parent which will be the case if the try-with-resource
807 * pattern recommended by {@link #scope(Object)} and
808 * {@link #sandbox(CharSequence, DebugConfig, Object...)} is used
809 *
810 * @see #scope(Object, Object[])
811 * @see #sandbox(CharSequence, DebugConfig, Object...)
812 */
813 public RuntimeException handle(Throwable exception) {
814 if (currentScope != null) {
815 return currentScope.handle(exception);
816 } else {
817 if (exception instanceof Error) {
818 throw (Error) exception;
819 }
820 if (exception instanceof RuntimeException) {
821 throw (RuntimeException) exception;
822 }
823 throw new RuntimeException(exception);
824 }
825 }
826
827 public void log(String msg) {
828 log(BASIC_LEVEL, msg);
829 }
830
831 /**
832 * Prints a message to the current debug scope's logging stream if logging is enabled.
833 *
834 * @param msg the message to log
835 */
836 public void log(int logLevel, String msg) {
837 if (currentScope != null) {
838 currentScope.log(logLevel, msg);
839 }
840 }
841
842 public void log(String format, Object arg) {
843 log(BASIC_LEVEL, format, arg);
844 }
845
846 /**
847 * Prints a message to the current debug scope's logging stream if logging is enabled.
848 *
849 * @param format a format string
850 * @param arg the argument referenced by the format specifiers in {@code format}
851 */
852 public void log(int logLevel, String format, Object arg) {
853 if (currentScope != null) {
854 currentScope.log(logLevel, format, arg);
855 }
856 }
857
858 public void log(String format, int arg) {
859 log(BASIC_LEVEL, format, arg);
860 }
861
862 /**
863 * Prints a message to the current debug scope's logging stream if logging is enabled.
864 *
865 * @param format a format string
866 * @param arg the argument referenced by the format specifiers in {@code format}
867 */
868 public void log(int logLevel, String format, int arg) {
869 if (currentScope != null) {
870 currentScope.log(logLevel, format, arg);
871 }
872 }
873
874 public void log(String format, Object arg1, Object arg2) {
875 log(BASIC_LEVEL, format, arg1, arg2);
876 }
877
878 /**
879 * @see #log(int, String, Object)
880 */
881 public void log(int logLevel, String format, Object arg1, Object arg2) {
882 if (currentScope != null) {
883 currentScope.log(logLevel, format, arg1, arg2);
884 }
885 }
886
887 public void log(String format, int arg1, Object arg2) {
888 log(BASIC_LEVEL, format, arg1, arg2);
889 }
890
891 /**
892 * @see #log(int, String, Object)
893 */
894 public void log(int logLevel, String format, int arg1, Object arg2) {
895 if (currentScope != null) {
896 currentScope.log(logLevel, format, arg1, arg2);
897 }
898 }
899
900 public void log(String format, Object arg1, int arg2) {
901 log(BASIC_LEVEL, format, arg1, arg2);
902 }
903
904 /**
905 * @see #log(int, String, Object)
906 */
907 public void log(int logLevel, String format, Object arg1, int arg2) {
908 if (currentScope != null) {
909 currentScope.log(logLevel, format, arg1, arg2);
910 }
911 }
912
913 public void log(String format, int arg1, int arg2) {
914 log(BASIC_LEVEL, format, arg1, arg2);
915 }
916
917 /**
918 * @see #log(int, String, Object)
919 */
920 public void log(int logLevel, String format, int arg1, int arg2) {
921 if (currentScope != null) {
922 currentScope.log(logLevel, format, arg1, arg2);
923 }
924 }
925
926 public void log(String format, Object arg1, Object arg2, Object arg3) {
927 log(BASIC_LEVEL, format, arg1, arg2, arg3);
928 }
929
930 /**
931 * @see #log(int, String, Object)
932 */
933 public void log(int logLevel, String format, Object arg1, Object arg2, Object arg3) {
934 if (currentScope != null) {
935 currentScope.log(logLevel, format, arg1, arg2, arg3);
936 }
937 }
938
939 public void log(String format, int arg1, int arg2, int arg3) {
940 log(BASIC_LEVEL, format, arg1, arg2, arg3);
941 }
942
943 /**
944 * @see #log(int, String, Object)
945 */
946 public void log(int logLevel, String format, int arg1, int arg2, int arg3) {
947 if (currentScope != null) {
948 currentScope.log(logLevel, format, arg1, arg2, arg3);
949 }
950 }
951
952 public void log(String format, Object arg1, Object arg2, Object arg3, Object arg4) {
953 log(BASIC_LEVEL, format, arg1, arg2, arg3, arg4);
954 }
955
956 /**
957 * @see #log(int, String, Object)
958 */
959 public void log(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4) {
960 if (currentScope != null) {
961 currentScope.log(logLevel, format, arg1, arg2, arg3, arg4);
962 }
963 }
964
965 public void log(String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5) {
966 log(BASIC_LEVEL, format, arg1, arg2, arg3, arg4, arg5);
967 }
968
969 /**
970 * @see #log(int, String, Object)
971 */
972 public void log(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5) {
973 if (currentScope != null) {
974 currentScope.log(logLevel, format, arg1, arg2, arg3, arg4, arg5);
975 }
976 }
977
978 public void log(String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6) {
979 log(BASIC_LEVEL, format, arg1, arg2, arg3, arg4, arg5, arg6);
980 }
981
982 /**
983 * @see #log(int, String, Object)
984 */
985 public void log(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6) {
986 if (currentScope != null) {
987 currentScope.log(logLevel, format, arg1, arg2, arg3, arg4, arg5, arg6);
988 }
989 }
990
991 public void log(String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6, Object arg7) {
992 log(BASIC_LEVEL, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7);
993 }
994
995 public void log(String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6, Object arg7, Object arg8) {
996 log(BASIC_LEVEL, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8);
997 }
998
999 /**
1000 * @see #log(int, String, Object)
1001 */
1002 public void log(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6, Object arg7) {
1003 if (currentScope != null) {
1004 currentScope.log(logLevel, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7);
1005 }
1006 }
1007
1008 public void log(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6, Object arg7, Object arg8) {
1009 if (currentScope != null) {
1010 currentScope.log(logLevel, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8);
1011 }
1012 }
1013
1014 public void log(String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6, Object arg7, Object arg8, Object arg9) {
1015 log(BASIC_LEVEL, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8, arg9);
1016 }
1017
1018 public void log(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6, Object arg7, Object arg8, Object arg9) {
1019 if (currentScope != null) {
1020 currentScope.log(logLevel, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8, arg9);
1021 }
1022 }
1023
1024 public void log(String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6, Object arg7, Object arg8, Object arg9, Object arg10) {
1025 log(BASIC_LEVEL, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8, arg9, arg10);
1026 }
1027
1028 public void log(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6, Object arg7, Object arg8, Object arg9, Object arg10) {
1029 if (currentScope != null) {
1030 currentScope.log(logLevel, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8, arg9, arg10);
1031 }
1032 }
1033
1034 public void logv(String format, Object... args) {
1035 logv(BASIC_LEVEL, format, args);
1036 }
1037
1038 /**
1039 * Prints a message to the current debug scope's logging stream. This method must only be called
1040 * if debugging scopes are {@linkplain DebugContext#areScopesEnabled() enabled} as it incurs
1041 * allocation at the call site. If possible, call one of the other {@code log()} methods in this
1042 * class that take a fixed number of parameters.
1043 *
1044 * @param format a format string
1045 * @param args the arguments referenced by the format specifiers in {@code format}
1046 */
1047 public void logv(int logLevel, String format, Object... args) {
1048 if (currentScope == null) {
1049 throw new InternalError("Use of Debug.logv() must be guarded by a test of Debug.isEnabled()");
1050 }
1051 currentScope.log(logLevel, format, args);
1052 }
1053
1054 /**
1055 * This override exists to catch cases when {@link #log(String, Object)} is called with one
1056 * argument bound to a varargs method parameter. It will bind to this method instead of the
1057 * single arg variant and produce a deprecation warning instead of silently wrapping the
1058 * Object[] inside of another Object[].
1059 */
1060 @Deprecated
1061 public void log(String format, Object[] args) {
1062 assert false : "shouldn't use this";
1063 log(BASIC_LEVEL, format, args);
1064 }
1065
1066 /**
1067 * This override exists to catch cases when {@link #log(int, String, Object)} is called with one
1068 * argument bound to a varargs method parameter. It will bind to this method instead of the
1069 * single arg variant and produce a deprecation warning instead of silently wrapping the
1070 * Object[] inside of another Object[].
1071 */
1072 @Deprecated
1073 public void log(int logLevel, String format, Object[] args) {
1074 assert false : "shouldn't use this";
1075 logv(logLevel, format, args);
1076 }
1077
1078 /**
1079 * Forces an unconditional dump. This method exists mainly for debugging. It can also be used to
1080 * force a graph dump from IDEs that support invoking a Java method while at a breakpoint.
1081 */
1082 public void forceDump(Object object, String format, Object... args) {
1083 DebugConfig config = currentConfig;
1084 Collection<DebugDumpHandler> dumpHandlers;
1085 boolean closeAfterDump;
1086 if (config != null) {
1087 dumpHandlers = config.dumpHandlers();
1088 closeAfterDump = false;
1089 } else {
1090 OptionValues options = getOptions();
1091 dumpHandlers = new ArrayList<>();
1092 for (DebugHandlersFactory factory : DebugHandlersFactory.LOADER) {
1093 for (DebugHandler handler : factory.createHandlers(options)) {
1094 if (handler instanceof DebugDumpHandler) {
1095 dumpHandlers.add((DebugDumpHandler) handler);
1096 }
1097 }
1098 }
1099 closeAfterDump = true;
1100 }
1101 for (DebugDumpHandler dumpHandler : dumpHandlers) {
1102 dumpHandler.dump(this, object, format, args);
1103 if (closeAfterDump) {
1104 dumpHandler.close();
1105 }
1106 }
1107 }
1108
1109 public void dump(int dumpLevel, Object object, String msg) {
1110 if (currentScope != null && currentScope.isDumpEnabled(dumpLevel)) {
1111 currentScope.dump(dumpLevel, object, msg);
1112 }
1113 }
1114
1115 public void dump(int dumpLevel, Object object, String format, Object arg) {
1116 if (currentScope != null && currentScope.isDumpEnabled(dumpLevel)) {
1117 currentScope.dump(dumpLevel, object, format, arg);
1118 }
1119 }
1120
1121 public void dump(int dumpLevel, Object object, String format, Object arg1, Object arg2) {
1122 if (currentScope != null && currentScope.isDumpEnabled(dumpLevel)) {
1123 currentScope.dump(dumpLevel, object, format, arg1, arg2);
1124 }
1125 }
1126
1127 public void dump(int dumpLevel, Object object, String format, Object arg1, Object arg2, Object arg3) {
1128 if (currentScope != null && currentScope.isDumpEnabled(dumpLevel)) {
1129 currentScope.dump(dumpLevel, object, format, arg1, arg2, arg3);
1130 }
1131 }
1132
1133 /**
1134 * This override exists to catch cases when {@link #dump(int, Object, String, Object)} is called
1135 * with one argument bound to a varargs method parameter. It will bind to this method instead of
1136 * the single arg variant and produce a deprecation warning instead of silently wrapping the
1137 * Object[] inside of another Object[].
1138 */
1139 @Deprecated
1140 public void dump(int dumpLevel, Object object, String format, Object[] args) {
1141 assert false : "shouldn't use this";
1142 if (currentScope != null && currentScope.isDumpEnabled(dumpLevel)) {
1143 currentScope.dump(dumpLevel, object, format, args);
1144 }
1145 }
1146
1147 /**
1148 * Calls all {@link DebugVerifyHandler}s in the current {@linkplain #getConfig() config} to
1149 * perform verification on a given object.
1150 *
1151 * @param object object to verify
1152 * @param message description of verification context
1153 *
1154 * @see DebugVerifyHandler#verify
1155 */
1156 public void verify(Object object, String message) {
1157 if (currentScope != null && currentScope.isVerifyEnabled()) {
1158 currentScope.verify(object, message);
1159 }
1160 }
1161
1162 /**
1163 * Calls all {@link DebugVerifyHandler}s in the current {@linkplain #getConfig() config} to
1164 * perform verification on a given object.
1165 *
1166 * @param object object to verify
1167 * @param format a format string for the description of the verification context
1168 * @param arg the argument referenced by the format specifiers in {@code format}
1169 *
1170 * @see DebugVerifyHandler#verify
1171 */
1172 public void verify(Object object, String format, Object arg) {
1173 if (currentScope != null && currentScope.isVerifyEnabled()) {
1174 currentScope.verify(object, format, arg);
1175 }
1176 }
1177
1178 /**
1179 * This override exists to catch cases when {@link #verify(Object, String, Object)} is called
1180 * with one argument bound to a varargs method parameter. It will bind to this method instead of
1181 * the single arg variant and produce a deprecation warning instead of silently wrapping the
1182 * Object[] inside of another Object[].
1183 */
1184 @Deprecated
1185 public void verify(Object object, String format, Object[] args) {
1186 assert false : "shouldn't use this";
1187 if (currentScope != null && currentScope.isVerifyEnabled()) {
1188 currentScope.verify(object, format, args);
1189 }
1190 }
1191
1192 /**
1193 * Opens a new indentation level (by adding some spaces) based on the current indentation level.
1194 * This should be used in a {@linkplain Indent try-with-resources} pattern.
1195 *
1196 * @return an object that reverts to the current indentation level when
1197 * {@linkplain Indent#close() closed} or null if debugging is disabled
1198 * @see #logAndIndent(int, String)
1199 * @see #logAndIndent(int, String, Object)
1200 */
1201 public Indent indent() {
1202 if (currentScope != null) {
1203 return currentScope.pushIndentLogger();
1204 }
1205 return null;
1206 }
1207
1208 public Indent logAndIndent(String msg) {
1209 return logAndIndent(BASIC_LEVEL, msg);
1210 }
1211
1212 /**
1213 * A convenience function which combines {@link #log(String)} and {@link #indent()}.
1214 *
1215 * @param msg the message to log
1216 * @return an object that reverts to the current indentation level when
1217 * {@linkplain Indent#close() closed} or null if debugging is disabled
1218 */
1219 public Indent logAndIndent(int logLevel, String msg) {
1220 if (currentScope != null && isLogEnabled(logLevel)) {
1221 return logvAndIndentInternal(logLevel, msg);
1222 }
1223 return null;
1224 }
1225
1226 public Indent logAndIndent(String format, Object arg) {
1227 return logAndIndent(BASIC_LEVEL, format, arg);
1228 }
1229
1230 /**
1231 * A convenience function which combines {@link #log(String, Object)} and {@link #indent()}.
1232 *
1233 * @param format a format string
1234 * @param arg the argument referenced by the format specifiers in {@code format}
1235 * @return an object that reverts to the current indentation level when
1236 * {@linkplain Indent#close() closed} or null if debugging is disabled
1237 */
1238 public Indent logAndIndent(int logLevel, String format, Object arg) {
1239 if (currentScope != null && isLogEnabled(logLevel)) {
1240 return logvAndIndentInternal(logLevel, format, arg);
1241 }
1242 return null;
1243 }
1244
1245 public Indent logAndIndent(String format, int arg) {
1246 return logAndIndent(BASIC_LEVEL, format, arg);
1247 }
1248
1249 /**
1250 * A convenience function which combines {@link #log(String, Object)} and {@link #indent()}.
1251 *
1252 * @param format a format string
1253 * @param arg the argument referenced by the format specifiers in {@code format}
1254 * @return an object that reverts to the current indentation level when
1255 * {@linkplain Indent#close() closed} or null if debugging is disabled
1256 */
1257 public Indent logAndIndent(int logLevel, String format, int arg) {
1258 if (currentScope != null && isLogEnabled(logLevel)) {
1259 return logvAndIndentInternal(logLevel, format, arg);
1260 }
1261 return null;
1262 }
1263
1264 public Indent logAndIndent(String format, int arg1, Object arg2) {
1265 return logAndIndent(BASIC_LEVEL, format, arg1, arg2);
1266 }
1267
1268 /**
1269 * @see #logAndIndent(int, String, Object)
1270 */
1271 public Indent logAndIndent(int logLevel, String format, int arg1, Object arg2) {
1272 if (currentScope != null && isLogEnabled(logLevel)) {
1273 return logvAndIndentInternal(logLevel, format, arg1, arg2);
1274 }
1275 return null;
1276 }
1277
1278 public Indent logAndIndent(String format, Object arg1, int arg2) {
1279 return logAndIndent(BASIC_LEVEL, format, arg1, arg2);
1280 }
1281
1282 /**
1283 * @see #logAndIndent(int, String, Object)
1284 */
1285 public Indent logAndIndent(int logLevel, String format, Object arg1, int arg2) {
1286 if (currentScope != null && isLogEnabled(logLevel)) {
1287 return logvAndIndentInternal(logLevel, format, arg1, arg2);
1288 }
1289 return null;
1290 }
1291
1292 public Indent logAndIndent(String format, int arg1, int arg2) {
1293 return logAndIndent(BASIC_LEVEL, format, arg1, arg2);
1294 }
1295
1296 /**
1297 * @see #logAndIndent(int, String, Object)
1298 */
1299 public Indent logAndIndent(int logLevel, String format, int arg1, int arg2) {
1300 if (currentScope != null && isLogEnabled(logLevel)) {
1301 return logvAndIndentInternal(logLevel, format, arg1, arg2);
1302 }
1303 return null;
1304 }
1305
1306 public Indent logAndIndent(String format, Object arg1, Object arg2) {
1307 return logAndIndent(BASIC_LEVEL, format, arg1, arg2);
1308 }
1309
1310 /**
1311 * @see #logAndIndent(int, String, Object)
1312 */
1313 public Indent logAndIndent(int logLevel, String format, Object arg1, Object arg2) {
1314 if (currentScope != null && isLogEnabled(logLevel)) {
1315 return logvAndIndentInternal(logLevel, format, arg1, arg2);
1316 }
1317 return null;
1318 }
1319
1320 public Indent logAndIndent(String format, Object arg1, Object arg2, Object arg3) {
1321 return logAndIndent(BASIC_LEVEL, format, arg1, arg2, arg3);
1322 }
1323
1324 /**
1325 * @see #logAndIndent(int, String, Object)
1326 */
1327 public Indent logAndIndent(int logLevel, String format, Object arg1, Object arg2, Object arg3) {
1328 if (currentScope != null && isLogEnabled(logLevel)) {
1329 return logvAndIndentInternal(logLevel, format, arg1, arg2, arg3);
1330 }
1331 return null;
1332 }
1333
1334 public Indent logAndIndent(String format, int arg1, int arg2, int arg3) {
1335 return logAndIndent(BASIC_LEVEL, format, arg1, arg2, arg3);
1336 }
1337
1338 /**
1339 * @see #logAndIndent(int, String, Object)
1340 */
1341 public Indent logAndIndent(int logLevel, String format, int arg1, int arg2, int arg3) {
1342 if (currentScope != null && isLogEnabled(logLevel)) {
1343 return logvAndIndentInternal(logLevel, format, arg1, arg2, arg3);
1344 }
1345 return null;
1346 }
1347
1348 public Indent logAndIndent(String format, Object arg1, int arg2, int arg3) {
1349 return logAndIndent(BASIC_LEVEL, format, arg1, arg2, arg3);
1350 }
1351
1352 /**
1353 * @see #logAndIndent(int, String, Object)
1354 */
1355 public Indent logAndIndent(int logLevel, String format, Object arg1, int arg2, int arg3) {
1356 if (currentScope != null && isLogEnabled(logLevel)) {
1357 return logvAndIndentInternal(logLevel, format, arg1, arg2, arg3);
1358 }
1359 return null;
1360 }
1361
1362 public Indent logAndIndent(String format, Object arg1, Object arg2, Object arg3, Object arg4) {
1363 return logAndIndent(BASIC_LEVEL, format, arg1, arg2, arg3, arg4);
1364 }
1365
1366 /**
1367 * @see #logAndIndent(int, String, Object)
1368 */
1369 public Indent logAndIndent(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4) {
1370 if (currentScope != null && isLogEnabled(logLevel)) {
1371 return logvAndIndentInternal(logLevel, format, arg1, arg2, arg3, arg4);
1372 }
1373 return null;
1374 }
1375
1376 public Indent logAndIndent(String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5) {
1377 return logAndIndent(BASIC_LEVEL, format, arg1, arg2, arg3, arg4, arg5);
1378 }
1379
1380 /**
1381 * @see #logAndIndent(int, String, Object)
1382 */
1383 public Indent logAndIndent(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5) {
1384 if (currentScope != null && isLogEnabled(logLevel)) {
1385 return logvAndIndentInternal(logLevel, format, arg1, arg2, arg3, arg4, arg5);
1386 }
1387 return null;
1388 }
1389
1390 public Indent logAndIndent(String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6) {
1391 return logAndIndent(BASIC_LEVEL, format, arg1, arg2, arg3, arg4, arg5, arg6);
1392 }
1393
1394 /**
1395 * @see #logAndIndent(int, String, Object)
1396 */
1397 public Indent logAndIndent(int logLevel, String format, Object arg1, Object arg2, Object arg3, Object arg4, Object arg5, Object arg6) {
1398 if (currentScope != null && isLogEnabled(logLevel)) {
1399 return logvAndIndentInternal(logLevel, format, arg1, arg2, arg3, arg4, arg5, arg6);
1400 }
1401 return null;
1402 }
1403
1404 /**
1405 * A convenience function which combines {@link #logv(int, String, Object...)} and
1406 * {@link #indent()}.
1407 *
1408 * @param format a format string
1409 * @param args the arguments referenced by the format specifiers in {@code format}
1410 * @return an object that reverts to the current indentation level when
1411 * {@linkplain Indent#close() closed} or null if debugging is disabled
1412 */
1413 public Indent logvAndIndent(int logLevel, String format, Object... args) {
1414 if (currentScope != null) {
1415 if (isLogEnabled(logLevel)) {
1416 return logvAndIndentInternal(logLevel, format, args);
1417 }
1418 return null;
1419 }
1420 throw new InternalError("Use of Debug.logvAndIndent() must be guarded by a test of Debug.isEnabled()");
1421 }
1422
1423 private Indent logvAndIndentInternal(int logLevel, String format, Object... args) {
1424 assert currentScope != null && isLogEnabled(logLevel) : "must have checked Debug.isLogEnabled()";
1425 currentScope.log(logLevel, format, args);
1426 return currentScope.pushIndentLogger();
1427 }
1428
1429 /**
1430 * This override exists to catch cases when {@link #logAndIndent(String, Object)} is called with
1431 * one argument bound to a varargs method parameter. It will bind to this method instead of the
1432 * single arg variant and produce a deprecation warning instead of silently wrapping the
1433 * Object[] inside of another Object[].
1434 */
1435 @Deprecated
1436 public void logAndIndent(String format, Object[] args) {
1437 assert false : "shouldn't use this";
1438 logAndIndent(BASIC_LEVEL, format, args);
1439 }
1440
1441 /**
1442 * This override exists to catch cases when {@link #logAndIndent(int, String, Object)} is called
1443 * with one argument bound to a varargs method parameter. It will bind to this method instead of
1444 * the single arg variant and produce a deprecation warning instead of silently wrapping the
1445 * Object[] inside of another Object[].
1446 */
1447 @Deprecated
1448 public void logAndIndent(int logLevel, String format, Object[] args) {
1449 assert false : "shouldn't use this";
1450 logvAndIndent(logLevel, format, args);
1451 }
1452
1453 public Iterable<Object> context() {
1454 if (currentScope != null) {
1455 return currentScope.getCurrentContext();
1456 } else {
1457 return Collections.emptyList();
1458 }
1459 }
1460
1461 @SuppressWarnings("unchecked")
1462 public <T> List<T> contextSnapshot(Class<T> clazz) {
1463 if (currentScope != null) {
1464 List<T> result = new ArrayList<>();
1465 for (Object o : context()) {
1466 if (clazz.isInstance(o)) {
1467 result.add((T) o);
1468 }
1469 }
1470 return result;
1471 } else {
1472 return Collections.emptyList();
1473 }
1474 }
1475
1476 /**
1477 * Searches the current debug scope, bottom up, for a context object that is an instance of a
1478 * given type. The first such object found is returned.
1479 */
1480 @SuppressWarnings("unchecked")
1481 public <T> T contextLookup(Class<T> clazz) {
1482 if (currentScope != null) {
1483 for (Object o : context()) {
1484 if (clazz.isInstance(o)) {
1485 return ((T) o);
1486 }
1487 }
1488 }
1489 return null;
1490 }
1491
1492 /**
1493 * Searches the current debug scope, top down, for a context object that is an instance of a
1494 * given type. The first such object found is returned.
1495 */
1496 @SuppressWarnings("unchecked")
1497 public <T> T contextLookupTopdown(Class<T> clazz) {
1498 if (currentScope != null) {
1499 T found = null;
1500 for (Object o : context()) {
1501 if (clazz.isInstance(o)) {
1502 found = (T) o;
1503 }
1504 }
1505 return found;
1506 }
1507 return null;
1508 }
1509
1510 /**
1511 * Creates a {@linkplain MemUseTrackerKey memory use tracker}.
1512 */
1513 public static MemUseTrackerKey memUseTracker(CharSequence name) {
1514 return createMemUseTracker("%s", name, null);
1515 }
1516
1517 /**
1518 * Creates a debug memory use tracker. Invoking this method is equivalent to:
1519 *
1520 * <pre>
1521 * Debug.memUseTracker(format, arg, null)
1522 * </pre>
1523 *
1524 * except that the string formatting only happens if mem tracking is enabled.
1525 *
1526 * @see #counter(String, Object, Object)
1527 */
1528 public static MemUseTrackerKey memUseTracker(String format, Object arg) {
1529 return createMemUseTracker(format, arg, null);
1530 }
1531
1532 /**
1533 * Creates a debug memory use tracker. Invoking this method is equivalent to:
1534 *
1535 * <pre>
1536 * Debug.memUseTracker(String.format(format, arg1, arg2))
1537 * </pre>
1538 *
1539 * except that the string formatting only happens if memory use tracking is enabled. In
1540 * addition, each argument is subject to the following type based conversion before being passed
1541 * as an argument to {@link String#format(String, Object...)}:
1542 *
1543 * <pre>
1544 * Type | Conversion
1545 * ------------------+-----------------
1546 * java.lang.Class | arg.getSimpleName()
1547 * |
1548 * </pre>
1549 *
1550 * @see #memUseTracker(CharSequence)
1551 */
1552 public static MemUseTrackerKey memUseTracker(String format, Object arg1, Object arg2) {
1553 return createMemUseTracker(format, arg1, arg2);
1554 }
1555
1556 private static MemUseTrackerKey createMemUseTracker(String format, Object arg1, Object arg2) {
1557 return new MemUseTrackerKeyImpl(format, arg1, arg2);
1558 }
1559
1560 /**
1561 * Creates a {@linkplain CounterKey counter}.
1562 */
1563 public static CounterKey counter(CharSequence name) {
1564 return createCounter("%s", name, null);
1565 }
1566
1567 /**
1568 * Gets a tally of the metric values in this context and a given tally.
1569 *
1570 * @param tally the tally to which the metrics should be added
1571 * @return a tally of the metric values in this context and {@code tally}. This will be
1572 * {@code tally} if this context has no metric values or {@code tally} is wide enough to
1573 * hold all the metric values in this context otherwise it will be a new array.
1574 */
1575 public long[] addValuesTo(long[] tally) {
1576 if (metricValues == null) {
1577 return tally;
1578 }
1579 if (tally == null) {
1580 return metricValues.clone();
1581 } else if (metricValues.length >= tally.length) {
1582 long[] newTally = metricValues.clone();
1583 for (int i = 0; i < tally.length; i++) {
1584 newTally[i] += tally[i];
1585 }
1586 return newTally;
1587 } else {
1588 for (int i = 0; i < metricValues.length; i++) {
1589 tally[i] += metricValues[i];
1590 }
1591 return tally;
1592 }
1593 }
1594
1595 /**
1596 * Creates and returns a sorted map from metric names to their values in {@code values}.
1597 *
1598 * @param values values for metrics in the {@link KeyRegistry}.
1599 */
1600 public static EconomicMap<MetricKey, Long> convertValuesToKeyValueMap(long[] values) {
1601 List<MetricKey> keys = KeyRegistry.getKeys();
1602 Collections.sort(keys, MetricKey.NAME_COMPARATOR);
1603 EconomicMap<MetricKey, Long> res = EconomicMap.create(keys.size());
1604 for (MetricKey key : keys) {
1605 int index = ((AbstractKey) key).getIndex();
1606 if (index >= values.length) {
1607 res.put(key, 0L);
1608 } else {
1609 res.put(key, values[index]);
1610 }
1611 }
1612 return res;
1613 }
1614
1615 void setMetricValue(int keyIndex, long l) {
1616 ensureMetricValuesSize(keyIndex);
1617 metricValues[keyIndex] = l;
1618 }
1619
1620 long getMetricValue(int keyIndex) {
1621 if (metricValues == null || metricValues.length <= keyIndex) {
1622 return 0L;
1623 }
1624 return metricValues[keyIndex];
1625 }
1626
1627 private void ensureMetricValuesSize(int index) {
1628 if (metricValues == null) {
1629 metricValues = new long[index + 1];
1630 }
1631 if (metricValues.length <= index) {
1632 metricValues = Arrays.copyOf(metricValues, index + 1);
1633 }
1634 }
1635
1636 public static String applyFormattingFlagsAndWidth(String s, int flags, int width) {
1637 if (flags == 0 && width < 0) {
1638 return s;
1639 }
1640 StringBuilder sb = new StringBuilder(s);
1641
1642 // apply width and justification
1643 int len = sb.length();
1644 if (len < width) {
1645 for (int i = 0; i < width - len; i++) {
1646 if ((flags & LEFT_JUSTIFY) == LEFT_JUSTIFY) {
1647 sb.append(' ');
1648 } else {
1649 sb.insert(0, ' ');
1650 }
1651 }
1652 }
1653
1654 String res = sb.toString();
1655 if ((flags & UPPERCASE) == UPPERCASE) {
1656 res = res.toUpperCase();
1657 }
1658 return res;
1659 }
1660
1661 /**
1662 * Creates a debug counter. Invoking this method is equivalent to:
1663 *
1664 * <pre>
1665 * Debug.counter(format, arg, null)
1666 * </pre>
1667 *
1668 * except that the string formatting only happens if count is enabled.
1669 *
1670 * @see #counter(String, Object, Object)
1671 */
1672 public static CounterKey counter(String format, Object arg) {
1673 return createCounter(format, arg, null);
1674 }
1675
1676 /**
1677 * Creates a debug counter. Invoking this method is equivalent to:
1678 *
1679 * <pre>
1680 * Debug.counter(String.format(format, arg1, arg2))
1681 * </pre>
1682 *
1683 * except that the string formatting only happens if count is enabled. In addition, each
1684 * argument is subject to the following type based conversion before being passed as an argument
1685 * to {@link String#format(String, Object...)}:
1686 *
1687 * <pre>
1688 * Type | Conversion
1689 * ------------------+-----------------
1690 * java.lang.Class | arg.getSimpleName()
1691 * |
1692 * </pre>
1693 *
1694 * @see #counter(CharSequence)
1695 */
1696 public static CounterKey counter(String format, Object arg1, Object arg2) {
1697 return createCounter(format, arg1, arg2);
1698 }
1699
1700 private static CounterKey createCounter(String format, Object arg1, Object arg2) {
1701 return new CounterKeyImpl(format, arg1, arg2);
1702 }
1703
1704 public DebugConfig getConfig() {
1705 return currentConfig;
1706 }
1707
1708 /**
1709 * Creates a {@linkplain TimerKey timer}.
1710 * <p>
1711 * A disabled timer has virtually no overhead.
1712 */
1713 public static TimerKey timer(CharSequence name) {
1714 return createTimer("%s", name, null);
1715 }
1716
1717 /**
1718 * Creates a debug timer. Invoking this method is equivalent to:
1719 *
1720 * <pre>
1721 * Debug.timer(format, arg, null)
1722 * </pre>
1723 *
1724 * except that the string formatting only happens if timing is enabled.
1725 *
1726 * @see #timer(String, Object, Object)
1727 */
1728 public static TimerKey timer(String format, Object arg) {
1729 return createTimer(format, arg, null);
1730 }
1731
1732 /**
1733 * Creates a debug timer. Invoking this method is equivalent to:
1734 *
1735 * <pre>
1736 * Debug.timer(String.format(format, arg1, arg2))
1737 * </pre>
1738 *
1739 * except that the string formatting only happens if timing is enabled. In addition, each
1740 * argument is subject to the following type based conversion before being passed as an argument
1741 * to {@link String#format(String, Object...)}:
1742 *
1743 * <pre>
1744 * Type | Conversion
1745 * ------------------+-----------------
1746 * java.lang.Class | arg.getSimpleName()
1747 * |
1748 * </pre>
1749 *
1750 * @see #timer(CharSequence)
1751 */
1752 public static TimerKey timer(String format, Object arg1, Object arg2) {
1753 return createTimer(format, arg1, arg2);
1754 }
1755
1756 /**
1757 * There are paths where construction of formatted class names are common and the code below is
1758 * surprisingly expensive, so compute it once and cache it.
1759 */
1760 private static final ClassValue<String> formattedClassName = new ClassValue<String>() {
1761 @Override
1762 protected String computeValue(Class<?> c) {
1763 final String simpleName = c.getSimpleName();
1764 Class<?> enclosingClass = c.getEnclosingClass();
1765 if (enclosingClass != null) {
1766 String prefix = "";
1767 while (enclosingClass != null) {
1768 prefix = enclosingClass.getSimpleName() + "_" + prefix;
1769 enclosingClass = enclosingClass.getEnclosingClass();
1770 }
1771 return prefix + simpleName;
1772 } else {
1773 return simpleName;
1774 }
1775 }
1776 };
1777
1778 public static Object convertFormatArg(Object arg) {
1779 if (arg instanceof Class) {
1780 return formattedClassName.get((Class<?>) arg);
1781 }
1782 return arg;
1783 }
1784
1785 static String formatDebugName(String format, Object arg1, Object arg2) {
1786 return String.format(format, convertFormatArg(arg1), convertFormatArg(arg2));
1787 }
1788
1789 private static TimerKey createTimer(String format, Object arg1, Object arg2) {
1790 return new TimerKeyImpl(format, arg1, arg2);
1791 }
1792
1793 /**
1794 * Represents a debug scope entered by {@link DebugContext#scope(Object)} or
1795 * {@link DebugContext#sandbox(CharSequence, DebugConfig, Object...)}. Leaving the scope is
1796 * achieved via {@link #close()}.
1797 */
1798 public interface Scope extends AutoCloseable {
1799 /**
1800 * Gets the names of this scope and its ancestors separated by {@code '.'}.
1801 */
1802 String getQualifiedName();
1803
1804 Iterable<Object> getCurrentContext();
1805
1806 @Override
1807 void close();
1808 }
1809
1810 boolean isTimerEnabled(TimerKeyImpl key) {
1811 if (!metricsEnabled) {
1812 // Pulling this common case out of `isTimerEnabledSlow`
1813 // gives C1 a better chance to inline this method.
1814 return false;
1815 }
1816 return isTimerEnabledSlow(key);
1817 }
1818
1819 private boolean isTimerEnabledSlow(AbstractKey key) {
1820 if (currentScope != null && currentScope.isTimeEnabled()) {
1821 return true;
1822 }
1823 if (immutable.listMetrics) {
1824 key.ensureInitialized();
1825 }
1826 assert checkNoConcurrentAccess();
1827 EconomicSet<String> unscoped = immutable.unscopedTimers;
1828 return unscoped != null && (unscoped.isEmpty() || unscoped.contains(key.getName()));
1829 }
1830
1831 /**
1832 * Determines if a given timer is enabled in the current scope.
1833 */
1834 boolean isCounterEnabled(CounterKeyImpl key) {
1835 if (!metricsEnabled) {
1836 // Pulling this common case out of `isCounterEnabledSlow`
1837 // gives C1 a better chance to inline this method.
1838 return false;
1839 }
1840 return isCounterEnabledSlow(key);
1841 }
1842
1843 private boolean isCounterEnabledSlow(AbstractKey key) {
1844 if (currentScope != null && currentScope.isCountEnabled()) {
1845 return true;
1846 }
1847 if (immutable.listMetrics) {
1848 key.ensureInitialized();
1849 }
1850 assert checkNoConcurrentAccess();
1851 EconomicSet<String> unscoped = immutable.unscopedCounters;
1852 return unscoped != null && (unscoped.isEmpty() || unscoped.contains(key.getName()));
1853 }
1854
1855 boolean isMemUseTrackerEnabled(MemUseTrackerKeyImpl key) {
1856 if (!metricsEnabled) {
1857 // Pulling this common case out of `isMemUseTrackerEnabledSlow`
1858 // gives C1 a better chance to inline this method.
1859 return false;
1860 }
1861 return isMemUseTrackerEnabledSlow(key);
1862 }
1863
1864 private boolean isMemUseTrackerEnabledSlow(AbstractKey key) {
1865 if (currentScope != null && currentScope.isMemUseTrackingEnabled()) {
1866 return true;
1867 }
1868 if (immutable.listMetrics) {
1869 key.ensureInitialized();
1870 }
1871 assert checkNoConcurrentAccess();
1872 EconomicSet<String> unscoped = immutable.unscopedMemUseTrackers;
1873 return unscoped != null && (unscoped.isEmpty() || unscoped.contains(key.getName()));
1874 }
1875
1876 public boolean areMetricsEnabled() {
1877 return metricsEnabled;
1878 }
1879
1880 @Override
1881 public void close() {
1882 closeDumpHandlers(false);
1883 if (description != null) {
1884 printMetrics(description);
1885 }
1886 if (metricsEnabled && globalMetrics != null && metricValues != null) {
1887 globalMetrics.add(this);
1888 }
1889 metricValues = null;
1890 }
1891
1892 public void closeDumpHandlers(boolean ignoreErrors) {
1893 if (currentConfig != null) {
1894 currentConfig.closeDumpHandlers(ignoreErrors);
1895 }
1896 }
1897
1898 /**
1899 * Records how many times a given method has been compiled.
1900 */
1901 private static EconomicMap<Integer, Integer> compilations;
1902
1903 /**
1904 * Maintains maximum buffer size used by {@link #printMetrics(Description)} to minimize buffer
1905 * resizing during subsequent calls to this method.
1906 */
1907 private static int metricsBufSize = 50_000;
1908
1909 /**
1910 * Flag that allows the first call to {@link #printMetrics(Description)} to delete the file that
1911 * will be appended to.
1912 */
1913 private static boolean metricsFileDeleteCheckPerformed;
1914
1915 /**
1916 * Prints metric values in this object to the file (if any) specified by
1917 * {@link DebugOptions#MetricsFile}.
1918 */
1919 public void printMetrics(Description desc) {
1920 if (metricValues == null) {
1921 return;
1922 }
1923 String metricsFile = DebugOptions.MetricsFile.getValue(getOptions());
1924 if (metricsFile != null) {
1925 // Use identity to distinguish methods that have been redefined
1926 // or loaded by different class loaders.
1927 Object compilable = desc.compilable;
1928 Integer identity = System.identityHashCode(compilable);
1929 int compilationNr;
1930 synchronized (PRINT_METRICS_LOCK) {
1931 if (!metricsFileDeleteCheckPerformed) {
1932 metricsFileDeleteCheckPerformed = true;
1933 File file = new File(metricsFile);
1934 if (file.exists()) {
1935 // This can return false in case something like /dev/stdout
1936 // is specified. If the file is unwriteable, the file open
1937 // below will fail.
1938 file.delete();
1939 }
1940 }
1941 if (compilations == null) {
1942 compilationNr = 0;
1943 compilations = EconomicMap.create();
1944 } else {
1945 Integer value = compilations.get(identity);
1946 compilationNr = value == null ? 0 : value + 1;
1947 }
1948 compilations.put(identity, compilationNr);
1949 }
1950
1951 // Release the lock while generating the content to reduce contention.
1952 // This means `compilationNr` fields may show up out of order in the file.
1953 ByteArrayOutputStream baos = new ByteArrayOutputStream(metricsBufSize);
1954 PrintStream out = new PrintStream(baos);
1955 if (metricsFile.endsWith(".csv") || metricsFile.endsWith(".CSV")) {
1956 printMetricsCSV(out, compilable, identity, compilationNr, desc.identifier);
1957 } else {
1958 printMetrics(out, compilable, identity, compilationNr, desc.identifier);
1959 }
1960
1961 byte[] content = baos.toByteArray();
1962 Path path = Paths.get(metricsFile);
1963 synchronized (PRINT_METRICS_LOCK) {
1964 metricsBufSize = Math.max(metricsBufSize, content.length);
1965 try {
1966 Files.write(path, content, StandardOpenOption.CREATE, StandardOpenOption.APPEND);
1967 } catch (IOException e) {
1968 }
1969 }
1970 }
1971
1972 }
1973
1974 /**
1975 * Lock to serialize writes to {@link DebugOptions#MetricsFile}.
1976 */
1977 private static final Object PRINT_METRICS_LOCK = new Object();
1978
1979 /**
1980 * Appends metrics in CSV format to {@code out} for a single method compilation.
1981 *
1982 * @param identity the identity hash code of {@code compilable}
1983 * @param compilationNr where this compilation lies in the ordered sequence of all compilations
1984 * identified by {@code identity}
1985 * @param compilationId the runtime issued identifier for the compilation
1986 */
1987 private void printMetricsCSV(PrintStream out, Object compilable, Integer identity, int compilationNr, String compilationId) {
1988 String compilableName = compilable instanceof JavaMethod ? ((JavaMethod) compilable).format("%H.%n(%p)%R") : String.valueOf(compilable);
1989 String csvFormat = CSVUtil.buildFormatString("%s", "%s", "%d", "%s");
1990 String format = String.format(csvFormat, CSVUtil.Escape.escapeArgs(compilableName, identity, compilationNr, compilationId));
1991 char sep = CSVUtil.SEPARATOR;
1992 format += sep + "%s" + sep + "%s" + sep + "%s";
1993 for (MetricKey key : KeyRegistry.getKeys()) {
1994 int index = ((AbstractKey) key).getIndex();
1995 if (index < metricValues.length) {
1996 Pair<String, String> valueAndUnit = key.toCSVFormat(metricValues[index]);
1997 CSVUtil.Escape.println(out, format, CSVUtil.Escape.escape(key.getName()), valueAndUnit.getLeft(), valueAndUnit.getRight());
1998 }
1999 }
2000 }
2001
2002 /**
2003 * Appends metrics in a human readable format to {@code out} for a single method compilation.
2004 *
2005 * @param identity the identity hash code of {@code compilable}
2006 * @param compilationNr where this compilation lies in the ordered sequence of all compilations
2007 * identified by {@code identity}
2008 * @param compilationId the runtime issued identifier for the compilation
2009 */
2010 private void printMetrics(PrintStream out, Object compilable, Integer identity, int compilationNr, String compilationId) {
2011 String compilableName = compilable instanceof JavaMethod ? ((JavaMethod) compilable).format("%H.%n(%p)%R") : String.valueOf(compilable);
2012 int maxKeyWidth = compilableName.length();
2013 SortedMap<String, String> res = new TreeMap<>();
2014 for (MetricKey key : KeyRegistry.getKeys()) {
2015 int index = ((AbstractKey) key).getIndex();
2016 if (index < metricValues.length && metricValues[index] != 0) {
2017 String name = key.getName();
2018 long value = metricValues[index];
2019 String valueString;
2020 if (key instanceof TimerKey) {
2021 // Report timers in ms
2022 TimerKey timer = (TimerKey) key;
2023 long ms = timer.getTimeUnit().toMillis(value);
2024 if (ms == 0) {
2025 continue;
2026 }
2027 valueString = ms + "ms";
2028 } else {
2029 valueString = String.valueOf(value);
2030 }
2031 res.put(name, valueString);
2032 maxKeyWidth = Math.max(maxKeyWidth, name.length());
2033 }
2034 }
2035
2036 String title = String.format("%s [id:%s compilation:%d compilation_id:%s]", compilableName, identity, compilationNr, compilationId);
2037 out.println(new String(new char[title.length()]).replace('\0', '#'));
2038 out.printf("%s%n", title);
2039 out.println(new String(new char[title.length()]).replace('\0', '~'));
2040
2041 for (Map.Entry<String, String> e : res.entrySet()) {
2042 out.printf("%-" + String.valueOf(maxKeyWidth) + "s = %20s%n", e.getKey(), e.getValue());
2043 }
2044 out.println();
2045 }
2046 }