|
| 1 | +/* |
| 2 | + * Licensed to the Apache Software Foundation (ASF) under one or more |
| 3 | + * contributor license agreements. See the NOTICE file distributed with |
| 4 | + * this work for additional information regarding copyright ownership. |
| 5 | + * The ASF licenses this file to You under the Apache License, Version 2.0 |
| 6 | + * (the "License"); you may not use this file except in compliance with |
| 7 | + * the License. You may obtain a copy of the License at |
| 8 | + * |
| 9 | + * http://www.apache.org/licenses/LICENSE-2.0 |
| 10 | + * |
| 11 | + * Unless required by applicable law or agreed to in writing, software |
| 12 | + * distributed under the License is distributed on an "AS IS" BASIS, |
| 13 | + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| 14 | + * See the License for the specific language governing permissions and |
| 15 | + * limitations under the License. |
| 16 | + */ |
| 17 | +package org.apache.lucene.gradle.plugins.hacks; |
| 18 | + |
| 19 | +import java.lang.management.LockInfo; |
| 20 | +import java.lang.management.ManagementFactory; |
| 21 | +import java.lang.management.MonitorInfo; |
| 22 | +import java.lang.management.ThreadInfo; |
| 23 | +import java.lang.management.ThreadMXBean; |
| 24 | +import java.time.Duration; |
| 25 | +import java.time.Instant; |
| 26 | +import java.util.Locale; |
| 27 | +import java.util.concurrent.TimeUnit; |
| 28 | +import javax.inject.Inject; |
| 29 | +import org.apache.lucene.gradle.SuppressForbidden; |
| 30 | +import org.apache.lucene.gradle.plugins.LuceneGradlePlugin; |
| 31 | +import org.gradle.api.Project; |
| 32 | +import org.gradle.api.logging.Logger; |
| 33 | +import org.gradle.api.logging.Logging; |
| 34 | +import org.gradle.api.provider.Provider; |
| 35 | +import org.gradle.api.services.BuildService; |
| 36 | +import org.gradle.api.services.BuildServiceParameters; |
| 37 | +import org.gradle.build.event.BuildEventsListenerRegistry; |
| 38 | +import org.gradle.tooling.events.FinishEvent; |
| 39 | +import org.gradle.tooling.events.OperationCompletionListener; |
| 40 | + |
| 41 | +/** |
| 42 | + * This tracks the build progress (looking at task completion updates) and emits some diagnostics if |
| 43 | + * no such progress can be observed. |
| 44 | + */ |
| 45 | +public class DumpGradleStateOnStalledBuildsPlugin extends LuceneGradlePlugin { |
| 46 | + /** Check for stalled progress every minute. */ |
| 47 | + static final long checkIntervalMillis = TimeUnit.MINUTES.toMillis(1); |
| 48 | + |
| 49 | + /** |
| 50 | + * After the no-progress is detected, dump everything every 5 minutes (unless progress is |
| 51 | + * restored). |
| 52 | + */ |
| 53 | + static final long recheckIntervalMillis = TimeUnit.MINUTES.toMillis(5); |
| 54 | + |
| 55 | + /** Consider 3 minutes of no-updates as no-progress. */ |
| 56 | + static final long minDurationOfNoUpdates = TimeUnit.MINUTES.toNanos(3); |
| 57 | + |
| 58 | + public static final String OPT_TRACK_GRADLE_STATE = "lucene.trackGradleState"; |
| 59 | + |
| 60 | + private final BuildEventsListenerRegistry listenerRegistry; |
| 61 | + |
| 62 | + @Inject |
| 63 | + public DumpGradleStateOnStalledBuildsPlugin(BuildEventsListenerRegistry listenerRegistry) { |
| 64 | + this.listenerRegistry = listenerRegistry; |
| 65 | + } |
| 66 | + |
| 67 | + @Override |
| 68 | + public void apply(Project project) { |
| 69 | + applicableToRootProjectOnly(project); |
| 70 | + |
| 71 | + var buildOptions = getBuildOptions(project); |
| 72 | + var trackStateOption = |
| 73 | + buildOptions.addBooleanOption( |
| 74 | + OPT_TRACK_GRADLE_STATE, |
| 75 | + "Track build progress and dump gradle jvm state diagnostics in case of no progress.", |
| 76 | + false); |
| 77 | + |
| 78 | + if (!trackStateOption.get()) { |
| 79 | + return; |
| 80 | + } |
| 81 | + |
| 82 | + Provider<TrackProgressService> service = |
| 83 | + project |
| 84 | + .getGradle() |
| 85 | + .getSharedServices() |
| 86 | + .registerIfAbsent("trackProgressService", TrackProgressService.class, _ -> {}); |
| 87 | + |
| 88 | + listenerRegistry.onTaskCompletion(service); |
| 89 | + } |
| 90 | + |
| 91 | + /** |
| 92 | + * This service collects per-task durations and prints a summary when closed (at the end of the |
| 93 | + * build). |
| 94 | + */ |
| 95 | + public abstract static class TrackProgressService |
| 96 | + implements BuildService<BuildServiceParameters.None>, |
| 97 | + OperationCompletionListener, |
| 98 | + AutoCloseable { |
| 99 | + private static final Logger LOGGER = Logging.getLogger(TrackProgressService.class); |
| 100 | + |
| 101 | + /** Execution time of all successful tasks. Keys are task paths, values are in millis. */ |
| 102 | + private volatile long lastUpdateNanos = System.nanoTime(); |
| 103 | + |
| 104 | + private final Thread trackerThread; |
| 105 | + private volatile boolean stop; |
| 106 | + |
| 107 | + public TrackProgressService() { |
| 108 | + this.trackerThread = |
| 109 | + new Thread("gradle-progress-tracker") { |
| 110 | + @Override |
| 111 | + public void run() { |
| 112 | + while (!stop) { |
| 113 | + try { |
| 114 | + sleepNow(checkIntervalMillis); |
| 115 | + |
| 116 | + long noUpdateTime = System.nanoTime() - lastUpdateNanos; |
| 117 | + if (noUpdateTime >= minDurationOfNoUpdates) { |
| 118 | + dumpGradleState(noUpdateTime); |
| 119 | + sleepNow(recheckIntervalMillis); |
| 120 | + } |
| 121 | + } catch (InterruptedException _) { |
| 122 | + // ignore. |
| 123 | + } |
| 124 | + } |
| 125 | + } |
| 126 | + |
| 127 | + @SuppressForbidden(reason = "legitimate sleep here.") |
| 128 | + private void sleepNow(long millis) throws InterruptedException { |
| 129 | + Thread.sleep(millis); |
| 130 | + } |
| 131 | + }; |
| 132 | + trackerThread.setDaemon(true); |
| 133 | + trackerThread.start(); |
| 134 | + } |
| 135 | + |
| 136 | + private void dumpGradleState(long noUpdateTimeNanos) { |
| 137 | + LOGGER.warn( |
| 138 | + "{}: Gradle panic: no status update in {}" + " seconds?", |
| 139 | + Instant.now(), |
| 140 | + Duration.ofNanos(noUpdateTimeNanos).toSeconds()); |
| 141 | + |
| 142 | + String jvmDiags; |
| 143 | + try { |
| 144 | + jvmDiags = collectJvmDiagnostics(); |
| 145 | + } catch (Throwable t) { |
| 146 | + jvmDiags = "Failed to collect jvm diagnostics: " + t.getMessage(); |
| 147 | + } |
| 148 | + LOGGER.warn(jvmDiags); |
| 149 | + } |
| 150 | + |
| 151 | + /** Collects heap stats and a full thread dump into a single String. */ |
| 152 | + public static String collectJvmDiagnostics() { |
| 153 | + StringBuilder sb = new StringBuilder(32_768); |
| 154 | + |
| 155 | + sb.append("====== GRADLE JVM DIAGNOSTICS ======\n"); |
| 156 | + |
| 157 | + Runtime rt = Runtime.getRuntime(); |
| 158 | + long max = rt.maxMemory(); |
| 159 | + long total = rt.totalMemory(); |
| 160 | + long free = rt.freeMemory(); |
| 161 | + long used = total - free; |
| 162 | + |
| 163 | + sb.append("=== JVM Heap ===\n") |
| 164 | + .append("Max: ") |
| 165 | + .append(formatBytes(max)) |
| 166 | + .append(" (") |
| 167 | + .append(max) |
| 168 | + .append(" bytes)\n") |
| 169 | + .append("Total: ") |
| 170 | + .append(formatBytes(total)) |
| 171 | + .append(" (") |
| 172 | + .append(total) |
| 173 | + .append(" bytes)\n") |
| 174 | + .append("Free: ") |
| 175 | + .append(formatBytes(free)) |
| 176 | + .append(" (") |
| 177 | + .append(free) |
| 178 | + .append(" bytes)\n") |
| 179 | + .append("Used: ") |
| 180 | + .append(formatBytes(used)) |
| 181 | + .append(" (") |
| 182 | + .append(used) |
| 183 | + .append(" bytes)\n\n"); |
| 184 | + |
| 185 | + // --- Thread dump --- |
| 186 | + ThreadMXBean tmx = ManagementFactory.getThreadMXBean(); |
| 187 | + boolean withMonitors = tmx.isObjectMonitorUsageSupported(); |
| 188 | + boolean withSyncs = tmx.isSynchronizerUsageSupported(); |
| 189 | + |
| 190 | + ThreadInfo[] infos = tmx.dumpAllThreads(withMonitors, withSyncs); |
| 191 | + sb.append("=== Threads (").append(infos.length).append(") ===\n"); |
| 192 | + |
| 193 | + for (ThreadInfo ti : infos) { |
| 194 | + if (ti == null) continue; |
| 195 | + |
| 196 | + sb.append('"') |
| 197 | + .append(ti.getThreadName()) |
| 198 | + .append('"') |
| 199 | + .append(" Id=") |
| 200 | + .append(ti.getThreadId()) |
| 201 | + .append(" ") |
| 202 | + .append(ti.getThreadState()); |
| 203 | + if (ti.isSuspended()) sb.append(" (suspended)"); |
| 204 | + if (ti.isInNative()) sb.append(" (in native)"); |
| 205 | + sb.append('\n'); |
| 206 | + |
| 207 | + // Stack trace with monitor/synchronizer details |
| 208 | + StackTraceElement[] stack = ti.getStackTrace(); |
| 209 | + for (int i = 0; i < stack.length; i++) { |
| 210 | + StackTraceElement ste = stack[i]; |
| 211 | + sb.append("\tat ").append(ste).append('\n'); |
| 212 | + |
| 213 | + // Lock the thread is currently waiting on |
| 214 | + if (i == 0 && ti.getLockInfo() != null) { |
| 215 | + sb.append("\t- waiting on ").append(ti.getLockInfo()).append('\n'); |
| 216 | + } |
| 217 | + // Monitors locked at this frame |
| 218 | + if (withMonitors) { |
| 219 | + for (MonitorInfo mi : ti.getLockedMonitors()) { |
| 220 | + if (mi.getLockedStackDepth() == i) { |
| 221 | + sb.append("\t- locked ").append(mi).append('\n'); |
| 222 | + } |
| 223 | + } |
| 224 | + } |
| 225 | + } |
| 226 | + |
| 227 | + // Locked synchronizers (e.g., ReentrantLocks) |
| 228 | + if (withSyncs) { |
| 229 | + LockInfo[] locks = ti.getLockedSynchronizers(); |
| 230 | + if (locks.length > 0) { |
| 231 | + sb.append("\n\tLocked synchronizers:\n"); |
| 232 | + for (LockInfo li : locks) { |
| 233 | + sb.append("\t- ").append(li).append('\n'); |
| 234 | + } |
| 235 | + } |
| 236 | + } |
| 237 | + sb.append('\n'); |
| 238 | + } |
| 239 | + |
| 240 | + // --- Deadlock info (if any) --- |
| 241 | + long[] deadlocked = tmx.findDeadlockedThreads(); |
| 242 | + if (deadlocked != null && deadlocked.length > 0) { |
| 243 | + sb.append("=== Deadlocked Threads ===\n"); |
| 244 | + for (long id : deadlocked) { |
| 245 | + sb.append(" - Thread Id=").append(id).append('\n'); |
| 246 | + } |
| 247 | + } |
| 248 | + |
| 249 | + sb.append("====== END: GRADLE JVM DIAGNOSTICS ======\n"); |
| 250 | + |
| 251 | + return sb.toString(); |
| 252 | + } |
| 253 | + |
| 254 | + private static String formatBytes(long bytes) { |
| 255 | + if (bytes < 1024) return bytes + " B"; |
| 256 | + double v = bytes; |
| 257 | + String[] units = {"KB", "MB", "GB", "TB", "PB"}; |
| 258 | + int i = 0; |
| 259 | + while (v >= 1024 && i < units.length - 1) { |
| 260 | + v /= 1024; |
| 261 | + i++; |
| 262 | + } |
| 263 | + return String.format(Locale.ROOT, "%.2f %s", v, units[i]); |
| 264 | + } |
| 265 | + |
| 266 | + @Override |
| 267 | + public void onFinish(FinishEvent event) { |
| 268 | + lastUpdateNanos = System.nanoTime(); |
| 269 | + } |
| 270 | + |
| 271 | + @Override |
| 272 | + public void close() { |
| 273 | + try { |
| 274 | + this.stop = true; |
| 275 | + this.trackerThread.interrupt(); |
| 276 | + this.trackerThread.join(Duration.ofSeconds(10)); |
| 277 | + } catch (InterruptedException e) { |
| 278 | + LOGGER.warn("Interrupted while waiting for tracker thread to finish.", e); |
| 279 | + } |
| 280 | + } |
| 281 | + } |
| 282 | +} |
0 commit comments