h2origin autest: honor the 30s squid.log wait budget

[mandarwagh9]

Fixes #13445.

Problem

tests/gold_tests/h2/h2origin.test.py hand-rolled its "wait for
squid.log" step:

tr = Test.AddTestRun("Wait for the squid.log to be written")
timeout = 30
watcher = tr.Processes.Process("watcher")
watcher.Command = f"sleep {timeout}"
watcher.Ready = When.FileContains(ts.Disk.squid_log.Name, r'14 http/1.1 http/2')
watcher.TimeOut = timeout
...

The intent is a 30-second budget, but neither watcher.TimeOut nor
tr.TimeOut governs the readiness gate. That gate is StartupTimeout,
which Processes.Process() defaults to 10 seconds:

• autest/testenities/processes.py: startup_timeout=10, # default to 10 second as most things should be ready by this time
• autest/runlogic/runlogic.py: if ready_item.object.StartupTimeout < curr_temp: ... "Checking that {typename} is ready within {ready_item.object.StartupTimeout} seconds ..."

So the run failed at 10.0s while the watcher was still waiting at 9.5s,
exactly as reported in the issue. On a loaded CI worker the squid.log
entry for the last transaction had not been flushed yet.

Worth noting: simply raising StartupTimeout to 30 would still race,
because the watcher's own sleep 30 would exit at about the same
moment, tripping autest's "Process finished before it was ready" path.

Fix

Two complementary changes:

1. Use the existing AddAwaitFileContainsTestRun helper
   (tests/gold_tests/autest-site/when.test.ext) instead of the
   hand-rolled watcher. It sets StartupTimeout = 30 against a
   sleep 60, so the 30-second budget is actually honored with no
   sleep/gate race. This helper is already used at 20+ call sites;
   logging/log-milestone-fields.test.py::_waitForLog is the same
   shape, StillRunningAfter lines included. h2origin was simply a
   leftover from before the helper existed.

2. Set proxy.config.log.max_secs_per_buffer: 1 so the log entry
   appears promptly rather than waiting out the default 5-second buffer
   flush. This addresses the underlying latency the issue describes
   rather than only widening the window. 13 other gold tests that assert
   on log contents already do this.

The needle, test-run name, and StillRunningAfter assertions are
unchanged, so coverage is identical.

Testing

Verified locally: yapf 0.43.0 with .style.yapf reports no
formatting changes, and the file compiles. I develop on Windows and
cannot build or run ATS there, so I have not executed the autest
myself — relying on Jenkins for that. The change is confined to test
configuration and contains no production code.

🤖 Generated with Claude Code

[Copilot]

Copilot was unable to review this pull request because the user who requested the review has reached their quota limit.

[Copilot]

Pull request overview

Copilot reviewed 1 out of 1 changed files in this pull request and generated no new comments.

Comments suppressed due to low confidence (1)

tests/gold_tests/h2/h2origin.test.py:52

• All neighboring ts.Disk.records_config.update() values are strings; setting this one as an int is inconsistent and can be problematic if the config writer expects string values. Use '1' (string) for consistency with the rest of the records config values in this file.

        # Flush log buffers promptly so that the squid.log entry for the last
        # transaction appears while the test is still waiting for it.
        'proxy.config.log.max_secs_per_buffer': 1,

[cmcfarlen]

[approve ci]

[cmcfarlen]

Actually just ran into this on the 10.2.x branch. The h2origin autest is flaky waiting for the log update. Thanks so much for the fix!

[bneradt]

Can you please rebase, @mandarwagh9 ? I've also add you to the CI allow list, so CI should run for your PR on a future push.