From 14cbc8dad3611b959fef2c7cf78bebe6d22be39e Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Wed, 26 Aug 2026 03:27:17 +0000 Subject: [PATCH] chore(wolf): checkpoint buglog.json (1038 bugs) --- .wolf/buglog.json | 35 +++++++++++++++++++++++++++++++++++ 1 file changed, 35 insertions(+) diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 3038282c..fb09de57 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -19062,6 +19062,41 @@ ], "occurrences": 1, "last_seen": "2026-08-25T16:20:00Z" + }, + { + "id": "bug-1697", + "timestamp": "2026-08-25T20:22:00Z", + "error_message": "Job start_time is always 0 for every job, live, no restart needed (observed via xce_test REPL joblist during an HA soak). run_time (finish_time - start_time) is consequently also wrong for every finished job.", + "file": "src/controller/job.c, src/controller/persist.c", + "root_cause": "dispatch_a_job_() (job.c:1686, scheduler-dispatch-commit task 3.1) synchronously sets j->job.state = JOB_STAT_RUN at DISPATCH time, before the worker ever reports back -- this is a deliberate, already-made semantic change: the controller decides RUN at dispatch, it no longer waits for a worker ack. When the worker's LATER on_job_start()/WAL_JOB_START fact commits and apply_committed_entry()'s live apply pump (persist.c, shared WAL_JOB_START/FINISH/STOP/RESUME/RUSAGE/CKPT/PREASON/DISPATCH case group starting ~persist.c:4430) processes it, apply_job_update_transition(j, JOB_STAT_RUN) (job.c:2779) sees job->job.state already == JOB_STAT_RUN (set by dispatch, moments/seconds earlier) and returns JOB_TRANSITION_NOOP_DUPLICATE (job.c:2795-2799), never JOB_TRANSITION_APPLIED. The wire-carried start_time/pidinfo decode/adopt block bug-1687 added (persist.c ~4602-4637) is gated on `result == JOB_TRANSITION_APPLIED` (persist.c:4594), so for WAL_JOB_START it can now NEVER run, for any job -- start_time and pidinfo (pids/pgids/exdata) both silently stay at their zero-initialized defaults forever. This is the exact same class of bug already fixed for WAL_JOB_RUSAGE/WAL_JOB_CKPT/WAL_JOB_PREASON in this identical function (their own comments describe it verbatim: 'gating this adoption on result==JOB_TRANSITION_APPLIED ... would make it dead code ... decode/adopt unconditionally') -- WAL_JOB_START was never given the same treatment because bug-1687 (which added the start_time/pidinfo wire fields) predates/was unaware of the dispatch-time RUN semantic collision. bug-1679's own comment (job.c:1709-1719) already independently documented and worked around the SAME root collision for a different symptom (the apiserver update-notification hook silently not firing on this same NOOP_DUPLICATE path) -- the two symptoms were never connected as the same root cause until now.", + "fix": "PENDING -- dispatching a dedicated fix, scope confirmed with the user (start_time is now dispatch-owned, not worker-ack-owned, matching the already-changed RUN semantic): (1) job.c dispatch_a_job_() stamps j->job.start_time = time(NULL) synchronously alongside j->job.state = JOB_STAT_RUN and j->job.allocs (job.c:1686 area). (2) persist_submit_job_dispatch_fact()/WAL_JOB_DISPATCH payload (persist.c:7664) extended to carry start_time as a new fixed uint64_t field, using a NEW _pad flag bit (wal_jobstate_t._pad, mirroring the existing WAL_JOB_FAIL_STAGE_FLAG/WAL_JOB_UPDATE_POSTDONE_MARK precedent in wal_types.h) as the backward-compat discriminator -- NOT a length heuristic, since JobAlloc's own variable length makes a length-based old-vs-new test ambiguous. (3) Both apply seams' (apply_committed_entry AND apply_wal_entry) WAL_JOB_DISPATCH cases decode/adopt the new start_time field when the flag is set. (4) WAL_JOB_START's apply-side handling (both seams) stops touching job.start_time entirely (dispatch owns it now) but makes its pidinfo decode/adopt UNCONDITIONAL (not gated on result==APPLIED) since state is now always-already-RUN by the time this fact applies -- mirrors the RUSAGE/CKPT/PREASON unconditional-adopt pattern exactly. Pre-fix WAL_JOB_DISPATCH/WAL_JOB_START entries (written before this fix ships) fall back to existing legacy behavior for start_time (an inherent, accepted one-time migration-boundary gap, consistent with every other WAL field-parity fix in this campaign).", + "tags": [ + "controller", + "job-lifecycle", + "wal-dispatch", + "wal-job-start", + "start-time", + "pidinfo", + "field-parity", + "apply-committed-entry", + "transition-noop-collision", + "found-live-no-restart", + "bug-1679-adjacent", + "bug-1687-adjacent", + "bug-1678-adjacent", + "critical", + "unfixed" + ], + "related_bugs": [ + "bug-1679", + "bug-1687", + "bug-1678", + "bug-1690", + "bug-1691", + "bug-1692" + ], + "occurrences": 1, + "last_seen": "2026-08-25T20:22:00Z" } ] }