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 */ 23package org.graalvm.compiler.debug; 24 25import static java.util.FormattableFlags.LEFT_JUSTIFY; 26import static java.util.FormattableFlags.UPPERCASE; 27import static org.graalvm.compiler.debug.DebugOptions.Count; 28import static org.graalvm.compiler.debug.DebugOptions.Counters; 29import static org.graalvm.compiler.debug.DebugOptions.Dump; 30import static org.graalvm.compiler.debug.DebugOptions.DumpOnError; 31import static org.graalvm.compiler.debug.DebugOptions.DumpOnPhaseChange; 32import static org.graalvm.compiler.debug.DebugOptions.ListMetrics; 33import static org.graalvm.compiler.debug.DebugOptions.Log; 34import static org.graalvm.compiler.debug.DebugOptions.MemUseTrackers; 35import static org.graalvm.compiler.debug.DebugOptions.Time; 36import static org.graalvm.compiler.debug.DebugOptions.Timers; 37import static org.graalvm.compiler.debug.DebugOptions.TrackMemUse; 38 39import java.io.ByteArrayOutputStream; 40import java.io.File; 41import java.io.IOException; 42import java.io.PrintStream; 43import java.nio.file.Files; 44import java.nio.file.Path; 45import java.nio.file.Paths; 46import java.nio.file.StandardOpenOption; 47import java.util.ArrayList; 48import java.util.Arrays; 49import java.util.Collection; 50import java.util.Collections; 51import java.util.Formatter; 52import java.util.List; 53import java.util.Map; 54import java.util.SortedMap; 55import java.util.TreeMap; 56 57import org.graalvm.compiler.options.OptionKey; 58import org.graalvm.compiler.options.OptionValues; 59import org.graalvm.util.EconomicMap; 60import org.graalvm.util.EconomicSet; 61import org.graalvm.util.Pair; 62 63import 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 */ 75public 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} 2047