diff --git a/maven-executor/src/main/java/org/apache/maven/executor/ExecutorRequest.java b/maven-executor/src/main/java/org/apache/maven/executor/ExecutorRequest.java index e5a54dd..e718dc5 100644 --- a/maven-executor/src/main/java/org/apache/maven/executor/ExecutorRequest.java +++ b/maven-executor/src/main/java/org/apache/maven/executor/ExecutorRequest.java @@ -141,6 +141,9 @@ public interface ExecutorRequest { * The optional execution time limit. If set, and execution does not finish within the given time, it is considered * failed and killed. If not set, no time limit is applied. Depending on implementation, the timeout detection may * be imprecise. + *

+ * The forked executor kills the started process together with the processes it started (on Java 9 and later), and + * throws {@link ExecutorTimeoutException}, which carries the tail of the output grabbed so far. */ Optional executionTimeout(); diff --git a/maven-executor/src/main/java/org/apache/maven/executor/ExecutorTimeoutException.java b/maven-executor/src/main/java/org/apache/maven/executor/ExecutorTimeoutException.java new file mode 100644 index 0000000..508e60f --- /dev/null +++ b/maven-executor/src/main/java/org/apache/maven/executor/ExecutorTimeoutException.java @@ -0,0 +1,70 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package org.apache.maven.executor; + +import java.util.Optional; + +/** + * Thrown when an execution does not finish within {@link ExecutorRequest#executionTimeout()}. It carries the tail of + * the output the execution produced before it was killed, so a caller can see where the build stalled. Only the tail: + * a hung build may have logged far more than should be kept alive with an exception. + */ +public class ExecutorTimeoutException extends ExecutorException { + /** + * The most output, in bytes, kept from each of STDOUT and STDERR. + */ + public static final int MAX_TAIL_BYTES = 64 * 1024; + + private final String stdOutTail; + + private final String stdErrTail; + + /** + * Constructs a new {@code ExecutorTimeoutException}. + * + * @param message the detail message + * @param stdOutTail the end of the STDOUT grabbed until the timeout, or {@code null} if output was not grabbed + * @param stdErrTail the end of the STDERR grabbed until the timeout, or {@code null} if output was not grabbed + */ + public ExecutorTimeoutException(String message, String stdOutTail, String stdErrTail) { + super(message); + this.stdOutTail = stdOutTail; + this.stdErrTail = stdErrTail; + } + + /** + * If {@link ExecutorRequest#grabOutputAsString()} was {@code true}, then the end of the STDOUT the execution + * produced before it timed out: at most {@link #MAX_TAIL_BYTES}. When cut, it starts at a line boundary if the + * kept window contains one, and may otherwise start mid-line. + * Otherwise, empty: caller-supplied {@link ExecutorRequest#stdOut()} already received all of it. + */ + public Optional stdOutTail() { + return Optional.ofNullable(stdOutTail); + } + + /** + * If {@link ExecutorRequest#grabOutputAsString()} was {@code true}, then the end of the STDERR the execution + * produced before it timed out: at most {@link #MAX_TAIL_BYTES}. When cut, it starts at a line boundary if the + * kept window contains one, and may otherwise start mid-line. + * Otherwise, empty: caller-supplied {@link ExecutorRequest#stdErr()} already received all of it. + */ + public Optional stdErrTail() { + return Optional.ofNullable(stdErrTail); + } +} diff --git a/maven-executor/src/main/java/org/apache/maven/executor/support/ProcessBuilderExecutorSupport.java b/maven-executor/src/main/java/org/apache/maven/executor/support/ProcessBuilderExecutorSupport.java index 4f8b29d..313c9bd 100644 --- a/maven-executor/src/main/java/org/apache/maven/executor/support/ProcessBuilderExecutorSupport.java +++ b/maven-executor/src/main/java/org/apache/maven/executor/support/ProcessBuilderExecutorSupport.java @@ -23,6 +23,7 @@ import java.io.InputStream; import java.io.OutputStream; import java.io.UncheckedIOException; +import java.nio.charset.Charset; import java.util.NoSuchElementException; import java.util.concurrent.CountDownLatch; import java.util.concurrent.ThreadLocalRandom; @@ -33,6 +34,7 @@ import org.apache.maven.executor.ExecutorException; import org.apache.maven.executor.ExecutorRequest; import org.apache.maven.executor.ExecutorResult; +import org.apache.maven.executor.ExecutorTimeoutException; import static java.util.Objects.requireNonNull; @@ -40,6 +42,8 @@ * Support class for executor implementations using {@link ProcessBuilder}. */ public abstract class ProcessBuilderExecutorSupport implements Executor { + private static final long DRAIN_MILLIS = 5000; + protected final AtomicBoolean closed; protected ProcessBuilderExecutorSupport() { @@ -69,8 +73,8 @@ protected ExecutorResult doExecuteProcess(ExecutorRequest execution, ProcessBuil OutputStream stdOut; OutputStream stdErr; if (execution.grabOutputAsString()) { - stdOut = new ByteArrayOutputStream(); - stdErr = new ByteArrayOutputStream(); + stdOut = new GrabbedOutput(); + stdErr = new GrabbedOutput(); } else { stdOut = execution.stdOut().orElse(IOTools.nullOutputStream()); stdErr = execution.stdErr().orElse(IOTools.nullOutputStream()); @@ -80,7 +84,8 @@ protected ExecutorResult doExecuteProcess(ExecutorRequest execution, ProcessBuil .executionTimeout() .orElseThrow(() -> new NoSuchElementException("No such element")) .toMillis(); - if (pump(process, stdIn, stdOut, stdErr).await(timeoutMillis, TimeUnit.MILLISECONDS)) { + CountDownLatch pumps = pump(process, stdIn, stdOut, stdErr); + if (pumps.await(timeoutMillis, TimeUnit.MILLISECONDS)) { int exitCode = process.waitFor(); String stdOutString = null; String stdErrString = null; @@ -91,8 +96,19 @@ protected ExecutorResult doExecuteProcess(ExecutorRequest execution, ProcessBuil } return new SimpleExecutionResult(execution, exitCode == 0, exitCode, stdOutString, stdErrString); } else { - process.destroyForcibly(); - throw new ExecutorException("Process timeout: " + execution); + ProcessTrees.destroyForcibly(process); + // the pumps finish once the destroyed processes have closed their pipes; wait for them, but + // not for long, since a descendant that survived (Java 8) keeps the pipes open + // an interrupt here takes the InterruptedException branch below, without the tail + pumps.await(DRAIN_MILLIS, TimeUnit.MILLISECONDS); + String stdOutTail = null; + String stdErrTail = null; + if (execution.grabOutputAsString()) { + // only the tail: a hung build may have logged far more than fits in a second copy + stdOutTail = ((GrabbedOutput) stdOut).tail(ExecutorTimeoutException.MAX_TAIL_BYTES); + stdErrTail = ((GrabbedOutput) stdErr).tail(ExecutorTimeoutException.MAX_TAIL_BYTES); + } + throw new ExecutorTimeoutException("Process timeout: " + execution, stdOutTail, stdErrTail); } } else { pump(process, stdIn, stdOut, stdErr).await(); @@ -108,15 +124,38 @@ protected ExecutorResult doExecuteProcess(ExecutorRequest execution, ProcessBuil } } catch (IOException e) { if (process != null) { - process.destroyForcibly(); + ProcessTrees.destroyForcibly(process); } throw new ExecutorException("IO problem while executing command: " + execution, e); } catch (InterruptedException e) { - process.destroyForcibly(); + ProcessTrees.destroyForcibly(process); throw new ExecutorException("Interrupted while executing command: " + execution, e); } } + /** + * Grabbed output that can also hand out its tail without copying the whole buffer. + */ + static final class GrabbedOutput extends ByteArrayOutputStream { + /** + * The last {@code maxBytes} bytes at most. When cut, the tail starts after the first line break in that + * window; a window without one starts mid-line, and a leading partial multibyte sequence decodes as U+FFFD. + */ + synchronized String tail(int maxBytes) { + int from = Math.max(0, count - maxBytes); + if (from > 0) { + // a break as the last byte would leave nothing + for (int i = from; i < count - 1; i++) { + if (buf[i] == '\n') { + from = i + 1; + break; + } + } + } + return new String(buf, from, count - from, Charset.defaultCharset()); + } + } + protected CountDownLatch pump(Process p, InputStream stdIn, OutputStream stdOut, OutputStream stdErr) { CountDownLatch latch = new CountDownLatch(3); String suffix = "-pump-" + ThreadLocalRandom.current().nextInt(); diff --git a/maven-executor/src/main/java/org/apache/maven/executor/support/ProcessTrees.java b/maven-executor/src/main/java/org/apache/maven/executor/support/ProcessTrees.java new file mode 100644 index 0000000..9eeb786 --- /dev/null +++ b/maven-executor/src/main/java/org/apache/maven/executor/support/ProcessTrees.java @@ -0,0 +1,89 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package org.apache.maven.executor.support; + +import java.lang.reflect.Method; +import java.util.stream.Stream; + +/** + * Destroys a started process together with every process it started. + *

+ * {@link Process#destroyForcibly()} reaches only the process itself: the JVMs a Maven build forks (Surefire, + * Failsafe, {@code exec:exec}) survive it, and on Windows so does the Maven JVM, which is a child of the + * {@code cmd.exe} running {@code mvn.cmd}. {@code ProcessHandle} (Java 9+) is reached by reflection rather than from + * a multi-release class, so the same code runs from an exploded {@code target/classes} directory, where versioned + * classes are never loaded. On Java 8 only the process itself is destroyed. + */ +final class ProcessTrees { + private static final Method TO_HANDLE; + private static final Method DESCENDANTS; + private static final Method DESTROY_FORCIBLY; + + static { + Method toHandle = null; + Method descendants = null; + Method destroyForcibly = null; + try { + Class processHandle = Class.forName("java.lang.ProcessHandle"); + toHandle = Process.class.getMethod("toHandle"); + descendants = processHandle.getMethod("descendants"); + destroyForcibly = processHandle.getMethod("destroyForcibly"); + } catch (ReflectiveOperationException e) { + // Java 8: no ProcessHandle + } + TO_HANDLE = toHandle; + DESCENDANTS = descendants; + DESTROY_FORCIBLY = destroyForcibly; + } + + private ProcessTrees() {} + + /** + * Forcibly destroys the descendants of the process, then the process. The descendants go first: once the parent + * is gone they are reparented and can no longer be found from it. + */ + static void destroyForcibly(Process process) { + if (TO_HANDLE != null) { + try { + Object handle = TO_HANDLE.invoke(process); + // a descendant may start a process while the snapshot is being destroyed; take a few more snapshots + for (int pass = 0; pass < 3; pass++) { + Object[] descendants = ((Stream) DESCENDANTS.invoke(handle)).toArray(); + if (descendants.length == 0) { + break; + } + for (Object descendant : descendants) { + destroyHandleForcibly(descendant); + } + } + } catch (ReflectiveOperationException | RuntimeException e) { + // best effort: the process itself is still destroyed below + } + } + process.destroyForcibly(); + } + + private static void destroyHandleForcibly(Object handle) { + try { + DESTROY_FORCIBLY.invoke(handle); + } catch (ReflectiveOperationException e) { + // the descendant may already be gone + } + } +} diff --git a/maven-executor/src/test/java/org/apache/maven/executor/support/HangingProcess.java b/maven-executor/src/test/java/org/apache/maven/executor/support/HangingProcess.java new file mode 100644 index 0000000..9b0e60c --- /dev/null +++ b/maven-executor/src/test/java/org/apache/maven/executor/support/HangingProcess.java @@ -0,0 +1,99 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package org.apache.maven.executor.support; + +import java.io.File; +import java.io.FileOutputStream; +import java.io.OutputStream; +import java.lang.ProcessBuilder.Redirect; +import java.net.URISyntaxException; +import java.nio.file.Paths; + +/** + * Stands in for a Maven build that hangs: {@code parent } prints a line to STDOUT and one to STDERR, starts + * {@code child } as its own child process, and sleeps; the child appends to the heartbeat file every 50ms, + * like a forked test JVM that never ends. {@code noisy } prints {@link #NOISY_LINES} lines to STDOUT, + * then {@link #LAST_LINE}, and sleeps. Both give up after {@link #LIFETIME_MILLIS}, so a failing test leaves no + * process behind for long. + */ +public final class HangingProcess { + static final String STDOUT_LINE = "parent started"; + static final String STDERR_LINE = "parent warning"; + static final long LIFETIME_MILLIS = 30_000; + static final int NOISY_LINES = 200_000; + static final String LAST_LINE = "last line before the hang"; + + private HangingProcess() {} + + static ProcessBuilder parent(File heartbeat) { + return java("parent", heartbeat); + } + + static ProcessBuilder noisy(File heartbeat) { + return java("noisy", heartbeat); + } + + private static ProcessBuilder java(String mode, File heartbeat) { + String java = System.getProperty("java.home") + File.separator + "bin" + File.separator + "java"; + String classPath; + try { + // toURI() decodes %20 and turns /D:/ into D:\ on Windows + classPath = Paths.get(HangingProcess.class + .getProtectionDomain() + .getCodeSource() + .getLocation() + .toURI()) + .toString(); + } catch (URISyntaxException e) { + throw new IllegalStateException(e); + } + return new ProcessBuilder( + java, "-cp", classPath, HangingProcess.class.getName(), mode, heartbeat.getAbsolutePath()); + } + + public static void main(String[] args) throws Exception { + long deadline = System.currentTimeMillis() + LIFETIME_MILLIS; + File heartbeat = new File(args[1]); + if ("parent".equals(args[0])) { + java("child", heartbeat) + .redirectOutput(Redirect.appendTo(new File(heartbeat.getPath() + ".out"))) + .redirectErrorStream(true) + .start(); + System.out.println(STDOUT_LINE); + System.out.flush(); + System.err.println(STDERR_LINE); + System.err.flush(); + } else if ("noisy".equals(args[0])) { + for (int i = 0; i < NOISY_LINES; i++) { + System.out.println("line " + i + " of the output a hung build keeps writing"); + } + System.out.println(LAST_LINE); + System.out.flush(); + } else { + try (OutputStream out = new FileOutputStream(heartbeat, true)) { + while (System.currentTimeMillis() < deadline) { + out.write('.'); + out.flush(); + Thread.sleep(50); + } + } + } + Thread.sleep(Math.max(0, deadline - System.currentTimeMillis())); + } +} diff --git a/maven-executor/src/test/java/org/apache/maven/executor/support/ProcessBuilderExecutorSupportTest.java b/maven-executor/src/test/java/org/apache/maven/executor/support/ProcessBuilderExecutorSupportTest.java new file mode 100644 index 0000000..042c7b8 --- /dev/null +++ b/maven-executor/src/test/java/org/apache/maven/executor/support/ProcessBuilderExecutorSupportTest.java @@ -0,0 +1,168 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +package org.apache.maven.executor.support; + +import java.io.File; +import java.nio.charset.Charset; +import java.nio.file.Path; +import java.time.Duration; + +import org.apache.maven.executor.ExecutorRequest; +import org.apache.maven.executor.ExecutorResult; +import org.apache.maven.executor.ExecutorTimeoutException; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.Timeout; +import org.junit.jupiter.api.io.TempDir; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.junit.jupiter.api.Assumptions.assumeTrue; + +@Timeout(60) +class ProcessBuilderExecutorSupportTest { + @TempDir + Path tempDir; + + @Test + void timeoutDestroysTheProcessTree() throws Exception { + assumeTrue(hasProcessHandle(), "descendants are reachable from Java 9 on"); + File heartbeat = tempDir.resolve("heartbeat").toFile(); + + assertThrows( + ExecutorTimeoutException.class, + () -> new TestExecutor().execute(request(Duration.ofSeconds(10)), HangingProcess.parent(heartbeat))); + + assertTrue(heartbeat.length() > 0, "the child never started, so the test proves nothing"); + long length = heartbeat.length(); + Thread.sleep(1000); + assertEquals(length, heartbeat.length(), "the child process outlived the timeout"); + } + + @Test + void timeoutKeepsTheGrabbedOutput() { + File heartbeat = tempDir.resolve("heartbeat").toFile(); + + ExecutorTimeoutException e = assertThrows( + ExecutorTimeoutException.class, + () -> new TestExecutor().execute(request(Duration.ofSeconds(5)), HangingProcess.parent(heartbeat))); + + assertTrue(e.getMessage().startsWith("Process timeout: "), e.getMessage()); + assertEquals(HangingProcess.STDOUT_LINE, e.stdOutTail().orElse("").trim()); + assertEquals(HangingProcess.STDERR_LINE, e.stdErrTail().orElse("").trim()); + } + + @Test + void timeoutKeepsOnlyTheTailOfLargeOutput() { + File heartbeat = tempDir.resolve("heartbeat").toFile(); + + ExecutorTimeoutException e = assertThrows( + ExecutorTimeoutException.class, + () -> new TestExecutor().execute(request(Duration.ofSeconds(5)), HangingProcess.noisy(heartbeat))); + + String tail = e.stdOutTail().orElse(""); + assertTrue( + tail.length() <= ExecutorTimeoutException.MAX_TAIL_BYTES, "tail has " + tail.length() + " characters"); + assertTrue( + tail.startsWith("line "), + "tail does not start at a line boundary: " + tail.substring(0, Math.min(40, tail.length()))); + assertEquals( + HangingProcess.LAST_LINE, + tail.substring(tail.trim().lastIndexOf('\n') + 1).trim()); + } + + @Test + void timeoutWithoutGrabbingHasNoTail() { + File heartbeat = tempDir.resolve("heartbeat").toFile(); + + ExecutorTimeoutException e = assertThrows( + ExecutorTimeoutException.class, + () -> new TestExecutor() + .execute(request(Duration.ofSeconds(5), false), HangingProcess.parent(heartbeat))); + + assertFalse(e.stdOutTail().isPresent()); + assertFalse(e.stdErrTail().isPresent()); + } + + @Test + void tailKeepsShortOutputWhole() { + assertEquals("one\ntwo\n", grabbed("one\ntwo\n").tail(64)); + } + + @Test + void tailStartsAfterTheFirstLineBreakInTheWindow() { + assertEquals("three\n", grabbed("one\ntwo\nthree\n").tail(10)); + } + + @Test + void tailIsNotEmptyWhenTheOnlyLineBreakIsTheLastByte() { + assertEquals("ne\n", grabbed("one\n").tail(3)); + } + + @Test + void tailWithoutLineBreakStartsMidLine() { + assertEquals("cdef", grabbed("abcdef").tail(4)); + } + + private static ProcessBuilderExecutorSupport.GrabbedOutput grabbed(String text) { + ProcessBuilderExecutorSupport.GrabbedOutput output = new ProcessBuilderExecutorSupport.GrabbedOutput(); + byte[] bytes = text.getBytes(Charset.defaultCharset()); + output.write(bytes, 0, bytes.length); + return output; + } + + private static boolean hasProcessHandle() { + try { + Class.forName("java.lang.ProcessHandle"); + return true; + } catch (ClassNotFoundException e) { + return false; + } + } + + private ExecutorRequest request(Duration timeout) { + return request(timeout, true); + } + + private ExecutorRequest request(Duration timeout, boolean grabOutputAsString) { + return ExecutorRequest.mavenBuilder() + .cwd(tempDir) + .userHomeDirectory(tempDir) + .executionTimeout(timeout) + .grabOutputAsString(grabOutputAsString) + .build(); + } + + private static final class TestExecutor extends ProcessBuilderExecutorSupport { + ExecutorResult execute(ExecutorRequest request, ProcessBuilder processBuilder) { + return doExecuteProcess(request, processBuilder); + } + + @Override + public ExecutorResult execute(ExecutorRequest executorRequest) { + throw new UnsupportedOperationException(); + } + + @Override + public String mavenVersion() { + throw new UnsupportedOperationException(); + } + } +}