1 /* 2 * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved. 3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. 4 * 5 * This code is free software; you can redistribute it and/or modify it 6 * under the terms of the GNU General Public License version 2 only, as 7 * published by the Free Software Foundation. 8 * 9 * This code is distributed in the hope that it will be useful, but WITHOUT 10 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or 11 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License 12 * version 2 for more details (a copy is included in the LICENSE file that 13 * accompanied this code). 14 * 15 * You should have received a copy of the GNU General Public License version 16 * 2 along with this work; if not, write to the Free Software Foundation, 17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. 18 * 19 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA 20 * or visit www.oracle.com if you need additional information or have any 21 * questions. 22 */ 23 24 25 package org.graalvm.compiler.hotspot; 26 27 import static org.graalvm.compiler.hotspot.HotSpotGraalCompiler.fmt; 28 import static org.graalvm.compiler.hotspot.HotSpotGraalOptionValues.GRAAL_OPTION_PROPERTY_PREFIX; 29 30 import java.util.Arrays; 31 import java.util.HashMap; 32 import java.util.Map; 33 import java.util.concurrent.atomic.AtomicInteger; 34 35 import org.graalvm.compiler.debug.TTY; 36 import org.graalvm.compiler.options.Option; 37 import org.graalvm.compiler.options.OptionKey; 38 import org.graalvm.compiler.options.OptionType; 39 import org.graalvm.compiler.options.OptionValues; 40 41 import jdk.vm.ci.code.CompilationRequest; 42 43 /** 44 * A watch dog that monitors the duration and compilation rate during a 45 * {@linkplain HotSpotGraalRuntimeProvider#isBootstrapping() bootstrap}. If time spent bootstrapping 46 * exceeds a specified timeout or the compilation rate falls below a given ratio of the maximum 47 * observed compilation rate (i.e., compilation slows down too much), the compiler will ignore all 48 * subsequent compilation requests, effectively draining the bootstrap completion queue and 49 * expediting completion of bootstrap. Note that the compilation rate is computed over the whole 50 * execution, not just the most recent measurement period. This means a sudden but temporary drop in 51 * any given measurement period won't cause bootstrapping to terminate early. 52 * 53 * This mechanism is based on past observations that a significantly falling bootstrap compilation 54 * rate implies a configuration where bootstrapping will take an unreasonably long time and it's 55 * better to drain the bootstrap compilation queue at some point that risk triggering timeouts in 56 * external harnesses such as integration tests. 57 */ 58 final class BootstrapWatchDog extends Thread { 59 60 public static class Options { 61 // @formatter:off 62 @Option(help = "Ratio of the maximum compilation rate below which the bootstrap compilation rate must not fall " + 63 "(0 or less disables monitoring).", type = OptionType.Debug) 64 public static final OptionKey<Double> BootstrapWatchDogCriticalRateRatio = new OptionKey<>(0.25D); 65 @Option(help = "Maximum time in minutes to spend bootstrapping (0 to disable this limit).", type = OptionType.Debug) 66 public static final OptionKey<Double> BootstrapTimeout = new OptionKey<>(15D); 67 // @formatter:on 68 } 69 70 /** 71 * Count of completed compilations. This is updated by the compiler threads and read by the 72 * watch dog thread. 73 */ 74 private final AtomicInteger compilations = new AtomicInteger(); 75 76 /** 77 * Set to true once the compilation rate drops too low or bootstrapping times out. 78 */ 79 private boolean hitCriticalRateOrTimeout; 80 81 /** 82 * The maximum compilation rate seen during execution. 83 */ 84 private double maxRate; 85 86 private final HotSpotGraalRuntimeProvider graalRuntime; 87 88 /** 89 * Creates and returns a {@link BootstrapWatchDog} if 90 * {@link Options#BootstrapWatchDogCriticalRateRatio} is not set to 0 otherwise returns 91 * {@code null}. 92 */ maybeCreate(HotSpotGraalRuntimeProvider graalRuntime)93 static BootstrapWatchDog maybeCreate(HotSpotGraalRuntimeProvider graalRuntime) { 94 OptionValues options = graalRuntime.getOptions(); 95 int timeout = (int) (Options.BootstrapTimeout.getValue(options) * 60); 96 double maxRateDecrease = Options.BootstrapWatchDogCriticalRateRatio.getValue(options); 97 return maxRateDecrease <= 0.0D && timeout == 0 ? null : new BootstrapWatchDog(graalRuntime, timeout, maxRateDecrease); 98 } 99 BootstrapWatchDog(HotSpotGraalRuntimeProvider graalRuntime, int timeout, double maxRateDecrease)100 private BootstrapWatchDog(HotSpotGraalRuntimeProvider graalRuntime, int timeout, double maxRateDecrease) { 101 this.setName(getClass().getSimpleName()); 102 this.start(); 103 this.graalRuntime = graalRuntime; 104 this.timeout = timeout; 105 this.maxRateDecrease = maxRateDecrease; 106 } 107 108 /** 109 * Set to true to debug the watch dog. 110 */ 111 private static final boolean DEBUG = Boolean.getBoolean("debug.graal.BootstrapWatchDog"); 112 113 /** 114 * Seconds to delay before starting to measure the compilation rate. 115 */ 116 private static final int INITIAL_DELAY = 10; 117 118 /** 119 * Seconds between each compilation rate measurement. 120 */ 121 private static final long EPOCH = 5; 122 123 /** 124 * Time in seconds before stopping a bootstrap. 125 */ 126 private final int timeout; 127 128 /** 129 * The watch dog {@link #hitCriticalCompilationRateOrTimeout() hits} a critical compilation rate 130 * if the current compilation rate falls below this ratio of the maximum compilation rate. 131 */ 132 private final double maxRateDecrease; 133 134 @Override run()135 public void run() { 136 if (DEBUG) { 137 TTY.printf("%nStarted %s%n", this); 138 } 139 long start = System.currentTimeMillis(); 140 Map<Thread, Watch> requestsAtTimeout = null; 141 Map<Thread, StackTraceElement[]> stacksAtTimeout = null; 142 try { 143 Thread.sleep(INITIAL_DELAY * 1000); 144 while (true) { 145 int currentCompilations = compilations.get(); 146 long elapsed = System.currentTimeMillis() - start; 147 double rate = currentCompilations / seconds(elapsed); 148 if (DEBUG) { 149 TTY.printf("%.2f: compilation rate is %.2f/sec%n", seconds(elapsed), rate); 150 } 151 if (rate > maxRate) { 152 maxRate = rate; 153 } else if (rate < (maxRate * maxRateDecrease)) { 154 TTY.printf("%nAfter %.2f seconds bootstrapping, compilation rate is %.2f compilations per second " + 155 "which is below %.2f times the max compilation rate of %.2f%n", seconds(elapsed), rate, maxRateDecrease, maxRate); 156 TTY.printf("To enable monitoring of long running individual compilations, re-run with -D%s%s=%.2f%n", 157 GRAAL_OPTION_PROPERTY_PREFIX, CompilationWatchDog.Options.CompilationWatchDogStartDelay.getName(), 158 seconds(elapsed) - 5); 159 hitCriticalRateOrTimeout = true; 160 return; 161 } 162 if (elapsed > timeout * 1000) { 163 if (requestsAtTimeout == null) { 164 requestsAtTimeout = snapshotRequests(); 165 stacksAtTimeout = new HashMap<>(); 166 for (Thread t : requestsAtTimeout.keySet()) { 167 stacksAtTimeout.put(t, t.getStackTrace()); 168 } 169 } else { 170 TTY.printf("%nHit bootstrapping timeout after %.2f seconds%n", seconds(elapsed)); 171 Map<Thread, Watch> requestsNow = snapshotRequests(); 172 for (Map.Entry<Thread, Watch> e : requestsAtTimeout.entrySet()) { 173 Thread t = e.getKey(); 174 CompilationRequest request1 = requestsAtTimeout.get(t).request; 175 CompilationRequest request2 = requestsNow.get(t).request; 176 if (request1 != null && request1 == request2) { 177 StackTraceElement[] stackTraceNow = t.getStackTrace(); 178 TTY.printf("Printing stack trace for current compilation of %s lasting more than %d seconds:%n%s", 179 fmt(request1.getMethod()), EPOCH, fmt(stackTraceNow)); 180 if (Arrays.equals(stacksAtTimeout.get(t), stackTraceNow)) { 181 TTY.printf("\t** Identical stack trace %d seconds ago, implying a hung compilation **%n", 182 EPOCH); 183 } 184 } else { 185 if (DEBUG) { 186 TTY.printf("%s was compiling %s%n", t, fmt(request1.getMethod())); 187 } 188 } 189 } 190 hitCriticalRateOrTimeout = true; 191 return; 192 } 193 } 194 if (!graalRuntime.isBootstrapping()) { 195 return; 196 } 197 198 Thread.sleep(EPOCH * 1000); 199 } 200 } catch (InterruptedException e) { 201 e.printStackTrace(TTY.out); 202 } 203 } 204 snapshotRequests()205 private Map<Thread, Watch> snapshotRequests() { 206 synchronized (requests) { 207 return new HashMap<>(requests); 208 } 209 } 210 seconds(long ms)211 private static double seconds(long ms) { 212 return (double) ms / 1000; 213 } 214 215 /** 216 * Queries whether a critically low compilation rate or {@link #timeout} occurred. 217 */ hitCriticalCompilationRateOrTimeout()218 boolean hitCriticalCompilationRateOrTimeout() { 219 return hitCriticalRateOrTimeout; 220 } 221 222 private final Map<Thread, Watch> requests = new HashMap<>(); 223 private final ThreadLocal<Watch> requestForThread = new ThreadLocal<>(); 224 225 /** 226 * Opens a scope for watching the compilation of a given method. 227 * 228 * @param request a compilation request about to be processed 229 * @return {@code null} if the compilation watch dog is disabled otherwise this object. The 230 * returned value should be used in a {@code try}-with-resources statement whose scope 231 * is the whole compilation so that leaving the scope will cause {@link Watch#close()} 232 * to be called. 233 */ watch(CompilationRequest request)234 Watch watch(CompilationRequest request) { 235 Watch watch = requestForThread.get(); 236 if (watch == null) { 237 watch = new Watch(); 238 synchronized (requests) { 239 requests.put(Thread.currentThread(), watch); 240 } 241 } 242 watch.open(request); 243 return watch; 244 } 245 246 /** 247 * Object for watching the compilations requests of a single compiler thread. 248 */ 249 class Watch implements AutoCloseable { 250 CompilationRequest request; 251 open(CompilationRequest r)252 void open(CompilationRequest r) { 253 assert this.request == null; 254 this.request = r; 255 } 256 257 @Override close()258 public void close() { 259 compilations.incrementAndGet(); 260 request = null; 261 } 262 } 263 } 264