test(e2e): a script op ran past its declared timeout without being cut off #4268

Describe the bug

On run 34948279363 the verify-every-bucket-takes-a-write step in hack/e2e-chainsaw/bucket/chainsaw-test.yaml declared timeout: 5m and ran for 606 seconds. It ended on its own, with a non-zero status from mc, rather than by being cut off.

The step markers, with ANSI stripped:

09:28:53.5150198Z  verify-every-bucket-takes-a-write | TRY    | BEGIN
09:38:59.7706736Z  verify-every-bucket-takes-a-write | SCRIPT | LOG
09:38:59.7715173Z  verify-every-bucket-takes-a-write | SCRIPT | ERROR
09:38:59.7716905Z  verify-every-bucket-takes-a-write | TRY    | END
09:39:01.8570856Z  verify-every-bucket-takes-a-write | SCRIPT | LOG
09:39:02.0171984Z  verify-every-bucket-takes-a-write | SCRIPT | DONE
09:39:12.0650052Z  verify-every-bucket-takes-a-write | SCRIPT | LOG
09:39:12.0666298Z  verify-every-bucket-takes-a-write | SCRIPT | DONE

TRY BEGIN to SCRIPT ERROR is 606.26s against the declared 300s. The two pairs after TRY END are the global error.catch operations, which log under the same step name, so they sit outside that interval instead of inside it. That distinction is the whole measurement: a grep on the step name alone merges catch with the script op, and then the number is not the script's. The split reconciles with the JUnit total of 645.6s for the case, as 1s creating buckets, 27s of readiness asserts, 606s of script and 12s of catch.

The failure arrived as ($error == null): Invalid value: false, which is the check on the script's own error. Searching every line of the suite for deadline exceeded, timed out, timeout and signal: killed returns nothing.

What this does not establish

The mechanism. Two candidates, and the log does not separate them:

1. An operation timeout does not bound a script op in Chainsaw v0.2.15.
2. It does bound it and kills the shell, but Chainsaw waits on a pipe that a grandchild process (mc) still holds open, so control does not come back until that process exits.

One indirect sign favours the second: every line of script output carries the single timestamp 09:38:59, which is what buffering until pipe close looks like. That is a hint rather than a finding. I have not shown that operation timeouts fail to apply, and this report does not claim it.

Environment

• Cozystack: main
• In-tree e2e lane, container sandbox
• Chainsaw v0.2.15
• Seen on run 34948279363

To Reproduce

Any script step whose command stays busy past its declared timeout should show it. The one above did so because the S3 PUT it runs fails only after the gateway and mc have each exhausted their own retries.

Expected behaviour

A script operation that passes its declared timeout is cut off at it, and says so.

Actual behaviour

It ran to its own completion at twice the declared ceiling, and nothing in the output mentions a timeout.

Additional context

This matters past one slow step because other timeouts are sized on the assumption that the ceiling cuts. hack/e2e-chainsaw/.chainsaw.yaml picks 6m and 13m for its catch operations on the stated premise that otherwise Chainsaw SIGKILLs the whole script partway through, and docs/agents/e2e-testing.md carries the same reasoning. If an operation ceiling does not cut a busy script, that premise is doing no work and those numbers rest on nothing.

It also changes the shape of #4250 rather than repeating it. That issue is about an operation ceiling smaller than the sum of its inner read caps, and its concern is that the ceiling fires first and reports only signal: killed. Both halves assume the ceiling fires at all. If it does not, the problem is not that the wrong instrument fires but that none does, and the remedy moves from resizing ceilings to making sure every read carries its own cap.

Not introduced by any current change: the pre-existing bucket case in the same file carries the same timeout: 5m on its own script step. The only visible cost today is on a failing run, where the capacity case takes about ten minutes instead of five. On a passing run the writes succeed immediately and the step is short.

Checklist

• I have checked the documentation
• I have searched for similar issues
• I have included all required information
• I have provided clear steps to reproduce
• I have included relevant logs