[FIX] The unwrapped-session detector compared two different clocks

The wake digest's `PREVIOUS SESSION DID NOT WRAP` alarm fired falsely at three
consecutive wakes and was overridden by hand at two of them. It was scoped as a
two-valued-detector problem. Diagnosing the class first found four defects, and
the scoped one was not the cause:

1. TIME BASE (the cause). Transcript timestamps are UTC (`...Z`); the code
   dropped the suffix and called `time.mktime`, which reads a struct_time as
   LOCAL, then compared the result against `os.path.getmtime`, a true epoch.
   Measured: +7201 s skew against a 900 s tolerance. Because the skew exceeds
   the tolerance, a wrap written at the end of a session could NEVER land inside
   the window — the alarm was systematic, not intermittent.
2. SELECTION. "Newest transcript quiet for >60 s" excluded the previous session
   at exactly the moment it mattered: on 2026-08-17 it had ended 12 s before the
   wake, was skipped, and the session from four days earlier was reported
   instead. The defect is time-dependent and disappears ~60 s later, which is
   why re-running the digest afterwards showed nothing wrong.
3. EVIDENCE. Wrap records were dated by mtime, which any later edit moves — the
   08-14 record read 08-17 because a CODA was appended to it. Now dated by git
   add-time, which cannot move once committed; mtime is a labelled fallback.
4. ARITY. `verdict is None` (could not assess) was folded into silence with
   "wrapped fine". Now four outcomes, per REVIEWED-104: wrapped · unwrapped ·
   unassessable-subject (environment) · unassessable-check (defect).

Acceptance is old-vs-new on the real case, not a unit pass. At the reconstructed
wake instant the old code selects the wrong transcript AND returns a false alarm
on the right one; the new code selects correctly and returns `wrapped`. Both
defects independently produced the alarm, so fixing only the arity — the scoped
task — would have shipped a fix that left it firing.

The selftest gains a control derived from the property rather than from the
check: a transcript's last inner timestamp and its file mtime are two readings of
one moment, so their MEDIAN skew detects a systematic clock mismatch (1 s now,
~7200 s before). Max is printed too, because one transcript legitimately skews
31 h — the same mutable-mtime problem, on the transcript side.

The old real-substrate gate demanded both verdicts occur across live sessions
and PASSED while the detector was broken: it established that outcomes were
spread, never that any was correct. Demoted to a printed note with its limit
stated beside it. Filed as PENDING-142 ADDENDUM 1.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_013Y6t6qx7cpaCu5xGdD36u4
This commit is contained in:
David F Glidden
2026-08-17 14:57:48 +02:00
co-authored by Claude Opus 5
parent 77e5e2556c
commit b6e1b5e470
+249 -48
View File
@@ -16,7 +16,7 @@ if it cannot be computed it says so rather than emitting nothing.
Provenance: 2026-07-28, steward-authorized alongside the PENDING split and the Provenance: 2026-07-28, steward-authorized alongside the PENDING split and the
CLAUDE.md doctrine annotation. Sibling of governance-drift-check.py. CLAUDE.md doctrine annotation. Sibling of governance-drift-check.py.
""" """
import os, re, subprocess, sys, time import calendar, os, re, subprocess, sys, time
HOME = os.path.expanduser("~") HOME = os.path.expanduser("~")
D = os.path.join(HOME, "dotfiles") D = os.path.join(HOME, "dotfiles")
@@ -138,6 +138,41 @@ def wrap_records():
if f.startswith("session-") and not f.startswith("session-ledger-")] if f.startswith("session-") and not f.startswith("session-ledger-")]
def parse_iso(s):
"""ISO-8601 -> true epoch, honouring the zone suffix.
THE 2026-08-17 BUG, and it is the whole reason the alarm below misfired.
Transcript timestamps are UTC (`2026-08-14T07:29:36.852Z`). The previous
implementation dropped the `Z` and called `time.mktime`, which reads a
struct_time as LOCAL — putting the span in a different time base from
`os.path.getmtime()`, which returns a true epoch. Measured that day: a
+2 h (CEST) skew against a 15 min tolerance. Since the skew exceeds the
tolerance, a wrap written at the end of a session could NEVER land inside
the window — so `PREVIOUS SESSION DID NOT WRAP` was systematic, not
occasional. It had been overridden by hand at two consecutive wakes.
Naive strings (no zone) are still read as local: that is what they mean.
"""
m = re.match(r"(\d{4}-\d{2}-\d{2})[T ](\d{2}:\d{2}:\d{2})", s or "")
if not m:
return None
try:
st = time.strptime(f"{m.group(1)}T{m.group(2)}", "%Y-%m-%dT%H:%M:%S")
except (ValueError, OverflowError):
return None
z = re.match(r"(?:\.\d+)?(Z|[+-]\d{2}:?\d{2})", s[m.end():])
if not z:
try:
return time.mktime(st)
except (ValueError, OverflowError):
return None
tag = z.group(1)
if tag == "Z":
return calendar.timegm(st)
sign = 1 if tag[0] == "+" else -1
return calendar.timegm(st) - sign * (int(tag[1:3]) * 3600 + int(tag[-2:]) * 60)
def transcript_span(path): def transcript_span(path):
""" """
A session's true span, from the timestamps INSIDE the transcript — never mtime. A session's true span, from the timestamps INSIDE the transcript — never mtime.
@@ -148,28 +183,115 @@ def transcript_span(path):
try: try:
with open(path, errors="ignore") as f: with open(path, errors="ignore") as f:
for line in f: for line in f:
m = re.search(r'"timestamp"\s*:\s*"([0-9T:\-]{19})', line) m = re.search(r'"timestamp"\s*:\s*"([^"]{19,40})"', line)
if m: if m:
e = parse_iso(m.group(1))
if e is None:
continue
if first is None: if first is None:
first = m.group(1) first = e
last = m.group(1) last = e
except OSError: except OSError:
return None, None return None, None
return first, last
def epoch(s):
try:
return time.mktime(time.strptime(s, "%Y-%m-%dT%H:%M:%S"))
except (ValueError, OverflowError):
return None
return epoch(first), epoch(last)
def wrap_inside(span, wrap_mtimes, lead=300, lag=900): def wrap_events():
"""Did a wrap record get written inside this session's span?""" """-> [(path, epoch, source)] — when each wrap record CAME INTO EXISTENCE.
Not mtime. A wrap record edited later — a CODA appended, a correction made —
carries the edit's mtime, so an ordinary and correct act destroys the evidence
that the wrap happened inside its own session. Measured 2026-08-17: the 08-14
record's mtime read 08-17 for exactly that reason. Git's add-time cannot move
once committed; mtime is the fallback for a not-yet-committed record and is
labelled so the caller can tell the two apart.
"""
added, at = {}, None
out = sh(["git", "-C", D, "log", "--diff-filter=A", "--format=%at",
"--name-only", "--", os.path.relpath(os.path.realpath(MEM), D)])
for line in (out or "").split("\n"):
line = line.strip()
if re.fullmatch(r"\d{9,11}", line):
at = int(line)
elif line and at is not None:
base = line.rsplit("/", 1)[-1]
if base not in added or at < added[base]:
added[base] = at # earliest add wins
ev = []
for p in wrap_records():
base = os.path.basename(p)
if base in added:
ev.append((p, added[base], "git"))
else:
try:
ev.append((p, os.path.getmtime(p), "mtime"))
except OSError:
pass
return ev
def previous_transcript(now, spans):
"""The session before this one, selected by SPAN — never by 'quiet for >60 s'.
The old rule excluded any transcript touched within 60 s as 'the current
session'. That is wrong at precisely the moment it matters: on 2026-08-17 the
previous session had ended 12 s before the wake, was excluded as too recent,
and the digest reported the session from four days earlier instead — 'ended
~Aug 13 21:36'. The defect is time-dependent and disappears ~60 s later, which
is why re-running the digest afterwards showed nothing wrong.
THIS session's transcript is the one most recently STARTED that is still being
appended. Keying on start alone breaks once the current session has run a
while; keying on end alone cannot tell a live session from one that ended
seconds ago. Both together identify it, and at most one is ever excluded — so
a just-ended prior session can no longer be skipped.
Residual, stated rather than hidden: if the current session's transcript holds
no parseable timestamp yet, the newest START is the previous session, and if it
also ended moments ago it is excluded and the one before it is reported. That
is the old failure in a much smaller window, and it is why the caller treats a
'no wrap' result as advisory rather than as proof.
"""
dated = [r for r in spans if r[1] is not None and r[2] is not None]
if not dated:
return None
live = max(dated, key=lambda r: r[1]) # newest start …
rest = [r for r in dated if r is not live] if live[2] >= now - 120 else dated
return max(rest, key=lambda r: r[2]) if rest else None # … and still growing
def wrap_verdict(span, events, lead=300, lag=10800):
"""-> (state, detail). FOUR outcomes, because 'I could not tell' is two things.
REVIEWED-104: a check whose subject can be absent may not be two-valued, and
the third outcome is itself two kinds — subject absent (environment, must not
block) versus check broken (defect). The previous version folded both into
silence via `verdict is None`, so 'I could not look' read as 'it wrapped'.
"""
a, b = span a, b = span
if a is None or b is None: if a is None or b is None:
return None # unreadable — not the same as 'no wrap' return "unassessable-subject", ("the previous session's transcript carries "
return any(a - lead <= m <= b + lag for m in wrap_mtimes) "no readable timestamps")
if not events:
return "unassessable-check", "no wrap records could be enumerated"
if any(a - lead <= e <= b + lag for _p, e, _s in events):
return "wrapped", ""
# No event in the window. Before alarming, ask whether some wrap record NAMES a
# day inside this span: commit lag can push real evidence past the window, and
# an alarm that cannot be substantiated is worse than an honest non-answer.
days, t, guard = set(), int(a), 0
while t <= int(b) + 86400 and guard < 60:
days.add(time.strftime("%Y-%m-%d", time.localtime(t)))
t += 86400
guard += 1
named = [os.path.basename(p) for p, _e, _s in events
if any(d in os.path.basename(p) for d in days)]
if named:
return ("unassessable-check",
f"no wrap event inside the span, but {named[0]} names a day within "
f"it — a real wrap with lagged evidence cannot be told apart from "
f"another session's record")
return "unwrapped", ""
def sec_unwrapped(): def sec_unwrapped():
@@ -182,30 +304,44 @@ def sec_unwrapped():
detected this via a MemPalace Stop hook; that hook is retired, but the detected this via a MemPalace Stop hook; that hook is retired, but the
failure it named is live. The transcripts are the only witness that a failure it named is live. The transcripts are the only witness that a
session ran at all. session ran at all.
Rebuilt 2026-08-17, after the alarm fired falsely at three consecutive wakes
and was overridden by hand at two of them. FOUR defects were found, and only
one was the one the work had been scoped to:
1. a UTC/local time-base mismatch (see `parse_iso`) — THE CAUSE, and large
enough that an end-of-session wrap could never be seen;
2. a selection rule that skipped a session which had just ended;
3. wrap evidence read from mutable mtimes;
4. a two-valued verdict over an assessment that can fail.
Fixing only (4), as scoped, would have left the false alarms firing.
""" """
proj = os.path.dirname(os.path.join(HOME, ".claude", "projects", proj = os.path.dirname(os.path.join(HOME, ".claude", "projects",
"-Users-davidglidden", "memory")) "-Users-davidglidden", "memory"))
try: try:
tx = [os.path.join(proj, f) for f in os.listdir(proj) if f.endswith(".jsonl")] tx = [os.path.join(proj, f) for f in os.listdir(proj) if f.endswith(".jsonl")]
except OSError: except OSError:
warn.append("session transcripts unreadable — wrap check did not run")
return None return None
now = time.time() if not tx:
# The current session's transcript is being appended right now; the previous
# session's is the newest one that has gone quiet.
prior = [p for p in tx if now - os.path.getmtime(p) > 60]
if not prior:
return None return None
last = max(prior, key=os.path.getmtime) prev = previous_transcript(time.time(), [(p,) + transcript_span(p) for p in tx])
verdict = wrap_inside(transcript_span(last), if prev is None:
[os.path.getmtime(w) for w in wrap_records()])
if verdict is None or verdict:
return None return None
ended = time.strftime("%b %d %H:%M", time.localtime(os.path.getmtime(last))) _path, a, b = prev
return (f"⚠ PREVIOUS SESSION DID NOT WRAP (ended ~{ended}). The thread and " state, detail = wrap_verdict((a, b), wrap_events())
f"question below are inherited from an OLDER session — treat them as " if state == "wrapped":
f"possibly stale, and expect no record of what that session did.\n" return None
f" Not established: whether that session did work worth keeping. The " ended = time.strftime("%b %d %H:%M", time.localtime(b))
f"transcript is on disk and can be read if the gap matters.") if state == "unwrapped":
return (f"⚠ PREVIOUS SESSION DID NOT WRAP (ended ~{ended}). The thread and "
f"question below are inherited from an OLDER session — treat them as "
f"possibly stale, and expect no record of what that session did.\n"
f" Not established: whether that session did work worth keeping. The "
f"transcript is on disk and can be read if the gap matters.")
return (f"◌ WRAP STATUS UNDETERMINED for the previous session (ended ~{ended}) — "
f"{detail}.\n"
f" This is neither an alarm nor a clean pass: the check could establish "
f"neither. Open the newest session record to see what it actually holds.")
def ruled_pendings(reviewed_text): def ruled_pendings(reviewed_text):
@@ -805,26 +941,91 @@ def selftest():
chk("is_homed FALSE for a symlink pointing OUTSIDE maps/", chk("is_homed FALSE for a symlink pointing OUTSIDE maps/",
not is_homed(os.path.join(HOME, ".claude"), MAPS_DIR)) not is_homed(os.path.join(HOME, ".claude"), MAPS_DIR))
print("\nunwrapped-session detector [PENDING-S2's obligation, our substrate]:") print("\nunwrapped-session detector [PENDING-S2's obligation, our substrate]:")
chk("wrap_inside TRUE when a wrap falls inside the span", # --- time base. The 2026-08-17 cause, and the control that was missing. ----
wrap_inside((1000.0, 2000.0), [1500.0])) _utc = calendar.timegm(time.strptime("2026-08-14T07:29:36", "%Y-%m-%dT%H:%M:%S"))
chk("wrap_inside TRUE for a wrap just after the last write [wraps land near the end]", chk("parse_iso reads a 'Z' timestamp as UTC [the 2026-08-17 cause]",
wrap_inside((1000.0, 2000.0), [2400.0])) parse_iso("2026-08-14T07:29:36.852Z") == _utc)
chk("wrap_inside FALSE when every wrap is outside [negative control]", _agrees = (parse_iso("2026-08-14T07:29:36.852Z")
not wrap_inside((1000.0, 2000.0), [500.0, 5000.0])) == time.mktime(time.strptime("2026-08-14T07:29:36", "%Y-%m-%dT%H:%M:%S")))
chk("wrap_inside returns None on an unreadable span [must NOT read as 'no wrap']", _utc_box = (time.altzone if time.daylight else time.timezone) == 0
wrap_inside((None, None), [1500.0]) is None) chk("parse_iso differs from the old mktime reading unless the box is on UTC"
# Discrimination on REAL sessions: the detector must return BOTH verdicts over " [negative control — proves the line above can fail]", _agrees == _utc_box)
# the actual transcript history. One verdict everywhere = it discriminates nothing. chk("parse_iso honours an explicit offset",
parse_iso("2026-08-14T09:29:36+02:00") == parse_iso("2026-08-14T07:29:36Z"))
chk("parse_iso returns None on junk [must not invent a span]",
parse_iso("not a timestamp") is None and parse_iso("") is None)
# THE END-TO-END FORM, derived from the property rather than from the check:
# a transcript's last inner timestamp and its file mtime are two readings of
# one moment. If they disagree by more than minutes, the detector is comparing
# two different clocks — which is exactly what it was doing (~7200 s skew).
_proj = os.path.dirname(MEM) _proj = os.path.dirname(MEM)
_tx = sorted((os.path.join(_proj, f) for f in os.listdir(_proj) _tx = sorted((os.path.join(_proj, f) for f in os.listdir(_proj)
if f.endswith(".jsonl")), key=os.path.getmtime)[-14:-1] if f.endswith(".jsonl")), key=os.path.getmtime)
_wm = [os.path.getmtime(w) for w in wrap_records()] # MEDIAN, not max, and the reason is itself a finding: a clock mismatch is
_v = [wrap_inside(transcript_span(p), _wm) for p in _tx] # SYSTEMATIC — it shifts every transcript by the same amount, so it moves the
chk(f"real sessions read as WRAPPED [{sum(1 for x in _v if x is True)} of {len(_v)}]", # median. A lone large skew is a different phenomenon: 2026-08-10's transcript
any(x is True for x in _v)) # was touched 31 h after its last line. That is the very mutable-mtime problem
chk(f"real sessions read as UNWRAPPED [{sum(1 for x in _v if x is False)} of {len(_v)}]" # `wrap_events` routes around, measured here on the transcript side. Max is
" — the negative instance; without one the detector is unproven", # printed so the outlier stays visible instead of being averaged away.
any(x is False for x in _v)) _skew = sorted(abs(os.path.getmtime(p) - transcript_span(p)[1])
for p in _tx[-8:] if transcript_span(p)[1] is not None)
_med = _skew[len(_skew) // 2] if _skew else -1
chk(f"transcript span END agrees with file mtime"
f" [median {_med:.0f}s, max {max(_skew) if _skew else -1:.0f}s;"
f" median was ~7200s before the fix]",
bool(_skew) and _med < 900)
# --- the four outcomes -----------------------------------------------------
_E = [("/w/session-2026-01-02-x.md", 1500.0, "git")]
chk("wrap_verdict WRAPPED when an event lands inside the span",
wrap_verdict((1000.0, 2000.0), _E)[0] == "wrapped")
chk("wrap_verdict WRAPPED for an event just after the last write [wraps land near the end]",
wrap_verdict((1000.0, 2000.0), [("/w/session-2026-01-02-x.md", 2400.0, "git")])[0]
== "wrapped")
chk("wrap_verdict UNWRAPPED when every event is outside [negative control]",
wrap_verdict((1000.0, 2000.0), [("/w/session-1999-01-01-a.md", 500.0, "git"),
("/w/session-1999-01-01-b.md", 5.0e8, "git")])[0]
== "unwrapped")
chk("wrap_verdict UNASSESSABLE-SUBJECT on an unreadable span [must NOT read as 'no wrap']",
wrap_verdict((None, None), _E)[0] == "unassessable-subject")
chk("wrap_verdict UNASSESSABLE-CHECK when no wrap record can be enumerated",
wrap_verdict((1000.0, 2000.0), [])[0] == "unassessable-check")
_t0 = time.time()
chk("wrap_verdict declines to alarm when a record NAMES a day inside the span"
" [commit lag must not become a false alarm]",
wrap_verdict((_t0, _t0 + 3600),
[(f"/w/session-{time.strftime('%Y-%m-%d', time.localtime(_t0))}-x.md",
_t0 + 10 * 86400, "git")])[0] == "unassessable-check")
# --- selection -------------------------------------------------------------
_now = 1_000_000.0
_spans = [("cur.jsonl", _now - 5, _now),
("prev.jsonl", _now - 86400, _now - 12),
("old.jsonl", _now - 400000, _now - 350000)]
chk("previous_transcript picks the session that ended 12 s ago [the 2026-08-17 miss]",
previous_transcript(_now, _spans)[0] == "prev.jsonl")
_mid = [("cur.jsonl", _now - 1380, _now), # running 23 min — a manual run
("prev.jsonl", _now - 86400, _now - 1400),
("old.jsonl", _now - 400000, _now - 350000)]
chk("previous_transcript excludes a LONG-running current session [manual mid-session run;"
" keying on start alone regressed here]",
previous_transcript(_now, _mid)[0] == "prev.jsonl")
chk("previous_transcript keeps a quiet newest-start transcript [negative control —"
" exclusion needs BOTH signals, not just newest start]",
previous_transcript(_now, _mid[1:])[0] == "prev.jsonl")
# --- real substrate --------------------------------------------------------
_ev = wrap_events()
_git = sum(1 for _p, _e, _s in _ev if _s == "git")
chk(f"wrap evidence is taken from git add-time, not mutable mtimes"
f" [{_git} of {len(_ev)} from git]", len(_ev) > 0 and _git > len(_ev) // 2)
_v = [wrap_verdict(transcript_span(p), _ev)[0] for p in _tx[-14:-1]]
chk(f"a real session reads as WRAPPED end-to-end [{_v.count('wrapped')} of {len(_v)}]",
"wrapped" in _v)
# ⚠ The old gate here demanded a real UNWRAPPED instance too, and PASSED on
# 2026-08-17 while the detector was systematically broken — it established that
# both verdicts OCCUR, never that either was CORRECT. Its subject was the
# spread of outcomes; the claim was their truth. Reported, not asserted.
print(f" [note] real-session outcome spread: "
+ ", ".join(f"{s}={_v.count(s)}" for s in sorted(set(_v)))
+ " — a spread is not a proof of correctness; the controls above are.")
print("\nlive substrate:") print("\nlive substrate:")
chk("PENDING.md readable", read(PENDING) is not None) chk("PENDING.md readable", read(PENDING) is not None)