From d01b78b22539ad42d16df5b020e16420330b7552 Mon Sep 17 00:00:00 2001
From: Assistant builder <meelstorm@gmail.com>
Date: Fri, 12 Jun 2026 06:28:58 +0000
Subject: [PATCH] Relay: log upstream events + forward error envelopes to
 device for diagnostics

Plan 3 smoke surfaced 'session_ended reason=error' on every wake with no
context. The relay now logs every upstream event type at INFO and forwards
any upstream 'error' event to the device as 'error code=upstream_<code>'
so it appears in the Pi's journal alongside the wake/session_ended pair.

Also extends the client's wakeword.predict with per-frame RMS + score
diagnostics and the bridge loop with a 5 s heartbeat for triage.
---
 backend/Realtime/RealtimeSession.cs | 24 +++++++++++++++++++++++-
 client/main.py                      | 17 +++++++++++++++++
 client/wakeword.py                  |  7 ++++++-
 3 files changed, 46 insertions(+), 2 deletions(-)

diff --git a/backend/Realtime/RealtimeSession.cs b/backend/Realtime/RealtimeSession.cs
index a1fca32..8ea67a7 100644
--- a/backend/Realtime/RealtimeSession.cs
+++ b/backend/Realtime/RealtimeSession.cs
@@ -65,11 +65,15 @@ public class RealtimeSession
         try
         {
             var enabled = _registry.EnabledFor(_cfg.EnabledTools).ToList();
+            _logger.LogInformation(
+                "relay opening session: model={Model} voice={Voice} tools=[{Tools}]",
+                _cfg.Model, _cfg.Voice, string.Join(",", enabled.Select(t => t.Name)));
             await _upstream.SendJsonAsync(RealtimeEvents.SessionUpdate(_cfg, enabled), ct);
 
             var ack = await WaitForUpstreamTypeAsync("session.updated", ct);
             if (ack is null)
             {
+                _logger.LogWarning("upstream closed before session.updated");
                 _endReason = EndReason.Error;
                 return;
             }
@@ -274,7 +278,25 @@ public class RealtimeSession
         {
             var evt = await _upstream.ReceiveJsonAsync(ct);
             if (evt is null) return null;
-            if ((string?)evt["type"] == type) return evt;
+            var evtType = (string?)evt["type"];
+            _logger.LogInformation("upstream evt={EvtType}", evtType);
+            if (evtType == "error")
+            {
+                var err = evt["error"] as JsonObject;
+                var code = (string?)err?["code"] ?? "unknown";
+                var msg = (string?)err?["message"] ?? evt.ToJsonString();
+                _logger.LogWarning("upstream error code={Code} message={Message}", code, msg);
+                await _output.WriteEnvelopeAsync(new JsonObject
+                {
+                    ["type"] = "error",
+                    ["code"] = "upstream_" + code,
+                    ["message"] = msg,
+                    ["fatal"] = false,
+                }, ct);
+                _endReason = EndReason.Error;
+                return null;
+            }
+            if (evtType == type) return evt;
         }
     }
 }
diff --git a/client/main.py b/client/main.py
index 951840d..ee451e2 100644
--- a/client/main.py
+++ b/client/main.py
@@ -43,11 +43,28 @@ def _build_bridge_thread(
     stop_event: threading.Event,
 ) -> threading.Thread:
     def run():
+        frame_counter = 0
+        recent_rms_max = 0.0
         while not stop_event.is_set():
             try:
                 pcm16_bytes = mic_queue.get(timeout=0.25)
             except queue.Empty:
                 continue
+            frame_counter += 1
+            raw = np.frombuffer(pcm16_bytes, dtype=np.int16)
+            rms = float(np.sqrt(np.mean(raw.astype(np.float32) ** 2)))
+            if rms > recent_rms_max:
+                recent_rms_max = rms
+            # Every ~5 s emit a heartbeat so we can see if the InputStream is
+            # actually producing frames and what state we're routing to.
+            if frame_counter % 62 == 0:
+                _log.info(
+                    "bridge frames=%d state=%s wake_en=%s up_en=%s qsize=%d rms_max_5s=%.0f",
+                    frame_counter, sm.state.name,
+                    sm.wakeword_enabled, sm.uplink_enabled, mic_queue.qsize(),
+                    recent_rms_max,
+                )
+                recent_rms_max = 0.0
             if sm.wakeword_enabled:
                 frame = np.frombuffer(pcm16_bytes, dtype=np.int16)
                 if frame.size != FRAME_SAMPLES:
diff --git a/client/wakeword.py b/client/wakeword.py
index 049b5b6..25f3be4 100644
--- a/client/wakeword.py
+++ b/client/wakeword.py
@@ -39,9 +39,14 @@ class WakewordDetector:
     def predict(self, frame_16k_int16: np.ndarray) -> bool:
         scores = self._model.predict(frame_16k_int16)
         score = float(scores.get(WAKEWORD, 0.0))
+        rms = float(np.sqrt(np.mean(frame_16k_int16.astype(np.float32) ** 2)))
         now = time.monotonic()
+        # Diagnostic: log any non-trivial score so we can see what's getting
+        # close to firing.
+        if score >= 0.1:
+            _log.info("score=%.3f rms=%.0f", score, rms)
         if score >= self._threshold and (now - self._last_fired) >= self._cooldown_s:
             self._last_fired = now
-            _log.info("wakeword fired score=%.3f", score)
+            _log.info("wakeword fired score=%.3f rms=%.0f", score, rms)
             return True
         return False