From 6ba21e5b3ab0111c46dcca55db75f69b4284b75e Mon Sep 17 00:00:00 2001 From: Jonathan Schneider Date: Mon, 17 Aug 2026 19:12:25 -0400 Subject: [PATCH] Don't report the RPC shutdown force-kill as a crash MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `shutdown()` SIGTERMs the subprocess, waits 5s, and escalates to `destroyForcibly()` if it hasn't exited. It then checked the exit code against an allowlist of {0, 1, 143} — which covers the graceful SIGTERM path but not 137, the exit code its own SIGKILL had just produced. A command whose work had fully completed failed with "Rewrite RPC process crashed with exit code: 137". It fired only when the subprocess needed more than 5s to handle SIGTERM, so it tracked machine load rather than anything about the command, and presented as a random crash in a healthy RPC process. Move the exit-code check inside the graceful branch instead of running it after both. The force-kill branch no longer inspects an exit code it caused, so a genuine external SIGKILL — an OOM killer kill arriving within the grace period — is still surfaced, which allowlisting 137 would have swallowed. Also: - The grace period is now settable via `setShutdownGracePeriod(Duration)`, defaulting to the existing 5s. - The message names what happened ("exited with code N in response to shutdown") and points at the stderr log when one is configured, rather than asserting a crash the caller cannot distinguish from a timeout. - The exception is held in a local and thrown after the stderr drain join rather than through it. That join exists to release the parent-side log handle before `shutdown()` returns; skipping it leaked the handle on Windows, which mattered little while the throw was spurious and matters now that it is rare and real. --- .../openrewrite/rpc/RewriteRpcProcess.java | 43 ++++- .../rpc/RewriteRpcProcessTest.java | 147 ++++++++++++++++++ 2 files changed, 184 insertions(+), 6 deletions(-) diff --git a/rewrite-core/src/main/java/org/openrewrite/rpc/RewriteRpcProcess.java b/rewrite-core/src/main/java/org/openrewrite/rpc/RewriteRpcProcess.java index b63f5e7b239..786942d537d 100644 --- a/rewrite-core/src/main/java/org/openrewrite/rpc/RewriteRpcProcess.java +++ b/rewrite-core/src/main/java/org/openrewrite/rpc/RewriteRpcProcess.java @@ -39,6 +39,7 @@ import java.nio.file.Path; import java.nio.file.Paths; import java.nio.file.StandardOpenOption; +import java.time.Duration; import java.util.Collection; import java.util.LinkedHashMap; import java.util.LinkedHashSet; @@ -74,6 +75,13 @@ public class RewriteRpcProcess extends Thread { @Setter private @Nullable Path stderrRedirect; + /** + * How long {@link #shutdown()} waits for the subprocess to exit after {@code SIGTERM} + * before escalating to {@code SIGKILL}. + */ + @Setter + private Duration shutdownGracePeriod = Duration.ofSeconds(5); + @Nullable private Thread shutdownHook; @@ -248,18 +256,24 @@ public void shutdown() { } shutdownHook = null; } + // Held back rather than thrown here so the stderr drain join below still runs. + RuntimeException unexpectedExit = null; if (process != null && process.isAlive()) { process.destroy(); try { - boolean exited = process.waitFor(5, TimeUnit.SECONDS); - if (!exited) { + if (process.waitFor(shutdownGracePeriod.toMillis(), TimeUnit.MILLISECONDS)) { + int exitCode = process.exitValue(); + if (exitCode != 0 && exitCode != 1 && exitCode != 143) { // 143 = SIGTERM + unexpectedExit = new RuntimeException(unexpectedExitMessage(exitCode)); + } + } else { + // The grace period elapsed, so escalate. The exit code this produces + // (137 on Unix) is this method's own SIGKILL rather than anything the + // subprocess did, so it is deliberately not inspected — inspecting it + // is what made a deliberate force-kill look like a crash. process.destroyForcibly(); process.waitFor(2, TimeUnit.SECONDS); } - int exitCode = process.exitValue(); - if (exitCode != 0 && exitCode != 1 && exitCode != 143) { // 143 = SIGTERM - throw new RuntimeException("Rewrite RPC process crashed with exit code: " + exitCode); - } } catch (InterruptedException e) { Thread.currentThread().interrupt(); } @@ -280,6 +294,23 @@ public void shutdown() { } stderrDrainThread = null; } + if (unexpectedExit != null) { + throw unexpectedExit; + } + } + + private String unexpectedExitMessage(int exitCode) { + String message = "Rewrite RPC process exited with code " + exitCode + + " in response to shutdown"; + if (exitCode == 137) { + // Reachable only when the subprocess died within the grace period, i.e. before + // shutdown() would have escalated, so this SIGKILL came from somewhere else. + message += " (SIGKILL from outside Rewrite, e.g. the OOM killer)"; + } + if (stderrRedirect != null) { + message += "\nSee stderr log: " + stderrRedirect; + } + return message; } /** diff --git a/rewrite-core/src/test/java/org/openrewrite/rpc/RewriteRpcProcessTest.java b/rewrite-core/src/test/java/org/openrewrite/rpc/RewriteRpcProcessTest.java index b67dd4e61b5..a9125ae21d1 100644 --- a/rewrite-core/src/test/java/org/openrewrite/rpc/RewriteRpcProcessTest.java +++ b/rewrite-core/src/test/java/org/openrewrite/rpc/RewriteRpcProcessTest.java @@ -16,13 +16,17 @@ package org.openrewrite.rpc; import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.condition.DisabledOnOs; +import org.junit.jupiter.api.condition.OS; import java.io.BufferedReader; +import java.io.IOException; import java.io.InputStreamReader; import java.io.UncheckedIOException; import java.lang.reflect.Field; import java.nio.file.Files; import java.nio.file.Path; +import java.nio.file.Paths; import java.time.Duration; import java.util.ArrayList; import java.util.Arrays; @@ -31,6 +35,7 @@ import static java.util.stream.Collectors.toList; import static org.assertj.core.api.Assertions.assertThat; +import static org.assertj.core.api.Assertions.assertThatCode; import static org.assertj.core.api.Assertions.assertThatThrownBy; import static org.junit.jupiter.api.Assertions.assertTimeoutPreemptively; @@ -166,6 +171,112 @@ void startFailsFastWhenBinaryMissing() { .hasMessageContaining(missing)); } + /** + * A subprocess that outlasts the grace period is force-killed by {@code shutdown()} itself, + * which on Unix yields exit code 137. That is this method's own SIGKILL, not a crash, so + * {@code shutdown()} must not report it — doing so failed commands whose work had already + * completed, intermittently, whenever the machine was loaded enough to slow the subprocess' + * SIGTERM handling past the grace period. + */ + @Test + @DisabledOnOs(value = OS.WINDOWS, disabledReason = "destroy() maps to TerminateProcess, which no child can delay") + void shutdownDoesNotReportItsOwnForceKillAsFailure() throws Exception { + Path ready = Files.createTempFile("rpc-force-kill-ready", ".marker"); + RewriteRpcProcess process = forkedProcess(SigtermIgnoringEntryPoint.class, ready); + // Shorter than the default 5s so the test doesn't have to wait it out. + process.setShutdownGracePeriod(Duration.ofMillis(500)); + Process underlying = null; + try { + process.start(); + underlying = underlyingProcess(process); + awaitReady(ready); + + assertThatCode(process::shutdown) + .as("a subprocess force-killed by shutdown() is not a failure of the command") + .doesNotThrowAnyException(); + + assertThat(underlying.isAlive()).as("subprocess should have been killed").isFalse(); + assertThat(underlying.exitValue()) + .as("the subprocess must actually have needed the force-kill, or this test proves nothing") + .isEqualTo(137); + } finally { + if (underlying != null) { + underlying.destroyForcibly(); + } + Files.deleteIfExists(ready); + } + } + + /** + * The complement of {@link #shutdownDoesNotReportItsOwnForceKillAsFailure()}: an exit code + * that the subprocess produced on its own — rather than one {@code shutdown()} inflicted — + * is still surfaced. Also covers that the stderr drain thread is joined before the throw + * escapes, since the parent-side log handle must be released on that path too. + */ + @Test + @DisabledOnOs(value = OS.WINDOWS, disabledReason = "destroy() maps to TerminateProcess, so the child never runs its hook") + void shutdownStillReportsAnExitCodeTheSubprocessChose() throws Exception { + Path ready = Files.createTempFile("rpc-unexpected-exit-ready", ".marker"); + Path stderrLog = Files.createTempFile("rpc-unexpected-exit", ".log"); + RewriteRpcProcess process = forkedProcess(UnexpectedExitEntryPoint.class, ready); + process.setStderrRedirect(stderrLog); + Process underlying = null; + try { + process.start(); + underlying = underlyingProcess(process); + awaitReady(ready); + Thread drainThread = field(process, "stderrDrainThread", Thread.class); + + assertThatThrownBy(process::shutdown) + .isInstanceOf(RuntimeException.class) + .hasMessageContaining("exited with code " + UnexpectedExitEntryPoint.EXIT_CODE) + .hasMessageContaining(stderrLog.toString()); + + assertThat(drainThread.isAlive()) + .as("the stderr drain must be joined before shutdown() throws, or the log handle leaks") + .isFalse(); + } finally { + if (underlying != null) { + underlying.destroyForcibly(); + } + Files.deleteIfExists(ready); + Files.deleteIfExists(stderrLog); + } + } + + private static RewriteRpcProcess forkedProcess(Class entryPoint, Path readyMarker) { + return new RewriteRpcProcess( + System.getProperty("java.home") + "/bin/java", + "-cp", System.getProperty("java.class.path"), + entryPoint.getName(), readyMarker.toString()); + } + + private static Process underlyingProcess(RewriteRpcProcess process) throws Exception { + return field(process, "process", Process.class); + } + + private static T field(RewriteRpcProcess process, String name, Class type) throws Exception { + Field f = RewriteRpcProcess.class.getDeclaredField(name); + f.setAccessible(true); + return type.cast(f.get(process)); + } + + /** + * Blocks until the forked JVM has written its readiness marker. Without this the test can + * SIGTERM the child before it installs its shutdown hook, which silently turns both tests + * into assertions about an ordinary JVM exit. + */ + private static void awaitReady(Path marker) throws Exception { + long deadline = System.nanoTime() + TimeUnit.SECONDS.toNanos(30); + while (Files.size(marker) == 0) { + if (System.nanoTime() > deadline) { + throw new AssertionError("forked JVM never signalled readiness at " + marker); + } + //noinspection BusyWait + Thread.sleep(50); + } + } + /** * Runs in the forked JVM. Spawns a long-running child via {@link RewriteRpcProcess}, * prints its PID, and returns from {@code main} so the JVM exits without an explicit @@ -201,4 +312,40 @@ public static void main(String[] args) throws Exception { } } } + + /** + * Forked entry point whose shutdown hook blocks, so the JVM cannot finish exiting on + * SIGTERM and {@code shutdown()} has to escalate to SIGKILL. + */ + public static class SigtermIgnoringEntryPoint { + public static void main(String[] args) throws Exception { + Runtime.getRuntime().addShutdownHook(new Thread(() -> { + try { + Thread.sleep(TimeUnit.SECONDS.toMillis(60)); + } catch (InterruptedException ignored) { + } + })); + signalReady(args[0]); + Thread.sleep(TimeUnit.SECONDS.toMillis(60)); + } + } + + /** + * Forked entry point that exits on SIGTERM with a code the parent has no reason to expect, + * standing in for a subprocess that dies of its own accord as it is being shut down. + */ + public static class UnexpectedExitEntryPoint { + static final int EXIT_CODE = 3; + + public static void main(String[] args) throws Exception { + // halt() rather than System.exit(), which deadlocks when called from a shutdown hook. + Runtime.getRuntime().addShutdownHook(new Thread(() -> Runtime.getRuntime().halt(EXIT_CODE))); + signalReady(args[0]); + Thread.sleep(TimeUnit.SECONDS.toMillis(60)); + } + } + + private static void signalReady(String marker) throws IOException { + Files.write(Paths.get(marker), "ready".getBytes()); + } }