Do not let an unreadable job result JSON kill the praktika runner before it reports - #112252
Do not let an unreadable job result JSON kill the praktika runner before it reports#112252groeneai wants to merge 8 commits into
Conversation
A coverage job whose 11882 tests all passed was reported as a red node with a completely empty info: a blank red box, no artifacts uploaded, and the dependent LLVM Coverage job plus Mergeable Check reddened with it. 39 such jobs on that shard alone over 21 days, across 38 unrelated PRs. The host docker daemon died during the post-run llvm-profdata merge, while Result.dump() was writing the ~1.5 MB result JSON. Serializable.dump opens the target with mode "w", which truncates it to zero bytes before the first byte of the payload is written, so the dying process left a 0-byte file and destroyed the RUNNING result _pre_run had persisted. Result.from_fs then raised JSONDecodeError. Of the two job-result reads in Runner.run the first (in _run) is caught by run()'s handler, but the second is unguarded while its sibling in _get_result_object is guarded, so the exception escaped to the interpreter and killed the runner before _post_run, the html report hook, the S3 upload and the commit status. Nothing ever attached a reason, so _finish_workflow later stamped ERROR with NOT_FINALIZED and an empty info. Three changes: - Result.dump() is now atomic: write a sibling temp file, flush and fsync, then os.replace onto the target, removing the temp on failure. A reader always sees either the previous complete content or the new complete content. Result inherits dump() and defines none of its own, so this single override covers every Result write path and touches no other Serializable subclass. The file content is byte-identical to before; only the write is staged. The temp must be a sibling, since os.replace is atomic only within one filesystem. - The read in _run degrades to a RUNNING result when the file is unreadable, so control enters the existing "not result.is_completed()" branch, which records the exit code, sets ERROR and attaches the last 20 log lines. It has to happen there because "process" is in scope in _run and nowhere else. RUNNING rather than ERROR is load-bearing: is_completed() is "status not in (PENDING, RUNNING)", so a synthesized ERROR is already completed and would skip that branch, removing the crash while preserving the blank-red-box symptom. RUNNING is also the state the process actually was in. - The second read uses the same helper. The reconciliation below it stays exactly where it is: it is the only conversion of a completed OK result into ERROR when the run failed, and it must stay outside "if run_hooks:" so local runs keep it and it stays ahead of the on_error_hook. This cannot hide a failure. The fallback's is_ok() is False, so the job stays red and is still counted in failed_results; a valid result holding a real test FAIL is returned byte-unchanged, and Serializable.from_file still raises, so only these two callers decide to degrade. One intended consequence: once the second read no longer aborts, _get_result_object promotes and dumps the result, so NOT_FINALIZED is no longer recorded for this signature and the reason moves into the job's own info. Two new pure-Python test files under ci/tests/, 18 tests, no build required. They fail 13/18 against unmodified sources and pass 18/18 with the change. Eleven mutants were run, each killed by its predicted assertion, including the one that synthesizes ERROR instead of RUNNING. Complementary to ClickHouse#109673: that PR labels a docker-daemon-death truncation as infra, but its label sits in a branch this signature cannot reach today because the read above it raises. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The existing tests call Runner._read_job_result_or_running directly and pin the source spelling of its call sites by AST. Neither sees the branch that actually produced the incident report: an unreadable result file must degrade to RUNNING so that _run's `if not result.is_completed():` block runs, records why the job died, and attaches process.get_latest_log() - which is reachable only inside the `with TeePopen(...)` scope. Two tests drive Runner._run itself, in-process with no docker and no server, and assert on the result read back from disk: the nonzero-exit case must persist ERROR carrying both the read error and the log tail plus the kill reason, and the exit-0 case must be left RUNNING rather than given a fabricated completed status. On unmodified master both fail by letting JSONDecodeError escape _run, which is the crash the change removes. Three mutants are each killed by a named assertion: returning ERROR instead of RUNNING from the helper, and moving the recovery out of the TeePopen scope, both lose the log tail; deleting set_status(ERROR) loses the status. Co-Authored-By: Claude Opus <noreply@anthropic.com>
The temp path Result.dump() stages into is derived from the result path and the writer's pid, so a job sharing the worktree can guess it and pre-create it as a symlink. open(path, "w") follows symlinks, so the dump would truncate and write whatever the link points at. Open the temp file with O_NOFOLLOW instead, which refuses the symlink with ELOOP and leaves both the link target and the previously persisted result untouched. The explicit mode is 0o666 so the created file keeps the permissions the plain open() produced (0o664 under the CI umask). Deliberately not O_EXCL: a leftover temp from a dump that was killed mid-write must stay reusable. With O_EXCL a normal dump after such a kill raises FileExistsError, turning the very crash this method exists to survive into a hard failure. Deliberately not tempfile.mkstemp() either: it creates with mode 0o600 and a random name, and the name has to stay derived from the pid so two processes writing the same result cannot collide. Also restore PRAKTIKA and PYTHONPATH around the tests that drive Runner._run; _run sets both process-globally and pytest does not restore process env between tests. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The e2e tests move the praktika temp directory aside in their cleanup: test_fuzzer and test_stress both rename ci/tmp to ci/tmp_result (and back up a pre-existing one to ci/tmp_backup) so a failed run's artifacts stay available for inspection. /ci/tmp is already ignored, but those two names were not, so any local ci/tests/ run left an untracked directory behind and runner._post_run reported a dirty repo state.
…al tests Two properties the change relies on were claimed but not observed by any test. Runner.run reads the job result a second time outside all three of its try blocks. That read is the crash site of the incident, yet both existing behavioral tests drive Runner._run instead, so nothing executed it, and the structural pin covering it rejects only the AST spelling Result.from_fs(job.name). Since Result.from_fs is cls.from_file(cls.file_name_static(name)), writing the equivalent Result.from_file(Result.file_name_static(job.name)) unparses differently, keeps the structural pin green, and reinstates the unhandled JSONDecodeError. The new test drives the real Runner.run with local_run=True and run_hooks=False so the only thing between the stubbed run and the exit is that read, and asserts SystemExit(1) plus the "Run script finished" print that sits after it, so an unguarded read fails the test by the crash itself. O_EXCL is deliberately absent from the temp-file open so a leftover temp from a previously killed dump stays reusable, otherwise crash recovery would itself crash. No test observed that: the existing ones assert the temp is absent after a failed dump, or pre-create a symlink, which O_EXCL also rejects, with EEXIST instead of ELOOP. An implementation adding O_EXCL therefore passed every test while turning recovery into FileExistsError. The new test hand-creates a regular leftover at the derived path and asserts the dump lands. Tests only; no praktika source change. Each new test is killed by a mutant that no pre-existing assertion catches.
Internal second-model review - adjudication log (click to expand)Pre-publication review by an independent model (engine: codex; 5 review rounds over the PR's
Severity: ❌ blocker / Session id: cron:clickhouse-review-slot-50:20260728-085200 |
Pre-PR validation gate (click to expand)
Session id: cron:clickhouse-review-slot-50:20260728-085200 |
|
cc @maxknv - could you review this? When the docker daemon dies mid- |
|
Workflow [PR], commit [e2910ba] Summary: ✅ AI ReviewSummaryThis PR makes Missing context / blind spots
Final Verdict✅ No new blockers or majors. |
The degradation added for the CI crash also changed the default local path. `python3 -m ci.praktika run` calls `Runner.run` with `local_run=True` and `run_hooks=False` (`__main__.py:396-398`), so `_get_result_object` - the only place that promotes a non-completed result to ERROR - never runs. A job that exited 0 but left its result file unreadable therefore reported success while the persisted result was still RUNNING, where before the degradation the unhandled JSONDecodeError exited 1. Measured on the default local invocation, over a job that truncates its own result file and exits 0: master exits 1, the published head exits 0. Six job outcomes (unreadable/garbage/no-result/failed/ok/failed-with-result) now all match master's exit code, with a readable ERROR instead of a crash. The failure is keyed on a marker set only when the read actually failed, not on `not result.is_completed()`. A local run whose job writes no result at all legitimately ends on the RUNNING/PENDING result that the pre-run dump persisted and exits 0 on master too, so the broader condition would turn that pre-existing case red. The `res` guard keeps the compensation off the already-failed path, which `_run` has already reported with the log tail. The CI path is unchanged: `_run`'s recovery branch still attaches `process.get_latest_log()` and still leaves RUNNING for `_get_result_object`. Reported by clickhouse-gh[bot], with a reproduction, on the PR.
The compensation was unconditional, so a run with the hooks enabled also had its result completed and `res` cleared before `_get_result_object` saw it, turning a run that previously exited 0 into exit 1. The promotion of a non-completed result is `_get_result_object`'s job and it runs under `if run_hooks:`, so only a run that skips the hooks needs it here. Gating on `not run_hooks` restores the hook path byte for byte (measured: exit 0 on both this branch and the previous head) and leaves the local path fixed. Also restore JOB_NAME and CHECK_NAME in the test fixture, which generate_local_run_environment sets process-globally.
Move completed-OK result normalization into `_get_result_object` and use `run_exit_code` as the source of truth. Keep hook-less unreadable-result handling scoped to synchronizing the local command exit code through `READ_FAILED_EXT_KEY`. Related: ClickHouse#112252 Test: pytest ci/tests/test_runner_unreadable_result_json.py ci/tests/test_runner_result_finalization.py
Do not let an unreadable job result JSON kill the praktika runner before it reports
Changelog category (leave one):
Changelog entry (a user-readable short description of the changes that goes into CHANGELOG.md):
Not user-facing: CI harness only.
Description
A
Stateless tests (amd_llvm_coverage, AsyncInsert, s3 storage, parallel)job whose 11882 testsall passed was reported as a red node with a completely empty
info- a blank red box in thereport, no artifacts uploaded, and the dependent
LLVM Coveragejob plusMergeable Checkreddenedwith it. CIDB records
check_status='error',test_name=''and zero failing test rows.Observed on
this job
(report),
and 39 times on that shard alone over the last 21 days across 38 unrelated PRs (26 more on
ParallelReplicas, s3 storage, parallel, 13 onold analyzer, ... 2/3, plus ~20 singletons on theother coverage shards). It concentrates on the longest coverage jobs, i.e. the ones with the
heaviest post-run
.profrawmerge.Root cause
The job finished all tests, then spent ~4 minutes in post-processing (jemalloc flamegraphs, then
llvm-profdata mergeof 22 x 176 MB.profrawfiles). Mid-merge the host docker daemon went away:Serializable.dumpisopen(self.file_name(), "w")+json.dump, andopen(..., "w")truncatesthe target to zero bytes before the first byte of the payload is written. A process killed inside
that window therefore leaves a 0-byte result file, destroying the
RUNNINGresult_pre_runhadpersisted. The from-root
chownwhose entire purpose is to make that file host-readable failed too(the daemon was gone), and its
Shell.runreturn value is discarded.Result.from_fsthen raisesJSONDecodeError: Expecting value: line 1 column 1 (char 0). There aretwo job-result reads in
Runner.run:runner.py:490, insidewith TeePopen(...) as process:. Its raise unwinds intorun'stry(body
1071..1086,except Exceptionat1087..1091) and is caught - the first traceback inthe log carries praktika's own
[timestamp]prefix becausetraceback.print_exc()printed it.runner.py:1093, which is not guarded, while its sibling at:548already is. Its raise isthe interpreter's own unhandled-exception dump (second traceback, no timestamp prefix, via
runpy->__main__.py:393), immediately followed by##[error]Process completed with exit code 1.So the runner dies at
:1093, before_get_result_object,_post_run, the html report hook, theS3 upload and the commit status -
grepof the job log finds=== Run script finished,=== Post run scriptandRun html report hookzero times. Nothing ever attaches a reason, so_finish_workflow(native_jobs.py:1049-1083) later finds the job resultnot is_completed(),stamps
ERRORand recordsNOT_FINALIZED. That is exactly whyinfois empty.The fix
1. Make
Result.dump()atomic (ci/praktika/result.py). Write to a sibling temp file,flush+fsync, thenos.replace()onto the target, removing the temp on any failure. A readernow always sees either the previous complete content or the new complete content.
Resultinheritsdump()and defines none of its own on master, so this single override covers everyResultwritepath - all of
complete_job,copy_result_to_s3[_with_version]and the_dump_if_persistedsetterpath included. The file content is byte-identical to the base implementation - only the write is
staged. The temp must be a sibling:
os.replaceis atomic only within one filesystem.Scoped deliberately to
Result.MetaClasses.Serializable.dumpandSerializableSingleton.dumparethe same in-place
open(..., "w")pattern, so_Environment,RunConfig,TestCaseIssueCatalog,StorageUsageandComputeUsagecan lose their files the same way. None of them is the file thatcaused this incident, and losing a usage counter degrades a metric rather than blanking a job report,
so widening the change is left for whoever wants it rather than bundled here.
This also fixes the write half of the same infra event, which is easy to miss. When the from-root
chownfails the result file is left root-owned, and the baseopen(target, "w")then raisesPermissionErroron the host side;os.replaceneeds write permission on the directory, not onthe target, so the host-side dump at
runner.py:510succeeds where an in-place write could not.The temp path is derived from the result path and this pid, so it is guessable by anything sharing
the worktree. The staged write therefore uses
os.open(tmp, O_WRONLY|O_CREAT|O_TRUNC|O_NOFOLLOW, 0o666)rather thanopen(tmp, "w"): apre-existing symlink at the temp path is refused with
ELOOPinstead of being written through.Two details are deliberate. The mode is
0o666so that, after umask, the created file's mode isbyte-identical to what
open(path, "w")produces (0o664under the CI umask) -tempfile.mkstemp()would silently narrow the result file to
0o600for every downstream reader, and its random namewould also give up the per-pid determinism. And the flags do not include
O_EXCL: a leftovertemp from a previously killed dump must stay reusable, otherwise the very crash this method exists
to survive would turn into a hard
FileExistsError. Both properties are pinned by tests.2. Recover at the
_runread (ci/praktika/runner.py). A newRunner._read_job_result_or_runningreturns aRUNNINGresult when the file is unreadable, socontrol enters the existing
if not result.is_completed():branch, which recordsJob killed, exit code [...], setsERRORand attachesprocess.get_latest_log(max_lines=20).This has to be inside
with TeePopen(...) as process:(lines469..510) -processis referencedin
_runand nowhere else, so a recovery at:1093could never reach the log tail.The
RUNNINGstatus is load-bearing, not cosmetic.is_completed()isstatus not in (PENDING, RUNNING), so a synthesizedERRORis already completed and skips thebranch above:
is_completed()infoERRORFailed to read Result json, ex: [...]RUNNINGJob killed, exit code [...]+ the log tailRUNNINGis also what the process actually was: it is precisely the state_pre_runpersisted, sothe fallback reconstructs reality rather than inventing it.
3. Make the second read safe (
ci/praktika/runner.py) - the same helper at:1093. Theif not res and result.is_ok(): set_status(ERROR)reconciliation right below it is kept exactlywhere it is, on the unconditional run path: it is the only conversion of a completed
OKresultinto
ERRORwhen the run failed (_get_result_objectonly promotes results that are notcompleted), and it must stay outside
if run_hooks:so ordinary local runs keep it and it staysahead of the
on_error_hook._get_result_object's own guard is left unchanged - it is the last-resort path, and with noprocessin scope there its terminalERRORis correct. The two workflow-result reads in_post_runread a different file written by a different process; they are a separate concern andare not touched here.
4. Keep the hook-less local run red (
ci/praktika/runner.py).python3 -m ci.praktika runcalls
runwithlocal_run=Trueandrun_hooks=False(__main__.py:396-398), so theif run_hooks:block - and with it_get_result_object, the only place that promotes anon-completed result - is skipped. Degrading the read there would report success for a job that
exited
0but left nothing readable, where before the degradation the unhandledJSONDecodeErrorexited
1. So when the hooks are skipped, a synthesized result is promoted toERRORand clearsres, which restores the old exit code with a readable reason instead of a traceback.The condition is "the read failed", tracked by an
extmarker set only in the fallback - notnot result.is_completed(). A local run whose job writes no result at all legitimately ends on theRUNNING/PENDINGresult the pre-run dump persisted and exits0on master too, so the broadercondition would turn that pre-existing, unrelated case red. It is also gated on
not run_hooks(the hook path's promotion and exit code are unchanged, measured) and on
res(a job that alreadyfailed has been reported by
_run, log tail included).This cannot hide a failure
The job stays red on every path. The fallback's
is_ok()isFalse, so_get_result_objectpromotes it toERRORand_finish_workflowstill counts it infailed_results. A valid result holding a real testFAILis returned byte-unchanged - there is anexplicit test for that. The change converts a crash with no information into a red job that says
why, and
Serializable.from_filestill raises: only these two callers decide to degrade.One intended consequence worth naming: once
:1093no longer aborts,_get_result_objectpromotesand dumps the result, so
native_jobs.py:1049'snot is_completed()stops firing for thissignature and
NOT_FINALIZEDis no longer recorded. The reason moves from nowhere into the job's owninfo.Testing
Two new pure-Python files under
ci/tests/(which runs on every PR), 31 tests, no build required:test_result_dump_atomic.py- a write that dies partway leaves the previous complete contentreadable; the temp file is a sibling of the target and uniquely named per process; no temp is left
behind on failure; content and mode are identical to the base implementation; a symlink at the
temp path is refused with
ELOOPwhile both the symlink target and the previously persisted resultstay intact; a stale regular temp left by a previously killed dump is reused rather than rejected;
nesting round-trips.
test_runner_unreadable_result_json.py- empty / truncated-mid-key / truncated-before-brace /garbage / missing file all degrade to a
RUNNING,is_completed() is False,is_ok() is Falseresult with the reason in
info; a genuineFAILand a genuineOKare returned unchanged; ASTassertions pin that no bare
Result.from_fs(job.name)returns torun/_runand that thereconciliation stays on the unconditional path, outside
if run_hooks:, ahead of_get_result_object; two tests drive the realRunner._runin-process over a 0-byte resultfile (no docker, no server, no build) and assert on the result read back from disk -
exit 125gives
ERRORcarrying both the read error and the job's own log tail ininfoplusJob killed, exit code [125]inerrors, whileexit 0staysRUNNINGso promoting it remains_get_result_object's job; and one drives the realRunner.runso the second read, the one thatactually killed the runner, is executed rather than only pinned by AST. The hook-less local path
has its own group: a job that exits
0leaving an unreadable result makes the command exit1with
ERROR; a readableOKstill exits0; a merelyRUNNINGresult is left alone (the controlthat keeps the condition off
is_completed()); the hook path is handed an untouchedRUNNINGresult so the promotion stays
_get_result_object's; the already-failed path keeps_run's logtail; and the marker is present only on a synthesized result and survives the dump round trip.
Both directions: the 31 tests fail 23/31 against unmodified
mastersources and pass 31/31 with thechange; on master the first
_runtest fails by raisingJSONDecodeErrorout ofrunner.py:490and the
runtest by raising it out ofrunner.py:1093, i.e. by the crash itself rather than by anassertion. 27 mutants were run, each killed by its predicted assertion - including the important one,
synthesizing
ERRORinstead ofRUNNING, which removes the crash while silently suppressing the logtail, and the closely related one that moves the recovery out of the
with TeePopen(...)scope. Bothare caught by
"daemon-death-tail" in persisted.info, the first also byis_completed() is False.Rewriting the second read as the equivalent
Result.from_file(Result.file_name_static(job.name))is amutant too: it slips past the AST pin and is caught only by the
Runner.runtest. DroppingO_NOFOLLOW, narrowing the mode to0o600and usingO_EXCLare mutants as well - the first two dieon the symlink test and the mode assertion, the third on the stale-regular-temp test (the symlink test
rejects
O_EXCLtoo, but withEEXISTrather thanELOOP, i.e. for the wrong reason). Six of the27 target the hook-less local path: deleting the promotion, broadening it to
not is_completed(),dropping the marker, dropping the
resguard, dropping thenot run_hooksgate, and persistingERRORwithout clearingres. The fullci/tests/suite was run before and after; the threepre-existing cases that need a live server on the machine used here flap independently of this diff,
so the clean A/B excludes exactly those: 482 -> 487 passed with 0 failures in both arms, i.e. exactly
the new tests.
Also measured directly on the default local invocation, over six job outcomes (unreadable / garbage /
no-result / failed /
OK/ failed-with-result): every exit code now matches unmodifiedmaster,with a readable
ERRORin place of the traceback in the two unreadable cases.fsyncadds a sync per dump; against an ~80-minute coverage job with a ~1.5 MB result payload(~32 ms to serialize) that is negligible. It can be dropped if preferred - the atomicity guarantee
comes from
os.replace, not fromfsync, and no durability beyond that is claimed.The
.gitignorehunk is why running the suite locally is now clean: the pre-existingci/tests/test_e2e.pyrenamesci/tmptoci/tmp_result(andci/tmp_backup) in itsfinallyblocks, and only
/ci/tmpwas ignored, so both scratch directories showed up as untracked sourceafter any
ci/tests/run. The test itself is left alone.Relation to #109673
#109673 labels a docker-daemon-death
truncation as infra so the job is auto-retried. Its label sits inside the
exit_code != 0/not result.is_completed()branch, which this signature cannot reach todaybecause the read above it raises. The two are complementary: that PR decides what to do once the
branch is entered, this one makes an unreadable result file reach it at all. Its
is_completed()precondition is provably satisfied by the
RUNNINGsynthesis; no claim is made here aboutauto-retry firing end to end.
Prior art for the shape (praktika fix + a
ci/tests/regression test for a docker-daemon-deathclass): merged #109096.
No related open issue found for this signature.