fix(cron): tag catch-up dispatches with scheduled vs actual time and lateness so late runs surface in UI - #99919
salch-cred wants to merge 4 commits into
Conversation
Covers the Android psutil installer helpers: - PsutilAndroidInstallError is a RuntimeError subclass - MARKER/REPLACEMENT contain expected substrings - _normalize_member_parts strips the tarball prefix - PSUTIL_URL points to a .tar.gz for psutil
…lateness (NousResearch#99879) Recurring jobs whose next_run_at is past the catch-up grace window were re-dispatched once immediately but with no provenance — the Routines UI/CLI showed the late run as an ordinary successful run. A 09:00 job that actually ran at 09:31 (or 11:27 after an overnight gateway crash) was indistinguishable from an on-time 09:00 run, and hours-late reminders were functionally missed without the user knowing. Fix: at the overdue-recurring branch in _get_due_jobs_locked (cron/jobs.py:4007), before falling through to due.append(job), tag the in-memory job with _dispatch_meta = { scheduled_at, dispatched_at, lateness_seconds, dispatch_kind: 'catch_up' }. The tag is transient (not persisted to jobs.json — it's on the deep-copied jobs entry, not raw_jobs) and flows through tick()'s due list so execution records and future UI work can display 'catch-up — scheduled 09:00, ran 09:31 (31m late)' instead of silently 'ok'. The log line now says 'late by 31s' explicitly. All 51 existing due/catch_up/grace tests pass; 2 new regression tests pin the tag on overdue dispatch and the absence on on-time dispatch. Fixes NousResearch#99879
|
Flagged by automated review on both this PR and NousResearch#99919: the file tests an unrelated module, was not part of this fix, and the duplicated addition would conflict for whichever PR merges second. Removing it keeps this diff scoped to the FIFO overflow rescue only.
Flagged by automated review on this PR and NousResearch#99912: the file tests an unrelated module and the duplicated addition would conflict for whichever PR merges second. Removing it keeps this diff scoped to the catch-up dispatch metadata tagging only.
|
Thanks — the persistence question was worth checking, and the answer is that the tag is transient by construction: _get_due_jobs_locked\ deep-copies at the top of the scan — \jobs = [_apply_skill_fields(j) for j in copy.deepcopy(raw_jobs)]\ (cron/jobs.py:3675). _dispatch_meta\ is set on entries in that deep-copied list, while \save_jobs\ persists only Stale test file: removed in b0ebd1e — same as the note on #99912, it was carried by mistake and would have conflicted for whichever PR merged second. |
|
Thanks @salch-cred — this was the right diagnosis and the right spot in
Closing as superseded — your PR correctly identified the missing provenance and the exact branch that needed it, it just landed second. #99879 stays open pending any remaining UI-surface work. |
|
Acknowledged — #100445's persisted last_dispatch stamp is strictly better than my transient in-memory tag: it survives the process boundary so hermes cron list/status can actually display the provenance, which mine couldn't. Thanks for the close note and the credit on the diagnosis. |
Problem (#99879)
A daily
0 9 * * *routine scheduled for 09:00 was observed running at 09:16–11:27 — up to 2.5h late. Gateway logs showed the previous gateway exited uncleanly and the overdue job was dispatched at restart. The Routines UI/CLI showed the late run as an ordinary "ok" run with no indication it was hours late. For reminders, that is functionally missed.Root cause (verified on main)
cron/jobs.py: _get_due_jobs_lockedhandles overdue recurring jobs correctly as a scheduler — it fast-forwardsnext_run_atand runs once now to avoid deferring indefinitely. But it did so without provenance: no scheduled vs actual time, no lateness, no kind tag. The due job fell through todue.append(job)as a plain job, and the execution record and Routines UI had no way to distinguish catch-up from on-time.Fix
Tag the in-memory job at the overdue branch with
_dispatch_metabefore dispatch:jobsentry, notraw_jobs— never persisted tojobs.json, never survives a restart on its owntick()'sduelist so execution records and future UI/CLI work can display "catch-up — scheduled 09:00, ran 09:31 (31m late)" instead of silently "ok"late by 1860sexplicitlyTests —
tests/cron/test_routine_catch_up_dispatch_meta.py(2, isolated via mocks)_dispatch_metapresent with scheduled/dispatched/lateness/kind_dispatch_metaAll 51 existing
due/catch_up/gracecron tests pass unchanged.Fixes #99879