consolidation's first daily attempt races the 02:00 Hobart nightly brain recycle

[adrianwedd]

Summary

Memory consolidation (src/pxh/memory.py:consolidate, dispatched via claude_session.run_claude_session("consolidate", ...) → _run_via_brain, resident spark-brain session, 180s timeout) opens its daily window at 02:00–06:00 Hobart (mind.py:3579). px-brain's supervisor also recycles context nightly at 02:00 Hobart (per CLAUDE.md's brain.py section: "recycles context on turn count + nightly at 02:00 Hobart — always at an idle moment, since a /clear between nudge and reply loses the request").

Consolidation's earliest possible attempt lands right at (or seconds after) 02:00, so it structurally races the recycle: if px-mind's tick happens to fire while the recycle is mid-flight, the request is injected right as the session is being cleared, and gets no reply within the 180s deadline.

Evidence — today, 2026-08-23

logs/tool-brain.log:

{"ts": "2026-08-22T16:03:56Z", "event": "brain_timeout", "kind": "consolidate", "session": "spark-brain", "timeout_s": 180, "validating_wait_s": 0.01, "lock_wait_s": 0.0, "exec_s": 180.11, "turns_since_reset": 54, "consecutive_slow_before": 0}

(16:03:56Z = 02:03:56 Hobart — 3-4 minutes after the scheduled recycle.) exec_s is essentially exactly the 180s budget — the brain never answered at all, not a slow-but-eventual reply.

logs/px-mind.log:

2026-08-23T02:03:56+10:00 ⚡ consolidation: failed — claude exit 1
2026-08-23T02:04:59+10:00 ⚡ consolidation: failed — consolidate quota reached (1/1)

So today's only real consolidation attempt failed to this collision, and the daily 1-attempt quota (claude_session.py's per-kind daily cap) was then exhausted by the same tick's retry, leaving zero further attempts for the day. state/consolidation_meta.json confirms: {"last_date": "2026-08-23", "attempts": 2, "done": false}.

Prior days show the same pattern isn't universal — it depends on exact tick timing relative to the recycle:

{"ts": "2026-08-20T16:00:31Z", "event": "brain_reply", "kind": "consolidate", ...}   # landed clean
{"ts": "2026-08-21T16:00:32Z", "event": "brain_unavailable", "kind": "consolidate", "reason": "session not validated", "state": "no_marker"}   # different failure mode, also recycle-adjacent
{"ts": "2026-08-22T16:03:56Z", "event": "brain_timeout", ...}   # today's collision

Three days sampled, three different outcomes, all within minutes of 02:00 Hobart — consistent with a scheduling race rather than a stable failure.

Not related to #275/#276

This is independent of the M5 circuit-breaker bug fixed in #275 — consolidation never touches M5 at all; it's routed straight to the resident spark-brain session via _brain_kinds(). Confirmed via python tools/check_resident_claude.py --list (clean, no cold-start paths) and by reading _run_via_brain's call path directly.

Suggested direction (not implemented here — filing per the goal's "fix narrow independent defects if obvious; otherwise issue them", and this needs recycle-scheduling context I don't have full confidence in)

Either:

• offset consolidation's window start a few minutes past 02:00 (e.g. 02:10) so it never lands in the recycle's typical window, or
• have the supervisor's recycle logic explicitly defer if a consolidation tick is imminent (mirroring how it already defers voice_turn mid-turn), or
• have px-mind's consolidation tick check brain.session_state() for validating before sending and back off, the same bounded-wait pattern brain: voice_turn instantly refused during recycle/handshake window instead of a bounded wait-and-recheck #273 added for voice_turn.

Blog, for comparison

px-blog is healthy and unaffected — state/health/px-blog.json shows 0 consecutive failures, last success today at 12:27 Hobart (well outside the 02:00 window). Its own schedule doesn't collide with the recycle.

[adrianwedd]

Cross-link: the 02:00 collision was independently re-observed in the 2026-08-26 log sweep (#304) — attempt 1 dies instantly with brain_unavailable every night and the 40-minute retry absorbs it (claude_sessions.jsonl:642-643). Not re-filed; this issue has the fuller evidence and remains the single home for it.

Still live on master 5b9070de: memory.CONSOLIDATION_WINDOW = (2, 6) and brain_daemon.NIGHTLY_RECYCLE_HOUR = 2 (env PX_BRAIN_RECYCLE_HOUR) are the same hour, so the race is structural rather than incidental. #294 moved consolidation onto its own background worker and #291 spaced the two attempts, but neither moved the window off the recycle — the collision this issue describes is untouched by both.

Cheapest correct fix of the three you listed is still the offset (CONSOLIDATION_WINDOW = (2, 6) → a start a few minutes past the hour is not expressible with an integer-hour constant, so this likely wants a minutes-resolution window start rather than a bumped hour — bumping to 3 would work but wastes an hour of the window).