Skip to content
52 changes: 52 additions & 0 deletions debug-subprocess-loop.sh
Original file line number Diff line number Diff line change
@@ -0,0 +1,52 @@
#!/bin/bash

# Script to help debug intermittent subprocess failures locally
# Usage: ./debug-subprocess-loop.sh [iterations] [target]

ITERATIONS=${1:-50}
TARGET=${2:-"test.os.SubprocessTests"}
SCALA_VERSION="2.13.16"

echo "Running $TARGET in loop for $ITERATIONS iterations..."
echo "Set SUBPROCESS_STRESS_ITERATIONS env var to control stress test iterations"

SUCCESS_COUNT=0
FAILURE_COUNT=0

for i in $(seq 1 $ITERATIONS); do
echo "=== Iteration $i/$ITERATIONS ==="

if ./mill -i "os.jvm[$SCALA_VERSION].test.testOnly" "$TARGET" 2>&1; then
SUCCESS_COUNT=$((SUCCESS_COUNT + 1))
echo "✓ Iteration $i: SUCCESS"
else
FAILURE_COUNT=$((FAILURE_COUNT + 1))
echo "✗ Iteration $i: FAILED"

# Optionally stop on first failure
if [ "$3" = "--stop-on-failure" ]; then
echo "Stopping on first failure as requested"
break
fi
fi

# Small delay between runs
sleep 0.1
done

echo ""
echo "=== SUMMARY ==="
echo "Total iterations: $ITERATIONS"
echo "Successes: $SUCCESS_COUNT"
echo "Failures: $FAILURE_COUNT"
echo "Success rate: $(( SUCCESS_COUNT * 100 / (SUCCESS_COUNT + FAILURE_COUNT) ))%"

if [ $FAILURE_COUNT -gt 0 ]; then
echo ""
echo "Failures detected! This may help reproduce the CI issue."
exit 1
else
echo ""
echo "All tests passed. Try increasing iterations or running under stress."
exit 0
fi
9 changes: 8 additions & 1 deletion os/test/src-jvm/SpawningSubprocessesNewTests.scala
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,14 @@ object SpawningSubprocessesNewTests extends TestSuite {
// Taking input from a file and directing output to another file
os.call(cmd = ("base64"), stdin = wd / "File.txt", stdout = wd / "File.txt.b64")

os.read(wd / "File.txt.b64") ==> "SSBhbSBjb3c=\n"
val expectedB64 = "SSBhbSBjb3c=\n"
val actualB64 = os.read(wd / "File.txt.b64")
if (actualB64 != expectedB64) {
throw new Exception(
s"base64 output mismatch: expected '$expectedB64', got '$actualB64' (${actualB64.length} chars)"
)
}
assert(actualB64 == expectedB64)

if (false) {
os.call(cmd = ("vim"), stdin = os.Inherit, stdout = os.Inherit, stderr = os.Inherit)
Expand Down
81 changes: 78 additions & 3 deletions os/test/src/SubprocessTests.scala
Original file line number Diff line number Diff line change
Expand Up @@ -82,7 +82,20 @@ object SubprocessTests extends TestSuite {
env = Map("ENV_ARG" -> "123")
)

assert(res.out.text().trim() == "Hello123")
// Enhanced debugging: show exit code and raw output on failure

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think these changes will help debugging a lot. Thank you.

I'll check the logs of the next os-lib CI run and see what I can
glean.

if (res.exitCode != 0) {
throw new Exception(
s"Subprocess failed with exit code ${res.exitCode}, stderr: '${res.err.text()}'"
)
}
val actualOutput = res.out.text().trim()
val expectedOutput = "Hello123"
if (actualOutput != expectedOutput) {
throw new Exception(
s"Output mismatch: expected '$expectedOutput', got '$actualOutput' (${actualOutput.length} chars, exit code: ${res.exitCode})"
)
}
assert(actualOutput == expectedOutput)
}
}
test("filebased2") {
Expand All @@ -109,13 +122,27 @@ object SubprocessTests extends TestSuite {
test("envArgs.doubleQuotesExpand-1") {

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you for the change from "locally" blocks to individual "test()"
blocks. That make it much easier for at least me to figure out
in CI log files which assertions are failing. A definite improvement.

if (Unix()) {
val res0 = proc("bash", "-c", "echo \"Hello$ENV_ARG\"").call(env = Map("ENV_ARG" -> "12"))
assert(res0.out.lines() == Seq("Hello12"))
val expectedLines = Seq("Hello12")
val actualLines = res0.out.lines()
if (actualLines != expectedLines) {
throw new Exception(
s"envArgs.doubleQuotesExpand-1 failed: expected $expectedLines, got $actualLines (exit code: ${res0.exitCode})"
)
}
assert(actualLines == expectedLines)
}
}
test("envArgs.doubleQuotesExpand-2") {
if (Unix()) {
val res1 = proc("bash", "-c", "echo \"Hello$ENV_ARG\"").call(env = Map("ENV_ARG" -> "12"))
assert(res1.out.lines() == Seq("Hello12"))
val expectedLines = Seq("Hello12")
val actualLines = res1.out.lines()
if (actualLines != expectedLines) {
throw new Exception(
s"envArgs.doubleQuotesExpand-2 failed: expected $expectedLines, got $actualLines (exit code: ${res1.exitCode})"
)
}
assert(actualLines == expectedLines)
}
}
test("envArgs.singleQuotesNoExpand") {
Expand Down Expand Up @@ -250,5 +277,53 @@ object SubprocessTests extends TestSuite {
assert(z.out.trim() == outsidePwd.toString)
}
}

// Stress test to help reproduce intermittent subprocess failures seen in CI
test("stressSubprocess") {
if (Unix()) {
val iterations = sys.env.get("SUBPROCESS_STRESS_ITERATIONS").map(_.toInt).getOrElse(10)
var failures = 0
var successes = 0

for (i <- 1 to iterations) {
try {
// Test the exact same pattern that's failing in CI
val res = proc("bash", "-c", "echo 'Hello'$ENV_ARG").call(env = Map("ENV_ARG" -> "123"))
val expected = "Hello123"
val actual = res.out.text().trim()

if (res.exitCode != 0) {
println(s"Iteration $i: subprocess failed with exit code ${res.exitCode}")
failures += 1
} else if (actual != expected) {
println(s"Iteration $i: output mismatch - expected '$expected', got '$actual'")
failures += 1
} else {
successes += 1
}

// Add a small delay to potentially trigger race conditions
Thread.sleep(1)

} catch {
case ex: Throwable =>
println(s"Iteration $i: exception - ${ex.getMessage}")
failures += 1
}
}

println(
s"Stress test completed: $successes successes, $failures failures out of $iterations iterations"
)

// Allow up to 10% failure rate for now to gather data
val failureRate = failures.toDouble / iterations
if (failureRate > 0.1) {
throw new Exception(
s"High failure rate in stress test: ${(failureRate * 100).toInt}% ($failures/$iterations)"
)
}
}
}
}
}
Loading