Repository navigation
chore(canary): keep captured logs on a RED, and correct the 401's surface - #572
Merged
Merged
Conversation
… surface The canary's REDs reproduce only unattended, so anything a run does not record is unrecoverable afterwards. Three REDs (2026-08-20/23/25) named the same test and preserved only a traceback — which for an auth 401 is the same shape whatever the cause. Run pytest with `-o junit_logging=all` so the preserved `tmp/canary-red-*.xml` carries the run's structlog output. The deciding line is already emitted: `client.context_cookie_state` (the #222 diagnostic) reports whether the launched browser context actually loaded the Flow session cookie. That boolean separates "the browser never got the cookie" from "the session was genuinely refused". Verified: the line lands in the JUnit under this flag. Also corrects docs/E2E_TESTING.md. The failure is a 401 on `labs.google/fx/api/trpc/project.createProject` — the NextAuth cookie surface — not the aisandbox Bearer/uploadImage path. The failing test is named for an upload, but the traceback dies one line earlier on project creation. #561 was recorded against the wrong host and its transport A/B tested a code path the failure never reaches. No behaviour change: the canary gates nothing, and the JUnit already stayed local carrying raw tracebacks, so the sanitization contract is unaffected. Refs #559, #561
This was referenced Aug 25, 2026
ffroliva
added a commit
that referenced
this pull request
Aug 26, 2026
…alled (#583) `run_canary.py --pull` fast-forwards the checkout and then keeps executing the copy Python loaded at startup, so every runner change was silently one night late. Not theoretical. #572 added `-o junit_logging=all` so a preserved RED would carry the `client.context_cookie_state` line that decides #561. It merged 2026-08-25 12:29 UTC; the 2026-08-26 02:00 run pulled it and produced a RED with ZERO log output, because the pre-pull copy was running: git show 230200b:scripts/canary/run_canary.py | grep -c junit_logging -> 0 Three REDs untriageable, and the failure reads as "#572 did not work" — which invites rewriting a fix that was already correct. Confirmed #572 is fine: a manual run on the current runner captured 40 system-out entries, 11 context_cookie_state lines, and flow_session_cookie_present. The runner now re-runs itself once when a successful pull changed its own source. Two independent loop guards, either sufficient alone: GFLOW_CANARY_REEXECED in the child env (checked first), and a content digest. An unreadable digest degrades to "unchanged" — updating late is a nuisance, looping is an outage. subprocess.run, never os.execv: on Windows execv does not replace the process image, so the PID changes and Task Scheduler can read the task as finished. A supervising process keeps that view intact and propagates the exit code. Asserted by an AST test, since a substring search matches the module's own explanation. The fix cannot help its own deployment — the first run after it lands is still the old runner. It applies from the following change onward. E2E on a scratch clone against a real profile, $0: control pre-fix runner, pull brings the flag -> no re-exec (correct), JUnit system-out: 0 <- reproduces 02:00 treatment fixed runner, develop ahead with a runner change -> canary.reexec_after_pull: ffd32333cb9b -> fef66243ee51 -> ran once, no loop, JUnit system-out: 42 Closes #582
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Three canary REDs (2026-08-20 / 08-23 / 08-25) named the same test and preserved only a traceback. For an auth 401 that traceback is the same shape whatever the cause, and the failure reproduces only on the unattended overnight run — so every red so far has been untriageable by construction.
Two changes, both evidence-driven.
1. Keep the logs (
-o junit_logging=all)The line that decides this is already emitted on every run —
client.context_cookie_state, the #222 diagnostic, which reports whether the launched browser context actually loaded the Flow session cookie:pytest captures it and throws it away. With this flag it lands in the preserved
tmp/canary-red-*.xml. Verified empirically before committing.That boolean is the discriminator:
present=False→ the browser context never loaded the cookies. Same class as macOS: generation runs on bundled Playwright Chromium despite .gflow_browser_strategy=chrome → 401 AuthExpiredError on createProject #222 (macOS), whereproject.createProject401'd while login and verification both passed because they read cookies a different way.present=True→ the context held a valid cookie and was still refused. Different cause, but the count / SAPISID / expiry come with it.2. Correct which auth surface fails
The preserved JUnit from all three REDs is byte-identical:
That is the NextAuth cookie surface. No Bearer token is involved —
_aisandbox_auth_headers()is gated onis_aisandbox(client.py:1256) and never runs. The failing line is:69(create_project), not:70(upload_image).#561 is titled for an
uploadImagefailure and its transport A/B tested a code path the failure never reaches.docs/E2E_TESTING.mdrepeated the same wording; corrected here so the next reader does not re-investigate the wrong host.What this PR deliberately does NOT do
No fix. The failure is not reproducible on demand — verified today against the live
denon82profile at $0:auth statusexit 0, the failing test 1 passed standalone, the full tier 18 passed. #561's own standing rule applies: no fix against a failure we cannot reproduce. This PR only makes the next occurrence readable.Falsified along the way
A leading hypothesis was that the canary's own pre-run
gflow auth statuscaused the RED: the session probe makes labs.google issue a rotated__Secure-next-auth.session-tokenviaSet-Cookie, which gflow-cli discards, leaving the profile on the superseded token. Measured directly — dead:createProjectwith on-disk token, x2Rotation is harmless. The canary is not causing its own red.
Test plan
tests/scripts/test_canary_classify.py::test_tier_run_captures_logs_into_the_junit— new, TDD (red → green)client.context_cookie_statereaches the JUnit under the flagruff check src tests+ruff format --check src tests: passpyright src: 0 errorswebsite/docsmirror regeneratedTiming
The canary runs from a dedicated clone that pulls
developbefore each run. This needs to be ondevelopbefore 03:00 tonight or tomorrow is another blind red.Refs #559, #561