feat(ci): Make the revdep driver log's timing record durable and visible - #2891
Merged
Conversation
_R_CHECK_TIMINGS_ stays off, by revdep2's still-valid reasoning: the two halves run at different times next to different neighbours, so per-stage [user/elapsed] stamps differ by construction and would be pure noise in the log the halves are compared through. The compensating claim -- "what a stage cost is still recorded by the elapsed stamping on the driver log" -- went quietly false in the container era: the driver log lived only in the runner's work directory and never reached an artifact. Run 33777134786's both-halves timeouts salvaged nothing at all, and "where did the 1800 seconds go" had no answer anywhere. Three changes make the record real again: copy_check_output() carries driver.log and status alongside every kept check directory; compare-one.R salvages the *failed* side too (both sides when both fail -- a killed check leaves a partial .Rcheck whose log lists every completed stage, and even a container that never ran leaves its driver log); and check-half.sh prints a failed half's stage timeline into the job log, where GitHub's own timestamps stack on the elapsed stamps. Successful halves stay quiet, so the artifact and log cost is confined to the handful of failures per run. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01UB7YutLzVWU7xCTYUvF3kF
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.
Prepared with Claude Code (LLM-assisted).
Why
_R_CHECK_TIMINGS_is off, and stays off. The setting is inherited from revdep2 with a rationale that still holds: the two halves of a package run at different times next to different queue neighbours, so per-stage[user/elapsed]stamps differ by construction and would be pure noise in the very log the halves are compared through. The design compensated withcheck-half.sh'sstamp()filter — every container line prefixed with elapsed seconds indriver.log— and the comment promised "nothing is lost".That promise went quietly false in the container era: the driver log only ever lived in the runner's ephemeral work directory. The timeout analysis of run 33777134786 hit the wall this creates — for both-halves timeouts (ctmm, E2E, PortfolioTesteR) nothing was salvaged, and "where did the 1800 seconds go" had no answer in any artifact or log.
Three changes make the record real again, at a cost confined to the handful of failures per run:
copy_check_output()now carriesdriver.logandstatusalongside every kept check directory, so anything salvaged brings its per-stage timeline with it.salvage_side()incompare.R, wired intocompare-one.R's failure branches — both sides when both fail). A killed check leaves a partial.Rcheckwhose00check.loglists every stage it completed; even a container that never ran leaves its driver log. Verified locally with simulated timeout work directories in both shapes.check-half.shprints a failed half's stage timeline (the stamped* checking …lines, last 60) into the job log under a collapsible group, where GitHub's wall-clock timestamps stack on the elapsed stamps. Successful halves stay quiet.After this, the next timeout's post-mortem is one grep — over the job log or the salvaged
driver.login therevdepx-reportartifact — instead of an archaeology expedition.🤖 Generated with Claude Code
https://claude.ai/code/session_01UB7YutLzVWU7xCTYUvF3kF
Generated by Claude Code