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.internal;
  24 
  25 import java.io.PrintStream;
  26 import java.util.Iterator;
  27 import java.util.concurrent.Callable;
  28 import java.util.concurrent.atomic.AtomicLong;
  29 
  30 import org.graalvm.compiler.debug.Debug;
  31 import org.graalvm.compiler.debug.DebugConfig;
  32 import org.graalvm.compiler.debug.DebugDumpHandler;
  33 import org.graalvm.compiler.debug.DebugVerifyHandler;
  34 import org.graalvm.compiler.debug.DelegatingDebugConfig;
  35 import org.graalvm.compiler.debug.Indent;
  36 import org.graalvm.compiler.debug.JavaMethodContext;
  37 import org.graalvm.compiler.debug.TTY;
  38 import org.graalvm.compiler.debug.TopLevelDebugConfig;
  39 
  40 import jdk.vm.ci.meta.JavaMethod;
  41 
  42 public final class DebugScope implements Debug.Scope {
  43 
  44     private final class IndentImpl implements Indent {
  45 
  46         private static final String INDENTATION_INCREMENT = "  ";
  47 
  48         final String indent;
  49         final IndentImpl parentIndent;
  50 
  51         IndentImpl(IndentImpl parentIndent) {
  52             this.parentIndent = parentIndent;
  53             this.indent = (parentIndent == null ? "" : parentIndent.indent + INDENTATION_INCREMENT);
  54         }
  55 
  56         private boolean logScopeName() {
  57             return logScopeName;
  58         }
  59 
  60         private void printScopeName(StringBuilder str, boolean isCurrent) {
  61             if (logScopeName) {
  62                 boolean parentPrinted = false;
  63                 if (parentIndent != null) {
  64                     parentPrinted = parentIndent.logScopeName();
  65                     parentIndent.printScopeName(str, false);
  66                 }
  67                 /*
  68                  * Always print the current scope, scopes with context and the any scope whose
  69                  * parent didn't print. This ensure the first new scope always shows up.
  70                  */
  71                 if (isCurrent || printContext(null) != 0 || !parentPrinted) {
  72                     str.append(indent).append("[thread:").append(Thread.currentThread().getId()).append("] scope: ").append(getQualifiedName()).append(System.lineSeparator());
  73                 }
  74                 printContext(str);
  75                 logScopeName = false;
  76             }
  77         }
  78 
  79         /**
  80          * Print or count the context objects for the current scope.
  81          */
  82         private int printContext(StringBuilder str) {
  83             int count = 0;
  84             if (context != null && context.length > 0) {
  85                 // Include some context in the scope output
  86                 for (Object contextObj : context) {
  87                     if (contextObj instanceof JavaMethodContext || contextObj instanceof JavaMethod) {
  88                         if (str != null) {
  89                             str.append(indent).append("Context: ").append(contextObj).append(System.lineSeparator());
  90                         }
  91                         count++;
  92                     }
  93                 }
  94             }
  95             return count;
  96         }
  97 
  98         public void log(int logLevel, String msg, Object... args) {
  99             if (isLogEnabled(logLevel)) {
 100                 StringBuilder str = new StringBuilder();
 101                 printScopeName(str, true);
 102                 str.append(indent);
 103                 String result = args.length == 0 ? msg : String.format(msg, args);
 104                 String lineSep = System.lineSeparator();
 105                 str.append(result.replace(lineSep, lineSep.concat(indent)));
 106                 str.append(lineSep);
 107                 output.append(str);
 108                 lastUsedIndent = this;
 109             }
 110         }
 111 
 112         IndentImpl indent() {
 113             lastUsedIndent = new IndentImpl(this);
 114             return lastUsedIndent;
 115         }
 116 
 117         @Override
 118         public void close() {
 119             if (parentIndent != null) {
 120                 lastUsedIndent = parentIndent;
 121             }
 122         }
 123     }
 124 
 125     /**
 126      * Interface for an additional information object per scope. The information object will be
 127      * given to child scopes, but can be explicitly set with
 128      * {@link DebugScope#enhanceWithExtraInfo(CharSequence, ExtraInfo, boolean, Object...)}
 129      */
 130     public interface ExtraInfo {
 131 
 132     }
 133 
 134     private static final ThreadLocal<DebugScope> instanceTL = new ThreadLocal<>();
 135     private static final ThreadLocal<DebugScope> lastClosedTL = new ThreadLocal<>();
 136     private static final ThreadLocal<DebugConfig> configTL = new ThreadLocal<>();
 137     private static final ThreadLocal<Throwable> lastExceptionThrownTL = new ThreadLocal<>();
 138 
 139     private final DebugScope parent;
 140     private final DebugConfig parentConfig;
 141     private final boolean sandbox;
 142     private IndentImpl lastUsedIndent;
 143     private boolean logScopeName;
 144 
 145     private final Object[] context;
 146 
 147     private DebugValueMap valueMap;
 148 
 149     private String qualifiedName;
 150     private final String unqualifiedName;
 151 
 152     private final ExtraInfo extraInfo;
 153 
 154     private static final AtomicLong uniqueScopeId = new AtomicLong();
 155     private final long scopeId;
 156 
 157     private static final char SCOPE_SEP = '.';
 158 
 159     private boolean countEnabled;
 160     private boolean timeEnabled;
 161     private boolean memUseTrackingEnabled;
 162     private boolean verifyEnabled;
 163     private boolean methodMetricsEnabled;
 164 
 165     private int currentDumpLevel;
 166     private int currentLogLevel;
 167 
 168     private PrintStream output;
 169 
 170     public static long getCurrentGlobalScopeId() {
 171         return uniqueScopeId.get();
 172     }
 173 
 174     public static DebugScope getInstance() {
 175         DebugScope result = instanceTL.get();
 176         if (result == null) {
 177             DebugScope topLevelDebugScope = new DebugScope(Thread.currentThread());
 178             instanceTL.set(topLevelDebugScope);
 179             return topLevelDebugScope;
 180         } else {
 181             return result;
 182         }
 183     }
 184 
 185     public static DebugConfig getConfig() {
 186         return configTL.get();
 187     }
 188 
 189     static final Object[] EMPTY_CONTEXT = new Object[0];
 190 
 191     private DebugScope(Thread thread) {
 192         this(thread.getName(), null, uniqueScopeId.incrementAndGet(), null, false);
 193         computeValueMap(thread.getName());
 194         DebugValueMap.registerTopLevel(getValueMap());
 195     }
 196 
 197     private DebugScope(String unqualifiedName, DebugScope parent, long scopeId, ExtraInfo metaInfo, boolean sandbox, Object... context) {
 198         this.parent = parent;
 199         this.sandbox = sandbox;
 200         this.parentConfig = getConfig();
 201         this.context = context;
 202         this.scopeId = scopeId;
 203         this.unqualifiedName = unqualifiedName;
 204         this.extraInfo = metaInfo;
 205         if (parent != null) {
 206             logScopeName = !unqualifiedName.equals("");
 207         } else {
 208             logScopeName = true;
 209         }
 210 
 211         this.output = TTY.out;
 212         assert context != null;
 213     }
 214 
 215     private void computeValueMap(String name) {
 216         if (parent != null) {
 217             for (DebugValueMap child : parent.getValueMap().getChildren()) {
 218                 if (child.getName().equals(name)) {
 219                     this.valueMap = child;
 220                     return;
 221                 }
 222             }
 223             this.valueMap = new DebugValueMap(name);
 224             parent.getValueMap().addChild(this.valueMap);
 225         } else {
 226             this.valueMap = new DebugValueMap(name);
 227         }
 228     }
 229 
 230     @Override
 231     public void close() {
 232         instanceTL.set(parent);
 233         configTL.set(parentConfig);
 234         lastClosedTL.set(this);
 235     }
 236 
 237     public boolean isDumpEnabled(int dumpLevel) {
 238         assert dumpLevel > 0;
 239         return currentDumpLevel >= dumpLevel;
 240     }
 241 
 242     /**
 243      * Enable dumping at the new {@code dumpLevel} for the remainder of enclosing scopes. This only
 244      * works if a {@link TopLevelDebugConfig} was installed at a higher scope.
 245      *
 246      * @param dumpLevel
 247      */
 248     public static void setDumpLevel(int dumpLevel) {
 249         TopLevelDebugConfig config = fetchTopLevelDebugConfig("setDebugLevel");
 250         if (config != null) {
 251             config.override(DelegatingDebugConfig.Level.DUMP, dumpLevel);
 252             recursiveUpdateFlags();
 253         }
 254     }
 255 
 256     /**
 257      * Enable logging at the new {@code logLevel} for the remainder of enclosing scopes. This only
 258      * works if a {@link TopLevelDebugConfig} was installed at a higher scope.
 259      *
 260      * @param logLevel
 261      */
 262     public static void setLogLevel(int logLevel) {
 263         TopLevelDebugConfig config = fetchTopLevelDebugConfig("setLogLevel");
 264         if (config != null) {
 265             config.override(DelegatingDebugConfig.Level.LOG, logLevel);
 266             config.delegate(DelegatingDebugConfig.Feature.LOG_METHOD);
 267             recursiveUpdateFlags();
 268         }
 269     }
 270 
 271     private static void recursiveUpdateFlags() {
 272         DebugScope c = DebugScope.getInstance();
 273         while (c != null) {
 274             c.updateFlags();
 275             c = c.parent;
 276         }
 277     }
 278 
 279     private static TopLevelDebugConfig fetchTopLevelDebugConfig(String msg) {
 280         DebugConfig config = getConfig();
 281         if (config instanceof TopLevelDebugConfig) {
 282             return (TopLevelDebugConfig) config;
 283         } else {
 284             if (config == null) {
 285                 TTY.println("DebugScope.%s ignored because debugging is disabled", msg);
 286             } else {
 287                 TTY.println("DebugScope.%s ignored because top level delegate config missing", msg);
 288             }
 289             return null;
 290         }
 291     }
 292 
 293     public boolean isVerifyEnabled() {
 294         return verifyEnabled;
 295     }
 296 
 297     public boolean isLogEnabled(int logLevel) {
 298         assert logLevel > 0;
 299         return currentLogLevel >= logLevel;
 300     }
 301 
 302     public boolean isCountEnabled() {
 303         return countEnabled;
 304     }
 305 
 306     public boolean isTimeEnabled() {
 307         return timeEnabled;
 308     }
 309 
 310     public boolean isMethodMeterEnabled() {
 311         return methodMetricsEnabled;
 312     }
 313 
 314     public boolean isMemUseTrackingEnabled() {
 315         return memUseTrackingEnabled;
 316     }
 317 
 318     public void log(int logLevel, String msg, Object... args) {
 319         if (isLogEnabled(logLevel)) {
 320             getLastUsedIndent().log(logLevel, msg, args);
 321         }
 322     }
 323 
 324     public ExtraInfo getExtraInfo() {
 325         return extraInfo;
 326     }
 327 
 328     public long scopeId() {
 329         return scopeId;
 330     }
 331 
 332     public void dump(int dumpLevel, Object object, String formatString, Object... args) {
 333         if (isDumpEnabled(dumpLevel)) {
 334             DebugConfig config = getConfig();
 335             if (config != null) {
 336                 String message = String.format(formatString, args);
 337                 for (DebugDumpHandler dumpHandler : config.dumpHandlers()) {
 338                     dumpHandler.dump(object, message);
 339                 }
 340             }
 341         }
 342     }
 343 
 344     /**
 345      * This method exists mainly to allow a debugger (e.g., Eclipse) to force dump a graph.
 346      */
 347     public static void forceDump(Object object, String format, Object... args) {
 348         DebugConfig config = getConfig();
 349         if (config != null) {
 350             String message = String.format(format, args);
 351             for (DebugDumpHandler dumpHandler : config.dumpHandlers()) {
 352                 dumpHandler.dump(object, message);
 353             }
 354         } else {
 355             TTY.println("Forced dump ignored because debugging is disabled - use -Dgraal.Dump=xxx");
 356         }
 357     }
 358 
 359     /**
 360      * @see Debug#verify(Object, String)
 361      */
 362     public void verify(Object object, String formatString, Object... args) {
 363         if (isVerifyEnabled()) {
 364             DebugConfig config = getConfig();
 365             if (config != null) {
 366                 String message = String.format(formatString, args);
 367                 for (DebugVerifyHandler handler : config.verifyHandlers()) {
 368                     handler.verify(object, message);
 369                 }
 370             }
 371         }
 372     }
 373 
 374     /**
 375      * Creates and enters a new debug scope which is either a child of the current scope or a
 376      * disjoint top level scope.
 377      *
 378      * @param name the name of the new scope
 379      * @param sandboxConfig the configuration to use for a new top level scope, or null if the new
 380      *            scope should be a child scope
 381      * @param newContextObjects objects to be appended to the debug context
 382      * @return the new scope which will be exited when its {@link #close()} method is called
 383      */
 384     public DebugScope scope(CharSequence name, DebugConfig sandboxConfig, Object... newContextObjects) {
 385         DebugScope newScope = null;
 386         if (sandboxConfig != null) {
 387             newScope = new DebugScope(name.toString(), this, uniqueScopeId.incrementAndGet(), null, true, newContextObjects);
 388             configTL.set(sandboxConfig);
 389         } else {
 390             newScope = this.createChild(name.toString(), this.extraInfo, newContextObjects);
 391         }
 392         instanceTL.set(newScope);
 393         newScope.updateFlags();
 394         return newScope;
 395     }
 396 
 397     public DebugScope enhanceWithExtraInfo(CharSequence name, ExtraInfo newInfo, boolean newId, Object... newContext) {
 398         DebugScope newScope = createChild(name.toString(), newInfo, newId ? uniqueScopeId.incrementAndGet() : this.scopeId, newContext);
 399         instanceTL.set(newScope);
 400         newScope.updateFlags();
 401         return newScope;
 402     }
 403 
 404     public RuntimeException handle(Throwable e) {
 405         DebugScope lastClosed = lastClosedTL.get();
 406         assert lastClosed.parent == this : "Debug.handle() used with no matching Debug.scope(...) or Debug.sandbox(...)";
 407         if (e != lastExceptionThrownTL.get()) {
 408             RuntimeException newException = null;
 409             instanceTL.set(lastClosed);
 410             try (DebugScope s = lastClosed) {
 411                 newException = s.interceptException(e);
 412             }
 413             assert instanceTL.get() == this;
 414             assert lastClosed == lastClosedTL.get();
 415             if (newException == null) {
 416                 lastExceptionThrownTL.set(e);
 417             } else {
 418                 lastExceptionThrownTL.set(newException);
 419                 throw newException;
 420             }
 421         }
 422         if (e instanceof Error) {
 423             throw (Error) e;
 424         }
 425         if (e instanceof RuntimeException) {
 426             throw (RuntimeException) e;
 427         }
 428         throw new RuntimeException(e);
 429     }
 430 
 431     private void updateFlags() {
 432         DebugConfig config = getConfig();
 433         if (config == null) {
 434             countEnabled = false;
 435             memUseTrackingEnabled = false;
 436             timeEnabled = false;
 437             verifyEnabled = false;
 438             currentDumpLevel = 0;
 439             methodMetricsEnabled = false;
 440             // Be pragmatic: provide a default log stream to prevent a crash if the stream is not
 441             // set while logging
 442             output = TTY.out;
 443         } else {
 444             countEnabled = config.isCountEnabled();
 445             memUseTrackingEnabled = config.isMemUseTrackingEnabled();
 446             timeEnabled = config.isTimeEnabled();
 447             verifyEnabled = config.isVerifyEnabled();
 448             output = config.output();
 449             currentDumpLevel = config.getDumpLevel();
 450             currentLogLevel = config.getLogLevel();
 451             methodMetricsEnabled = config.isMethodMeterEnabled();
 452         }
 453     }
 454 
 455     @SuppressWarnings("try")
 456     private RuntimeException interceptException(final Throwable e) {
 457         final DebugConfig config = getConfig();
 458         if (config != null) {
 459             try (DebugScope s = scope("InterceptException", null, e)) {
 460                 return config.interceptException(e);
 461             } catch (Throwable t) {
 462                 return new RuntimeException("Exception while intercepting exception", t);
 463             }
 464         }
 465         return null;
 466     }
 467 
 468     private DebugValueMap getValueMap() {
 469         if (valueMap == null) {
 470             computeValueMap(unqualifiedName);
 471         }
 472         return valueMap;
 473     }
 474 
 475     long getCurrentValue(int index) {
 476         return getValueMap().getCurrentValue(index);
 477     }
 478 
 479     void setCurrentValue(int index, long l) {
 480         getValueMap().setCurrentValue(index, l);
 481     }
 482 
 483     private DebugScope createChild(String newName, ExtraInfo newInfo, Object[] newContext) {
 484         return new DebugScope(newName, this, this.scopeId, newInfo, false, newContext);
 485     }
 486 
 487     private DebugScope createChild(String newName, ExtraInfo newInfo, long newId, Object[] newContext) {
 488         return new DebugScope(newName, this, newId, newInfo, false, newContext);
 489     }
 490 
 491     public Iterable<Object> getCurrentContext() {
 492         final DebugScope scope = this;
 493         return new Iterable<Object>() {
 494 
 495             @Override
 496             public Iterator<Object> iterator() {
 497                 return new Iterator<Object>() {
 498 
 499                     DebugScope currentScope = scope;
 500                     int objectIndex;
 501 
 502                     @Override
 503                     public boolean hasNext() {
 504                         selectScope();
 505                         return currentScope != null;
 506                     }
 507 
 508                     private void selectScope() {
 509                         while (currentScope != null && currentScope.context.length <= objectIndex) {
 510                             currentScope = currentScope.sandbox ? null : currentScope.parent;
 511                             objectIndex = 0;
 512                         }
 513                     }
 514 
 515                     @Override
 516                     public Object next() {
 517                         selectScope();
 518                         if (currentScope != null) {
 519                             return currentScope.context[objectIndex++];
 520                         }
 521                         throw new IllegalStateException("May only be called if there is a next element.");
 522                     }
 523 
 524                     @Override
 525                     public void remove() {
 526                         throw new UnsupportedOperationException("This iterator is read only.");
 527                     }
 528                 };
 529             }
 530         };
 531     }
 532 
 533     public static <T> T call(Callable<T> callable) {
 534         try {
 535             return callable.call();
 536         } catch (Exception e) {
 537             if (e instanceof RuntimeException) {
 538                 throw (RuntimeException) e;
 539             } else {
 540                 throw new RuntimeException(e);
 541             }
 542         }
 543     }
 544 
 545     public void setConfig(DebugConfig newConfig) {
 546         configTL.set(newConfig);
 547         updateFlags();
 548     }
 549 
 550     public String getQualifiedName() {
 551         if (qualifiedName == null) {
 552             if (parent == null) {
 553                 qualifiedName = unqualifiedName;
 554             } else {
 555                 qualifiedName = parent.getQualifiedName() + SCOPE_SEP + unqualifiedName;
 556             }
 557         }
 558         return qualifiedName;
 559     }
 560 
 561     public Indent pushIndentLogger() {
 562         lastUsedIndent = getLastUsedIndent().indent();
 563         return lastUsedIndent;
 564     }
 565 
 566     public IndentImpl getLastUsedIndent() {
 567         if (lastUsedIndent == null) {
 568             if (parent != null) {
 569                 lastUsedIndent = new IndentImpl(parent.getLastUsedIndent());
 570             } else {
 571                 lastUsedIndent = new IndentImpl(null);
 572             }
 573         }
 574         return lastUsedIndent;
 575     }
 576 }