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.
This commit is contained in:
@@ -65,11 +65,15 @@ public class RealtimeSession
|
|||||||
try
|
try
|
||||||
{
|
{
|
||||||
var enabled = _registry.EnabledFor(_cfg.EnabledTools).ToList();
|
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);
|
await _upstream.SendJsonAsync(RealtimeEvents.SessionUpdate(_cfg, enabled), ct);
|
||||||
|
|
||||||
var ack = await WaitForUpstreamTypeAsync("session.updated", ct);
|
var ack = await WaitForUpstreamTypeAsync("session.updated", ct);
|
||||||
if (ack is null)
|
if (ack is null)
|
||||||
{
|
{
|
||||||
|
_logger.LogWarning("upstream closed before session.updated");
|
||||||
_endReason = EndReason.Error;
|
_endReason = EndReason.Error;
|
||||||
return;
|
return;
|
||||||
}
|
}
|
||||||
@@ -274,7 +278,25 @@ public class RealtimeSession
|
|||||||
{
|
{
|
||||||
var evt = await _upstream.ReceiveJsonAsync(ct);
|
var evt = await _upstream.ReceiveJsonAsync(ct);
|
||||||
if (evt is null) return null;
|
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;
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -43,11 +43,28 @@ def _build_bridge_thread(
|
|||||||
stop_event: threading.Event,
|
stop_event: threading.Event,
|
||||||
) -> threading.Thread:
|
) -> threading.Thread:
|
||||||
def run():
|
def run():
|
||||||
|
frame_counter = 0
|
||||||
|
recent_rms_max = 0.0
|
||||||
while not stop_event.is_set():
|
while not stop_event.is_set():
|
||||||
try:
|
try:
|
||||||
pcm16_bytes = mic_queue.get(timeout=0.25)
|
pcm16_bytes = mic_queue.get(timeout=0.25)
|
||||||
except queue.Empty:
|
except queue.Empty:
|
||||||
continue
|
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:
|
if sm.wakeword_enabled:
|
||||||
frame = np.frombuffer(pcm16_bytes, dtype=np.int16)
|
frame = np.frombuffer(pcm16_bytes, dtype=np.int16)
|
||||||
if frame.size != FRAME_SAMPLES:
|
if frame.size != FRAME_SAMPLES:
|
||||||
|
|||||||
+6
-1
@@ -39,9 +39,14 @@ class WakewordDetector:
|
|||||||
def predict(self, frame_16k_int16: np.ndarray) -> bool:
|
def predict(self, frame_16k_int16: np.ndarray) -> bool:
|
||||||
scores = self._model.predict(frame_16k_int16)
|
scores = self._model.predict(frame_16k_int16)
|
||||||
score = float(scores.get(WAKEWORD, 0.0))
|
score = float(scores.get(WAKEWORD, 0.0))
|
||||||
|
rms = float(np.sqrt(np.mean(frame_16k_int16.astype(np.float32) ** 2)))
|
||||||
now = time.monotonic()
|
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:
|
if score >= self._threshold and (now - self._last_fired) >= self._cooldown_s:
|
||||||
self._last_fired = now
|
self._last_fired = now
|
||||||
_log.info("wakeword fired score=%.3f", score)
|
_log.info("wakeword fired score=%.3f rms=%.0f", score, rms)
|
||||||
return True
|
return True
|
||||||
return False
|
return False
|
||||||
|
|||||||
Reference in New Issue
Block a user