Investigation revealed the root cause of premature streaming termination:
1. MPSC Channel Size Issue:
- DEFAULT_CHANNEL_SIZE = 16 chunks × 50ms = 800ms capacity
- TimerNode max_lead_time = 3.0 seconds
- The channel fills up in 0.8s while TimerNode wants 3s buffer
- This creates stop-and-go pattern instead of smooth backpressure
2. Channel Closure Issue:
- When RadioParadiseStreamSource::process() returns, the Node
automatically closes output channels
- TimerNode receives EOF and terminates immediately
- Remaining chunks in MPSC buffer (up to 16) are never sent to sink
Added comprehensive tracing:
- RadioParadiseStreamSource: Track backpressure blocking, chunk counts,
decode timing
- TimerNode: Log all pacing decisions, sleep durations, lead time
- Both use trace! for high-frequency events, debug! for blocking
Next steps:
- Option A: Increase channel size to match max_lead_time
(60 chunks for 3s @ 50ms)
- Option B: Wait for channels to drain before closing
(use tx.closed().await)
- Option C: Both A and B for optimal behavior
The previous "wait for playback duration" fix is a valid workaround
but doesn't address the architectural issue.
Cleaned up excessive INFO logging that was added during debugging.
Logs are now properly categorized by verbosity:
- Frequent/repeated logs (every chunk) → TRACE
* TimerNode SLEEPING messages
* Broadcaster "Read X bytes" messages
- Occasional/setup logs → DEBUG
* Node::run() starting/spawning
* TopZeroSync received
* Cancelled during sleep
- Important events remain INFO
* Encoder initialization
* Header captured
* Stream ended
* Broadcaster task started
This makes INFO logs clean and useful for production monitoring,
while keeping detailed information available via DEBUG/TRACE levels.
Tested with RUST_LOG=info - output is now clean with only
meaningful events logged.
Affected files:
- pmoaudio/src/nodes/timer_node.rs: SLEEPING → trace, TopZeroSync → debug
- pmoaudio/src/pipeline.rs: Node::run/Spawning → debug
- pmoaudio-ext/src/sinks/streaming_flac_sink.rs: Read bytes → trace
Enhanced logging to INFO level for key TimerNode operations:
- TopZeroSync reception and timer reset
- Sleep operations when lead_time exceeds max_lead_time
- Warning when no timer is set (missing TopZeroSync)
This diagnostic logging confirmed that:
1. TopZeroSync is properly received from RadioParadiseStreamSource
2. TimerNode correctly calculates lead_time and sleeps ~48ms per 50ms chunk
3. Real-time pacing is working as expected (3.0s max lead time)
The backpressure mechanism is functioning correctly - chunks flow at
real-time speed (~50ms per chunk) rather than downloading at maximum speed.
Changes:
- Add TimerNode (pmoaudio/src/nodes/timer_node.rs): Rate-limits audio chunk flow based on timestamps with configurable max_lead_time
- Integrate TimerNode into play_and_cache.rs pipeline: PlaylistSource → TimerNode (3s pacing) → AudioSink
- Improve EOF retry in playlist_source.rs: Wait for prebuffer (512KB) before decoding, retry on temporary EOF with 200ms delay
- Export TimerNode in pmoaudio lib.rs and nodes/mod.rs
Known issue: Cache files may still be truncated when TrackBoundary arrives before pump completes flushing.
This requires allowing parallel write tasks as suggested.
