From 54fd4a4ab0b6b5cff78f00ba555e22df7692e76b Mon Sep 17 00:00:00 2001 From: arcattack Date: Wed, 22 Jul 2026 20:10:38 -0500 Subject: [PATCH] Timestamps for the launch-chain logs (operator request) Every relay/console print now carries a wall-clock prefix (_StampedOut stdout wrapper; the GUI monitor regexes use search() so the prefix is transparent), and the pod's READY/pend lines carry wall time + tick -- post-mortems measure delays instead of guessing (the 3m40s load reconstruction needed heartbeat-counting archaeology). Co-Authored-By: Claude Opus 4.8 (1M context) --- engine/MUNGA_L4/L4APP.cpp | 6 ++++-- engine/MUNGA_L4/L4NET.CPP | 10 ++++++++-- tools/btconsole.py | 29 +++++++++++++++++++++++++++++ 3 files changed, 41 insertions(+), 4 deletions(-) diff --git a/engine/MUNGA_L4/L4APP.cpp b/engine/MUNGA_L4/L4APP.cpp index 615697d..f9fdebe 100644 --- a/engine/MUNGA_L4/L4APP.cpp +++ b/engine/MUNGA_L4/L4APP.cpp @@ -577,7 +577,8 @@ int BTTakePendingRunMissions(void) gBTRunMissionPendCount = 0; if (pended > 0) DEBUG_STREAM << "[launch] load complete -- firing " << pended - << " pended RunMission(s)" << std::endl << std::flush; + << " pended RunMission(s) t=" << GetTickCount() + << std::endl << std::flush; return pended; } @@ -645,7 +646,8 @@ void DEBUG_STREAM << "[launch] RunMission arrived in state " << (int)GetApplicationState() << " (still loading) -- pended until the load completes (" - << gBTRunMissionPendCount << ")" << std::endl << std::flush; + << gBTRunMissionPendCount << ") t=" << GetTickCount() + << std::endl << std::flush; return; } diff --git a/engine/MUNGA_L4/L4NET.CPP b/engine/MUNGA_L4/L4NET.CPP index 7fed3a3..223496d 100644 --- a/engine/MUNGA_L4/L4NET.CPP +++ b/engine/MUNGA_L4/L4NET.CPP @@ -636,8 +636,14 @@ void BTRelayNotifyReady(void) break; Sleep(10); } - DEBUG_STREAM << "[launch] READY " << (done == want ? "sent" : "send FAILED") - << " to the relay" << std::endl << std::flush; + { + SYSTEMTIME lt; + GetLocalTime(<); + DEBUG_STREAM << "[launch] READY " << (done == want ? "sent" : "send FAILED") + << " to the relay at " << (int)lt.wHour << ":" << (int)lt.wMinute + << ":" << (int)lt.wSecond << " t=" << GetTickCount() + << std::endl << std::flush; + } } void BTRelayUploadMatchLog(void) diff --git a/tools/btconsole.py b/tools/btconsole.py index 881cb37..f09bdcf 100644 --- a/tools/btconsole.py +++ b/tools/btconsole.py @@ -1130,7 +1130,36 @@ def relay_main(argv): return 0 +class _StampedOut: + """Line-timestamping stdout wrapper: every log line gets a wall-clock + prefix so post-mortems can measure delays instead of guessing (operator + request 2026-07-22). The GUI's monitor regexes all use .search(), so + the prefix is transparent to them.""" + + def __init__(self, inner): + self._inner = inner + self._at_line_start = True + + def write(self, text): + out = [] + for ch in text: + if self._at_line_start and ch != "\n": + out.append(time.strftime("%H:%M:%S ")) + self._at_line_start = False + out.append(ch) + if ch == "\n": + self._at_line_start = True + self._inner.write("".join(out)) + + def flush(self): + self._inner.flush() + + def __getattr__(self, name): + return getattr(self._inner, name) + + def main(): + sys.stdout = _StampedOut(sys.stdout) if len(sys.argv) >= 2 and sys.argv[1] == "--relay": return relay_main(sys.argv[2:]) if len(sys.argv) < 3: