Intermittent AuTest failure: h2origin (squid.log not written within 10s)
- Dominant language
- C++
- Stars
- 2k
- Forks
- 874
- Avg merge
- 6d 15h
- Merged PRs (30d)
- 46
Description
The `h2origin` gold test (`tests/gold_tests/h2/h2origin.test.py`) is flaky on CI: the "Wait for the squid.log to be written" run intermittently fails because the log line does not appear within a 10-second readiness window. It passes on re-run with no code change.
```
Run: Wait for the squid.log to be written: Failed
Starting TestRun 2-tr : Checking that Process is ready within 10.0 seconds so we can start process: Default - Failed
Reason: Process failed to become ready in time: 10.0 seconds. Waited 10.000008344650269 seconds
Process: watcher: Passed
Time-Out : Process finishes within expected time - Passed
Reason: Returned value: 9.50020146369934 < 30.0
Process: Default: Skipped
Reason: Was not started
```
Seen on https://ci.trafficserver.apache.org/job/Github_Builds/job/autest/40871/ (AuTest 0of4), where the other 65 test files in the shard passed.
The test intends a 30-second budget for the wait:
https://github.com/apache/trafficserver/blob/master/tests/gold_tests/h2/h2origin.test.py#L87-L98
`watcher.TimeOut` and `tr.TimeOut` are both set to 30, but the readiness gate that `StartBefore` applies to the watcher is a separate 10-second default that the test does not raise. The watcher was still waiting at 9.5s when the readiness check expired at 10.0s, so the 30-second budget is never reached. Squid log entries appear only when the log buffer is flushed, so on a loaded CI worker the entry for the last transaction can take longer than 10 seconds to show up.
Passing `ready=` with a longer timeout to `StartBefore`, or lowering the log flush interval for this test, would make the wait honor the intended budget.
Contributor guide
Research direction
Start with tests/gold_tests/h2/h2origin.test.py around lines 87-98 and run the h2origin AuTest case to reproduce the readiness timeout. Check how StartBefore handles the watcher readiness window versus its 30-second timeout; done means the test waits for the squid.log entry within the intended budget and passes reliably on CI.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python
- Domain
- testing
- Issue type
- Bug
- Difficulty
- 2/5
- Estimated time
- 1-3 hours
- Activity status
- Quiet
- Clarity
- Clearly specified
- Newbie friendliness
- 58/100