| /* |
| * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved. |
| * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. |
| * |
| * This code is free software; you can redistribute it and/or modify it |
| * under the terms of the GNU General Public License version 2 only, as |
| * published by the Free Software Foundation. |
| * |
| * This code is distributed in the hope that it will be useful, but WITHOUT |
| * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or |
| * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License |
| * version 2 for more details (a copy is included in the LICENSE file that |
| * accompanied this code). |
| * |
| * You should have received a copy of the GNU General Public License version |
| * 2 along with this work; if not, write to the Free Software Foundation, |
| * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. |
| * |
| * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA |
| * or visit www.oracle.com if you need additional information or have any |
| * questions. |
| */ |
| |
| |
| package org.graalvm.compiler.hotspot; |
| |
| import static org.graalvm.compiler.hotspot.HotSpotGraalCompiler.fmt; |
| |
| import java.util.Arrays; |
| |
| import org.graalvm.compiler.debug.TTY; |
| import org.graalvm.compiler.options.Option; |
| import org.graalvm.compiler.options.OptionKey; |
| import org.graalvm.compiler.options.OptionType; |
| import org.graalvm.compiler.options.OptionValues; |
| |
| import jdk.vm.ci.meta.ResolvedJavaMethod; |
| |
| /** |
| * A watch dog for reporting long running compilations. This is designed to be an always on |
| * mechanism for the purpose of getting better reports from customer sites. As such, it only exits |
| * the VM when it is very sure about a stuck compilation as opposed to only observing a long running |
| * compilation. In both cases, it logs messages to {@link TTY}. |
| * |
| * A watch dog thread is associated with each compiler thread. It wakes up every |
| * {@value #SPIN_TIMEOUT_MS} milliseconds to observe the state of the compiler thread. After the |
| * first {@link Options#CompilationWatchDogStartDelay} seconds of a specific compilation, the watch |
| * dog reports a long running compilation. Every |
| * {@link Options#CompilationWatchDogStackTraceInterval} seconds after that point in time where the |
| * same compilation is still executing, the watch dog takes a stack trace of the compiler thread. If |
| * more than {@value Options#NonFatalIdenticalCompilationSnapshots} contiguous identical stack |
| * traces are seen, the watch dog reports a stuck compilation and exits the VM. |
| */ |
| class CompilationWatchDog extends Thread implements AutoCloseable { |
| |
| public static class Options { |
| // @formatter:off |
| @Option(help = "Delay in seconds before watch dog monitoring a compilation (0 disables monitoring).", type = OptionType.Debug) |
| public static final OptionKey<Double> CompilationWatchDogStartDelay = new OptionKey<>(0.0D); |
| @Option(help = "Interval in seconds between a watch dog reporting stack traces for long running compilations.", type = OptionType.Debug) |
| public static final OptionKey<Double> CompilationWatchDogStackTraceInterval = new OptionKey<>(60.0D); |
| @Option(help = "Number of contiguous identical compiler thread stack traces allowed before the VM exits " + |
| "on the basis of a stuck compilation.", type = OptionType.Debug) |
| public static final OptionKey<Integer> NonFatalIdenticalCompilationSnapshots = new OptionKey<>(20); |
| // @formatter:on |
| } |
| |
| private enum WatchDogState { |
| /** |
| * The watch dog thread sleeps currently, either no method is currently compiled, or no |
| * method is compiled long enough to be monitored. |
| */ |
| SLEEPING, |
| /** |
| * The watch dog thread identified a compilation that already takes long enough to be |
| * interesting. It will sleep and wake up periodically and check if the current compilation |
| * takes too long. If it takes too long it will start collecting stack traces from the |
| * compiler thread. |
| */ |
| WATCHING_WITHOUT_STACK_INSPECTION, |
| /** |
| * The watch dog thread is fully monitoring the compiler thread. It takes stack traces |
| * periodically and sleeps again until the next period. If the number of stack traces |
| * reaches a certain upper bound and those stack traces are equal it will shut down the |
| * entire VM with an error. |
| */ |
| WATCHING_WITH_STACK_INSPECTION |
| } |
| |
| /** |
| * The number of milliseconds a watch dog thread sleeps between observing the state of the |
| * compilation thread it is associated with. Most compilations are expected to complete within |
| * this time period and thus not be actively monitored by the watch dog. |
| */ |
| private static final int SPIN_TIMEOUT_MS = 1000; |
| |
| private WatchDogState state = WatchDogState.SLEEPING; |
| private final Thread compilerThread; |
| private final long startDelayMilliseconds; |
| private final long stackTraceIntervalMilliseconds; |
| private final int nonFatalIdenticalCompilationSnapshots; |
| private volatile ResolvedJavaMethod currentMethod; |
| private volatile int currentId; |
| private ResolvedJavaMethod lastWatched; |
| |
| // The 4 fields below are for a single compilation being watched |
| private long elapsed; |
| private int traceIntervals; |
| private int numberOfIdenticalStackTraces; |
| private StackTraceElement[] lastStackTrace; |
| |
| CompilationWatchDog(Thread compilerThread, long startDelayMilliseconds, long stackTraceIntervalMilliseconds, int nonFatalIdenticalCompilationSnapshots) { |
| this.compilerThread = compilerThread; |
| this.setName("WatchDog" + getId() + "[" + compilerThread.getName() + "]"); |
| this.setPriority(Thread.MAX_PRIORITY); |
| this.setDaemon(true); |
| this.startDelayMilliseconds = startDelayMilliseconds; |
| this.stackTraceIntervalMilliseconds = stackTraceIntervalMilliseconds; |
| this.nonFatalIdenticalCompilationSnapshots = nonFatalIdenticalCompilationSnapshots; |
| } |
| |
| public void startCompilation(ResolvedJavaMethod method, int id) { |
| trace("start %s", fmt(method)); |
| this.currentMethod = method; |
| this.currentId = id; |
| } |
| |
| public void stopCompilation() { |
| trace(" stop %s", fmt(currentMethod)); |
| this.currentMethod = null; |
| } |
| |
| private void reset() { |
| elapsed = 0; |
| traceIntervals = 0; |
| numberOfIdenticalStackTraces = 0; |
| lastWatched = null; |
| lastStackTrace = null; |
| state = WatchDogState.SLEEPING; |
| } |
| |
| private void tick(WatchDogState newState) { |
| state = newState; |
| } |
| |
| /** |
| * Saves the current stack trace {@link StackTraceElement} of the monitored compiler thread |
| * {@link CompilationWatchDog#compilerThread}. |
| * |
| * @param newStackTrace the current stack trace of the monitored compiler thread |
| * @return {@code true} if the stack trace is equal to the last stack trace (or if it is the |
| * first one) and {@code false} if it is not equal to the last one. |
| */ |
| private boolean recordStackTrace(StackTraceElement[] newStackTrace) { |
| if (lastStackTrace == null) { |
| lastStackTrace = newStackTrace; |
| return true; |
| } |
| if (!Arrays.equals(lastStackTrace, newStackTrace)) { |
| lastStackTrace = newStackTrace; |
| return false; |
| } |
| return true; |
| } |
| |
| /** |
| * Set to true to debug the watch dog. |
| */ |
| private static final boolean DEBUG = Boolean.getBoolean("debug.graal.CompilationWatchDog"); |
| |
| private void trace(String format, Object... args) { |
| if (DEBUG) { |
| TTY.println(this + ": " + String.format(format, args)); |
| } |
| } |
| |
| private static long ms(double seconds) { |
| return (long) seconds * 1000; |
| } |
| |
| private static double secs(long ms) { |
| return (double) ms / 1000; |
| } |
| |
| @Override |
| public String toString() { |
| return getName(); |
| } |
| |
| @Override |
| public void run() { |
| try { |
| trace("Started%n", this); |
| while (true) { |
| // get a copy of the last set method |
| final ResolvedJavaMethod currentlyCompiling = currentMethod; |
| if (currentlyCompiling == null) { |
| // continue sleeping, compilation is either over before starting |
| // to watch the compiler thread or no compilation at all started |
| reset(); |
| } else { |
| switch (state) { |
| case SLEEPING: |
| lastWatched = currentlyCompiling; |
| elapsed = 0; |
| tick(WatchDogState.WATCHING_WITHOUT_STACK_INSPECTION); |
| break; |
| case WATCHING_WITHOUT_STACK_INSPECTION: |
| if (currentlyCompiling.equals(lastWatched)) { |
| if (elapsed >= startDelayMilliseconds) { |
| // we looked at the same compilation for a certain time |
| // so now we start to collect stack traces |
| tick(WatchDogState.WATCHING_WITH_STACK_INSPECTION); |
| trace("changes mode to watching with stack traces"); |
| } else { |
| // we still compile the same method but won't collect traces |
| // yet |
| trace("watching without stack traces [%.2f seconds]", secs(elapsed)); |
| } |
| elapsed += SPIN_TIMEOUT_MS; |
| } else { |
| // compilation finished before we exceeded initial watching |
| // period |
| reset(); |
| } |
| break; |
| case WATCHING_WITH_STACK_INSPECTION: |
| if (currentlyCompiling.equals(lastWatched)) { |
| if (elapsed >= startDelayMilliseconds + (traceIntervals * stackTraceIntervalMilliseconds)) { |
| trace("took a stack trace"); |
| boolean newStackTrace = recordStackTrace(compilerThread.getStackTrace()); |
| if (!newStackTrace) { |
| trace("%d identical stack traces in a row", numberOfIdenticalStackTraces); |
| numberOfIdenticalStackTraces = 0; |
| } |
| numberOfIdenticalStackTraces++; |
| if (numberOfIdenticalStackTraces > nonFatalIdenticalCompilationSnapshots) { |
| synchronized (CompilationWatchDog.class) { |
| TTY.printf("======================= WATCH DOG THREAD =======================%n" + |
| "%s took %d identical stack traces, which indicates a stuck compilation (id=%d) of %s%n%sExiting VM%n", this, |
| numberOfIdenticalStackTraces, currentId, fmt(currentMethod), fmt(lastStackTrace)); |
| System.exit(-1); |
| } |
| } else if (newStackTrace) { |
| synchronized (CompilationWatchDog.class) { |
| TTY.printf("======================= WATCH DOG THREAD =======================%n" + |
| "%s detected long running compilation (id=%d) of %s [%.2f seconds]%n%s", this, currentId, fmt(currentMethod), |
| secs(elapsed), fmt(lastStackTrace)); |
| } |
| } |
| traceIntervals++; |
| } else { |
| // we still watch the compilation in the same trace interval |
| trace("watching with stack traces [%.2f seconds]", secs(elapsed)); |
| } |
| elapsed += SPIN_TIMEOUT_MS; |
| } else { |
| // compilation finished before we are able to collect stack |
| // traces |
| reset(); |
| } |
| break; |
| default: |
| break; |
| } |
| } |
| try { |
| Thread.sleep(SPIN_TIMEOUT_MS); |
| } catch (InterruptedException e) { |
| // Silently swallow |
| } |
| } |
| } catch (VirtualMachineError vmError) { |
| /* |
| * We encounter a VM error. This includes for example OutOfMemoryExceptions. In such a |
| * case we silently swallow the error. If it happens again the application thread will |
| * most likely encounter the same problem. If not the watchdog thread will no longer |
| * monitor the compilation and thus the error cannot happen again. |
| */ |
| } catch (Throwable t) { |
| /* |
| * A real exception happened on the compilation watchdog. This is unintended behavior |
| * and must not happen in any case. |
| */ |
| throw new InternalError(String.format("%s encountered an exception%n%s%n", this, fmt(t)), t); |
| } |
| } |
| |
| private static final ThreadLocal<CompilationWatchDog> WATCH_DOGS = new ThreadLocal<>(); |
| |
| /** |
| * Opens a scope for watching the compilation of a given method. |
| * |
| * @param method a method about to be compiled |
| * @param id compilation request identifier |
| * @return {@code null} if the compilation watch dog is disabled otherwise this object. The |
| * returned value should be used in a {@code try}-with-resources statement whose scope |
| * is the whole compilation so that leaving the scope will cause {@link #close()} to be |
| * called. |
| */ |
| static CompilationWatchDog watch(ResolvedJavaMethod method, int id, OptionValues options) { |
| long startDelayMilliseconds = ms(Options.CompilationWatchDogStartDelay.getValue(options)); |
| if (startDelayMilliseconds > 0.0D) { |
| // Lazily get a watch dog thread for the current compiler thread |
| CompilationWatchDog watchDog = WATCH_DOGS.get(); |
| if (watchDog == null) { |
| Thread currentThread = currentThread(); |
| long stackTraceIntervalMilliseconds = ms(Options.CompilationWatchDogStackTraceInterval.getValue(options)); |
| int nonFatalIdenticalCompilationSnapshots = Options.NonFatalIdenticalCompilationSnapshots.getValue(options); |
| watchDog = new CompilationWatchDog(currentThread, startDelayMilliseconds, stackTraceIntervalMilliseconds, nonFatalIdenticalCompilationSnapshots); |
| WATCH_DOGS.set(watchDog); |
| watchDog.start(); |
| } |
| watchDog.startCompilation(method, id); |
| return watchDog; |
| } |
| return null; |
| } |
| |
| @Override |
| public void close() { |
| stopCompilation(); |
| } |
| } |
