Skip to content

#481 chore: add diagnostic logging to broadcast/drain pipeline#486

Closed
hoblin wants to merge 1 commit into
mainfrom
chore/481-debug-pending-message-broadcasts
Closed

#481 chore: add diagnostic logging to broadcast/drain pipeline#486
hoblin wants to merge 1 commit into
mainfrom
chore/481-debug-pending-message-broadcasts

Conversation

@hoblin

@hoblin hoblin commented Apr 30, 2026

Copy link
Copy Markdown
Owner

Summary

Investigative logging for #481 (TUI pending tool responses leak: some entries persist until restart). Adds a paired server + TUI logging stream so a leak round can be replayed post-hoc.

  • Server side — new BroadcastDiagnostics.logger (Melete/Mneme module-logger pattern) writes to log/broadcast.log in dev only:
    • PendingMessage#broadcast_created / #broadcast_removed — every emit, with PM id, message_type, source_name, tool_use_id, session_id, view_mode
    • MessageBroadcaster#emit — every Message broadcast, with id + tool_use_id + action
    • DrainJob#perform — when start_processing! refuses, log state + tool_round_complete? + mailbox counts
    • DrainJob#drain_mailbox — round membership (tool_response PM ids + tool_use_ids), promoted count
  • TUI side — new TUI::BroadcastLogger (PerformanceLogger flag-gated pattern), opt-in via --broadcast-debug, writes to log/tui_broadcast.log:
    • Every received WebSocket message logged with action, type, id, pending_message_id, tool_use_id
    • For pending_message_removed: logs whether MessageStore#remove_pending actually matched a stored entry (the silent-miss case is the leak's smoking gun)
  • TOML template gets a new [broadcast] log_path setting; existing users will need anima migrate to pick it up before passing --broadcast-debug.

Why this approach

Research ruled out the original "decorator raise eats the broadcast" framing — drain_mailbox runs each promote! in its own transaction, so a per-PM render failure can't take down siblings. Research also ruled out the comment's revised hypothesis that a from_melete_goal unknown-tool error breaks Session#tool_round_complete? — unknown-tool PMs have message_type: \"tool_response\" and the correct tool_use_id, so the round-completion query counts them correctly. The remaining failure modes (broadcast lost in transit, TUI subscription race on reconnect, remove_pending silent miss because the create broadcast was missed) all need the paired server-emit / TUI-receipt log to diagnose, which is what this PR delivers.

How to use

# Server (always on in dev)
tail -f log/broadcast.log

# TUI side (opt-in)
./exe/anima tui --host localhost:42135 --broadcast-debug
tail -f log/tui_broadcast.log

Reproduce a batch tool round (e.g. spawn multiple sub-agents in parallel), wait for the leak, then compare:

  • N PMs created → N broadcast_created server lines → N recv pending_message_created TUI lines?
  • N PMs destroyed → N broadcast_removed server lines → N recv pending_message_removed matched=true TUI lines?
  • N Messages created → N MessageBroadcaster ... broadcast server lines → matching recv action=create type=tool_response TUI lines?

Any mismatch identifies the leak point.

Test plan

Breaking changes

  • TUI users who already have ~/.anima/tui.toml will need to run anima migrate to pick up the new [broadcast] log_path setting before passing --broadcast-debug. Users who never pass the flag are unaffected (the setting is only read when the flag is on).

Closes part of #481 (the diagnostic-logging acceptance criterion). Root-cause identification + follow-up implementation issue are the remaining ACs and will be handled after the diagnostic logs let us reproduce.

Wires dev-only logging on every server emit (PendingMessage broadcast_created,
broadcast_removed, MessageBroadcaster#emit, DrainJob mailbox decisions) to
log/broadcast.log, and a parallel TUI-side logger (--broadcast-debug flag,
log/tui_broadcast.log) on every received WebSocket message. Pair the two
streams to count creates/removes/messages per batch round and identify any
per-PM mismatch, per the issue #481 investigation.

Server-side BroadcastDiagnostics follows the Melete/Mneme module logger
pattern — null logger outside development so call sites stay unconditional.
TUI-side BroadcastLogger follows the PerformanceLogger flag-gated pattern.
@hoblin

hoblin commented Apr 30, 2026

Copy link
Copy Markdown
Owner Author

Closing — over-engineered for the goal. The acceptance criterion is to identify the broadcast leak's root cause once; shipping a permanent module + TOML setting + CLI flag + TUI logger class for a one-shot investigation is dead weight in the gem.

Replacing with inline Rails.logger.debug calls on the server-side broadcast/drain path (no new files, no shipped infrastructure). For first-pass diagnosis, server logs are sufficient — every broadcast_removed emit will show up alongside whatever the TUI is displaying, and any stuck entry whose PM id has no matching emit line points at a server-side leak; whose PM id has a matching emit line points at TUI-side application miss. TUI-side instrumentation can be added as a follow-up if first-pass diagnosis lands at #2.

@hoblin hoblin closed this Apr 30, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant