Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions changelog.d/3352-test-timeout.fixed.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
- `wheels test` no longer dies with `Read timed out` on a suite that takes more than about two minutes. The CLI's HTTP client applied a hardcoded 120-second read timeout to every request, which is right for the short request/response bridge commands but is a hard ceiling on how big a suite the test command can run — and it produced **no result at all**, not a failure report, so a passing suite was indistinguishable from a hung app. The budget is now 900 seconds by default and configurable with `--timeout=<seconds>` or `WHEELS_TEST_TIMEOUT`. When it is still exceeded, the message says which side gave up, that the specs may well have passed, and how to give it longer or scope the run. The browser-test runner, which makes the same long-running call, got the same budget (#3352)
- `tools/test-local.sh` writes its results to a per-checkout file instead of a single fixed `/tmp` path, so two working copies running the suite no longer overwrite each other — which silently turned a develop-vs-branch comparison into two copies of the same run. It also clears the file before the request, so a run that fails outright (`HTTP 000`, typically a server that is not up yet) can no longer leave the previous run's results behind to be read as if they were current. Override with `WHEELS_TEST_RESULT_FILE` (#3352)
80 changes: 70 additions & 10 deletions cli/lucli/Module.cfc
Original file line number Diff line number Diff line change
Expand Up @@ -276,6 +276,7 @@ component extends="modules.BaseModule" {
.option(name = "reporter", default = "simple", description = "Output format: simple, json, or tap")
.option(name = "db", default = "sqlite", description = "Database the suite runs against")
.option(name = "base-path", default = "", description = "URL prefix the app is mounted under (e.g. /myapp). Auto-derived from WHEELS_SUBPATH or set(subpath=...) when omitted.")
.option(name = "timeout", default = "", description = "Seconds to wait for the suite to finish (default 900). Also settable with WHEELS_TEST_TIMEOUT.")
.flag(name = "verbose", default = false, description = "Print per-spec detail instead of the summary rollup")
.flag(name = "ci", default = false, description = "CI mode output")
.flag(name = "core", default = false, description = "Run the framework core suite (vendor/wheels/tests) instead of the app suite")
Expand Down Expand Up @@ -738,10 +739,46 @@ component extends="modules.BaseModule" {
db = parsed.db,
dbExplicit = structKeyExists(arguments.coll, "db"),
useTestDB = parsed["test-db"],
basePath = parsed["base-path"]
basePath = parsed["base-path"],
timeout = $resolveTestTimeout(parsed.timeout)
};
}

/**
* Seconds to wait for the test-runner response. `--timeout` wins, then
* WHEELS_TEST_TIMEOUT, then 900.
*
* The shared HTTP helper reads for 120 seconds, which is right for the
* request/response bridge commands but is a hard ceiling on how big a suite
* `wheels test` can run: a suite that grows past roughly 140 seconds starts
* failing with `Read timed out` and NO result document at all — not a failure
* report, a crashed runner (issue #3352). The threshold moves with machine
* speed, so a suite can pass locally and fail in CI. A test run is the one
* command here whose duration is expected to scale with the project, so it
* gets its own budget rather than inheriting the bridge default.
*
* Non-numeric or non-positive input falls back to the default rather than
* throwing: a mistyped timeout should not be the thing that stops a test run.
*/
public numeric function $resolveTestTimeout(string parsedTimeout = "") {
if (
len(trim(arguments.parsedTimeout))
&& isNumeric(trim(arguments.parsedTimeout))
&& val(arguments.parsedTimeout) > 0
) {
return val(arguments.parsedTimeout);
}
// mirrors how $resolveTestBasePath() reads WHEELS_SUBPATH
try {
var envValue = createObject("java", "java.lang.System").getenv("WHEELS_TEST_TIMEOUT");
if (!isNull(envValue) && len(trim(envValue)) && isNumeric(trim(envValue)) && val(envValue) > 0) {
return val(envValue);
}
} catch (any e) {
}
return 900;
}

/**
* hint: Run test suite with optional filter and reporter
*/
Expand All @@ -757,6 +794,7 @@ component extends="modules.BaseModule" {
var dbExplicit = opts.dbExplicit;
var useTestDB = opts.useTestDB;
var basePath = opts.basePath;
var timeoutSeconds = opts.timeout;

// Default to APP mode unless --core is set explicitly. The previous
// auto-detection ("if vendor/wheels/tests/ exists, default to core")
Expand All @@ -775,7 +813,10 @@ component extends="modules.BaseModule" {
// expects. Onboarding finding #2.
filter = $normalizeTestFilter(filter, coreTests);

return runTests(filter, reporter, format, verboseOutput, coreTests, db, ciMode, useTestDB, dbExplicit, basePath);
return runTests(
filter, reporter, format, verboseOutput, coreTests,
db, ciMode, useTestDB, dbExplicit, basePath, timeoutSeconds
);
}

/**
Expand Down Expand Up @@ -5709,7 +5750,8 @@ component extends="modules.BaseModule" {
boolean ciMode = false,
boolean useTestDB = true,
boolean dbExplicit = false,
string basePath = ""
string basePath = "",
numeric timeoutSeconds = 900
) {
var serverPort = $requireRunningServer([
"Start one with: wheels start",
Expand Down Expand Up @@ -5778,7 +5820,7 @@ component extends="modules.BaseModule" {
testUrl &= "&directory=#filter#";
}

var httpResult = makeHttpRequest(testUrl);
var httpResult = makeHttpRequest(testUrl, arguments.timeoutSeconds * 1000);

// Try to parse JSON result
if (isJSON(httpResult)) {
Expand Down Expand Up @@ -5821,7 +5863,18 @@ component extends="modules.BaseModule" {
}
} catch (any e) {
runState.crashed = true;
out("Test execution failed: #e.message#", "red");
// A read timeout here is indistinguishable from a hung app to anyone who has not
// seen it before, because the runner produced no document at all — the suite may
// well have passed (issue #3352). Say which side gave up, and how to give it longer.
if (reFindNoCase("(read timed out|SocketTimeout)", e.message)) {
out("Test run timed out after #arguments.timeoutSeconds#s waiting for the suite to finish.", "red");
out("The specs may have passed — the CLI stopped waiting, the runner did not stop running.", "yellow");
out("Give it longer: wheels test --timeout=#arguments.timeoutSeconds * 2#", "yellow");
out("Or set WHEELS_TEST_TIMEOUT=<seconds> for the whole environment.", "yellow");
out("Or scope the run: wheels test --filter=<subdirectory>", "yellow");
} else {
out("Test execution failed: #e.message#", "red");
}
}

// Exit non-zero when specs failed/errored so CI and shells can detect it.
Expand Down Expand Up @@ -7584,8 +7637,13 @@ component extends="modules.BaseModule" {
return result;
}

private string function makeHttpRequest(required string requestUrl) {
return makeHttpRequestWithStatus(arguments.requestUrl).body;
/**
* @readTimeout Milliseconds to wait for the response. Defaults to the
* request/response bridge budget; long-running callers such as
* `wheels test` pass their own (issue #3352).
*/
private string function makeHttpRequest(required string requestUrl, numeric readTimeout = 120000) {
return makeHttpRequestWithStatus(requestUrl = arguments.requestUrl, readTimeout = arguments.readTimeout).body;
}

/**
Expand All @@ -7601,14 +7659,15 @@ component extends="modules.BaseModule" {
*/
private struct function makeHttpRequestWithStatus(
required string requestUrl,
boolean followRedirects = true
boolean followRedirects = true,
numeric readTimeout = 120000
) {
var javaUrl = createObject("java", "java.net.URL").init(arguments.requestUrl);
var conn = javaUrl.openConnection();
conn.setRequestMethod("GET");
conn.setInstanceFollowRedirects(javacast("boolean", arguments.followRedirects));
conn.setConnectTimeout(5000);
conn.setReadTimeout(120000);
conn.setReadTimeout(javacast("int", arguments.readTimeout));

var responseCode = conn.getResponseCode();
var inputStream = responseCode >= 400 ? conn.getErrorStream() : conn.getInputStream();
Expand Down Expand Up @@ -8023,7 +8082,8 @@ component extends="modules.BaseModule" {
var testUrl = "http://localhost:#serverPort##runnerPath#?db=sqlite&format=json&directory=#directory#";

try {
var httpResult = makeHttpRequest(testUrl);
// same long-running suite over the same 120s-default helper (issue #3352)
var httpResult = makeHttpRequest(testUrl, $resolveTestTimeout() * 1000);
} catch (any e) {
out("Failed to reach test runner at: #testUrl#", "red");
out("Is the server running? Try: wheels start", "yellow");
Expand Down
27 changes: 27 additions & 0 deletions cli/lucli/tests/specs/commands/TestCommandSpec.cfc
Original file line number Diff line number Diff line change
Expand Up @@ -110,6 +110,33 @@ component extends="wheels.wheelstest.system.BaseSpec" {

});

// Issue #3352: the shared HTTP helper reads for 120 seconds, which is right for the
// request/response bridge commands but is a hard ceiling on how big a suite `wheels
// test` can run. Past roughly 140 seconds the run fails with `Read timed out` and NO
// result document — not a failure report, a crashed runner — and the threshold moves
// with machine speed, so a suite can pass locally and fail in CI.
describe("$resolveTestTimeout", () => {

it("defaults to 900 seconds when nothing is supplied", () => {
// generous enough that a multi-minute suite completes, which is the ask
expect(mod.$resolveTestTimeout()).toBe(900);
expect(mod.$resolveTestTimeout("")).toBe(900);
expect(mod.$resolveTestTimeout(" ")).toBe(900);
});

it("honours an explicit --timeout", () => {
expect(mod.$resolveTestTimeout("1800")).toBe(1800);
expect(mod.$resolveTestTimeout(" 45 ")).toBe(45);
});

it("falls back to the default rather than throwing on junk input", () => {
// a mistyped timeout must not be the thing that stops a test run
expect(mod.$resolveTestTimeout("soon")).toBe(900);
expect(mod.$resolveTestTimeout("0")).toBe(900);
expect(mod.$resolveTestTimeout("-30")).toBe(900);
});
});

describe("$normalizeTestFilter (app mode)", () => {

it("returns empty string for empty input", () => {
Expand Down
10 changes: 9 additions & 1 deletion tools/test-local.sh
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,11 @@ DB="${DB:-sqlite}"
# Must match set(reloadPassword=...) in config/settings.cfm — a mismatch never
# reloads and, since #3062, counts against the per-IP reload rate limit.
PASSWORD="wheels-dev"
RESULT_FILE="/tmp/wheels-local-test-results.json"
# Per-checkout results file. A single fixed /tmp path is shared by every checkout on
# the machine, so two working copies running the suite overwrite each other's results —
# and a develop-vs-branch comparison silently becomes two copies of the same run
# (issue #3352). Keyed on the project root so concurrent checkouts stay separate.
RESULT_FILE="${WHEELS_TEST_RESULT_FILE:-/tmp/wheels-local-test-results-$(echo "$PROJECT_ROOT" | shasum | cut -c1-12).json}"

# Browser specs call back into the local Wheels CLI server — point Playwright
# at the right port. CI sets this explicitly before invoking the script;
Expand Down Expand Up @@ -129,6 +133,10 @@ if [ -n "$FILTER" ]; then
fi

echo "Running tests: Lucee 7 + SQLite${FILTER:+ (filter: $FILTER)}"
# Clear it first. When the request fails outright — a server that is not up yet reports
# HTTP 000 — curl may write nothing, leaving the PREVIOUS run's results sitting there to
# be read as if they were this run's (issue #3352). A crashed run must leave no result.
rm -f "$RESULT_FILE"
HTTP_CODE=$(curl -s -o "$RESULT_FILE" \
--max-time 600 \
--write-out "%{http_code}" \
Expand Down
Loading