fix(logs): parse the update/handoff logs' ISO-8601 stamps; cover them in the LOG_FILES stamp contract

- _TS_RE now accepts the T-separated stamps update.log and
  desktop-update-handoff.log actually write (posix.sh date +%Y-%m-%dT%H:%M:%S%z,
  windows.ps1 yyyy-MM-ddTHH:mm:ssK, the update banner), so --since filtering
  works for hermes logs update/handoff instead of silently dropping everything.
- test_logs' LOG_FILES stamp contract gains real writer samples for update/handoff.
- Replace the PR's source-shape (inspect.getsource) upload tests with behavioral
  ones (monkeypatched uploader, --local capture); the upload/--local loops stay
  data-driven over bundle.items() as on main.
This commit is contained in:
Brooklyn Nicholson
2026-09-29 16:56:17 -05:00
committed by brooklyn!
Unverified
parent 60f9d2abb1
commit 3ec91de490
2 changed files with 36 additions and 4 deletions
+6 -4
View File
@@ -53,8 +53,10 @@ LOG_FILES = {
"mcp": "mcp-stderr.log",
}
# "2026-04-05 22:35:00[,123]" at the start of a line.
_TS_RE = re.compile(r"^(\d{4}-\d{2}-\d{2}\s+\d{2}:\d{2}:\d{2})")
# "2026-04-05 22:35:00[,123]" at the start of a line; update.log /
# desktop-update-handoff.log stamp with the shell's ISO-8601 "T" shape
# ("2026-09-29T21:36:18+08:00", "=== hermes update started 2026-09-29T21:36:18 ===").
_TS_RE = re.compile(r"(\d{4}-\d{2}-\d{2}[T ]\d{2}:\d{2}:\d{2})")
_LEVEL_RE = re.compile(r"\s(DEBUG|INFO|WARNING|ERROR|CRITICAL)\s")
# Logger name: the token before ":" after the level and optional "[session]" tag,
# e.g. "INFO gateway.run:" or "INFO [sess_abc] tools.terminal_tool:".
@@ -72,11 +74,11 @@ def _parse_since(since_str: str) -> Optional[datetime]:
def _parse_line_timestamp(line: str) -> Optional[datetime]:
m = _TS_RE.match(line)
m = _TS_RE.search(line)
if not m:
return None
try:
return datetime.strptime(m.group(1), "%Y-%m-%d %H:%M:%S")
return datetime.strptime(m.group(1).replace("T", " "), "%Y-%m-%d %H:%M:%S")
except ValueError:
return None
+30
View File
@@ -38,6 +38,15 @@ class TestParseLineTimestamp:
ts = _parse_line_timestamp("2026-04-11 10:23:45 INFO gateway.run: msg")
assert ts == datetime(2026, 4, 11, 10, 23, 45)
def test_iso_t_separated_update_and_handoff_stamps(self):
# posix.sh: date +%Y-%m-%dT%H:%M:%S%z; windows.ps1: yyyy-MM-ddTHH:mm:ssK
assert _parse_line_timestamp("2026-09-29T21:36:18+08:00 update| step done") == datetime(
2026, 9, 29, 21, 36, 18
)
assert _parse_line_timestamp("2026-09-29T21:36:18Z step stalled") == datetime(
2026, 9, 29, 21, 36, 18
)
class TestExtractLevel:
def test_info(self):
assert _extract_level("2026-01-01 00:00:00 INFO gateway.run: msg") == "INFO"
@@ -177,6 +186,24 @@ def _mcp_output_line() -> str:
return log.getvalue()
def _update_log_line() -> str:
"""The update.log run banner hermes_cli.main_dashboard writes on every update."""
import datetime as dt
return f"\n=== hermes update started {dt.datetime.now().isoformat(timespec='seconds')} ===\n".lstrip()
def _handoff_log_line() -> str:
"""A desktop-update-handoff.log line from scripts/desktop-update/posix.sh's log()."""
import subprocess
line = subprocess.run(
["bash", "-c", 'log() { echo "$(date +%Y-%m-%dT%H:%M:%S%z) $1"; }; log "update| → Checking if desktop app needs rebuilding..."'],
capture_output=True, text=True, check=True,
).stdout
return line.rstrip("\n")
def _log_file_samples() -> dict:
"""One line per LOG_FILES entry, produced by that file's real writer where Python can run it."""
return {
@@ -187,6 +214,9 @@ def _log_file_samples() -> dict:
# Written by TypeScript; apps/desktop/electron/desktop-log-line.test.ts pins the same shape.
"desktop": "2026-09-28 13:18:46,062 [hermes] [boot] ready",
"mcp": _mcp_output_line(),
# update.log mirrors raw update output; handoff lines carry the shim's ISO-8601 stamp.
"update": _update_log_line(),
"handoff": _handoff_log_line(),
}