Add temporary diagnostics for LED flicker investigation

Logs (WARNING level) when: multiple heartbeats arrive in one serial read
batch, a heartbeat gap exceeds 0.5s, or reapply_app_volumes takes >0.15s.
Suspected cause: synchronous playerctl/pulsectl calls in the reapply path
occasionally stalling the main loop long enough for backed-up heartbeats
to flush in a burst, each triggering an LED resend. To be removed once
confirmed/fixed.
main
Chris Nutter 2026-08-13 18:43:48 -07:00
parent 743c504918
commit 77f795903e
1 changed files with 21 additions and 0 deletions

View File

@ -421,11 +421,20 @@ def main() -> None:
send_leds(ser, initial_colors) send_leds(ser, initial_colors)
last_led_colors[:] = initial_colors last_led_colors[:] = initial_colors
heartbeat_count = 0
last_heartbeat_ts = 0.0
while True: while True:
data = ser.read(64) data = ser.read(64)
if data: if data:
buf.extend(data) buf.extend(data)
messages, buf = parse_messages(buf) messages, buf = parse_messages(buf)
hb_in_batch = sum(1 for m in messages if m["type"] == "heartbeat")
if hb_in_batch > 1:
log.warning(
"DIAG: %d heartbeats in one read batch (backlog flush)",
hb_in_batch,
)
for msg in messages: for msg in messages:
if msg["type"] == "knob": if msg["type"] == "knob":
handle_knob( handle_knob(
@ -439,6 +448,14 @@ def main() -> None:
msg["id"], msg["action"], config, pulse, active_window msg["id"], msg["action"], config, pulse, active_window
) )
elif msg["type"] == "heartbeat": elif msg["type"] == "heartbeat":
now_hb = time.monotonic()
heartbeat_count += 1
if last_heartbeat_ts and (now_hb - last_heartbeat_ts) > 0.5:
log.warning(
"DIAG: heartbeat gap %.2fs before heartbeat #%d",
now_hb - last_heartbeat_ts, heartbeat_count,
)
last_heartbeat_ts = now_hb
new_colors = all_led_colors(config, knob_norms) new_colors = all_led_colors(config, knob_norms)
send_leds(ser, new_colors) send_leds(ser, new_colors)
last_led_colors[:] = new_colors last_led_colors[:] = new_colors
@ -467,7 +484,11 @@ def main() -> None:
knob_quiet = now - last_knob_event[0] >= 0.2 knob_quiet = now - last_knob_event[0] >= 0.2
if (pulse.drain_events() or now - last_reapply >= 1.0) and knob_quiet: if (pulse.drain_events() or now - last_reapply >= 1.0) and knob_quiet:
last_reapply = now last_reapply = now
_t0 = time.monotonic()
reapply_app_volumes(config, pulse, knob_norms) reapply_app_volumes(config, pulse, knob_norms)
_elapsed = time.monotonic() - _t0
if _elapsed > 0.15:
log.warning("DIAG: reapply_app_volumes took %.3fs", _elapsed)
except serial.SerialException as exc: except serial.SerialException as exc:
log.warning("Serial error: %s — retrying in 3 s", exc) log.warning("Serial error: %s — retrying in 3 s", exc)