Skip to content

Do not warn when a status channel is full - #442

Merged
jhelovuo merged 1 commit into
Atostek:masterfrom
alpitol:fix/no-warn-on-full-status-channel
Sep 11, 2026
Merged

Do not warn when a status channel is full#442
jhelovuo merged 1 commit into
Atostek:masterfrom
alpitol:fix/no-warn-on-full-status-channel

Conversation

@alpitol

@alpitol alpitol commented Sep 10, 2026

Copy link
Copy Markdown
Contributor

While making MWE for PR 441, came across this. So RustDDS seem to send warnings unnecessary if no one is listening best effort messages. This is ai-generated pull request made with Claude Opus 5. The PR below:

Do not warn when a status channel is full

Summary

StatusChannelSender::try_send logs

WARN rustdds::dds::statusevents] StatusChannelSender cannot send new status changes, channel is full.

for a condition that the same function documents, twice, as normal. Because
RustDDS's own built-in Discovery endpoints never drain their status channels,
this fires once per discovered participant per built-in endpoint, forever, and
the application can neither drain nor suppress it.

The bug

src/dds/statusevents.rs:

/// Best-effort send. If there is no receiver, this will fail silently.
pub fn try_send(&self, t: T) -> Result<(), mio_channel::TrySendError<T>> {
  ...
    Err(mio_channel::TrySendError::Full(_tt)) => {
      warn!("StatusChannelSender cannot send new status changes, channel is full.");
      // It is perfectly normal to fail due to full channel, because
      // no-one is required to be listening to these.
      ...
      // We convert the Err to Ok, bause we do not consider this to be an error.
      // The caller loses the payload object (tt), even though it is not sent.
      Ok(())
    }

The doc comment promises to "fail silently". The comment on the line after the
warn! says the condition is "perfectly normal". The comment three lines later
says "we do not consider this to be an error". And yet it warns — at the one
level applications actually leave enabled in production.

Why it fires constantly

Every built-in Discovery endpoint — DCPSParticipant, DCPSPublication,
DCPSSubscription, DCPSParticipantMessage, DCPSTopic — is an ordinary
DataWriter/DataReader, so each gets a status channel of capacity 4
(sync_status_channel(4), src/dds/pubsub.rs:479 and :1103).

Nothing ever drains those four slots:

  • Discovery never calls try_recv_status / as_status_evented /
    as_async_status_stream on its built-in endpoints (grep returns nothing).
  • The application has no handle on them either — they are internal.

Meanwhile, each discovered remote participant produces one
PublicationMatched / SubscriptionMatched event on each built-in endpoint.

So the channels fill after 4 participants, and from the 5th onwards every single
match event is dropped and warned about.

I confirmed this by instrumenting Writer::send_status /
Reader::send_status_change. On an ordinary office network, two bare
DomainParticipants with no topics, writers or readers at all:

 37 PROBE writer topic="DCPSSubscription"       status=PublicationMatched  {...}
 37 PROBE writer topic="DCPSPublication"        status=PublicationMatched  {...}
 37 PROBE writer topic="DCPSParticipant"        status=PublicationMatched  {...}
 37 PROBE writer topic="DCPSParticipantMessage" status=PublicationMatched  {...}
 37 PROBE reader topic="DCPSSubscription"       status=SubscriptionMatched {...}
 37 PROBE reader topic="DCPSPublication"        status=SubscriptionMatched {...}
 37 PROBE reader topic="DCPSParticipant"        status=SubscriptionMatched {...}
 37 PROBE reader topic="DCPSParticipantMessage" status=SubscriptionMatched {...}
  7 PROBE writer topic="DCPSTopic"              status=PublicationMatched  {...}
  7 PROBE reader topic="DCPSTopic"              status=SubscriptionMatched {...}

— 18 distinct remote participants (other people's ROS 2 / Fast-DDS nodes) were
on that domain, and the events are genuine one-per-peer matches, not duplicates.
The warning rate is therefore proportional to how busy the domain is, and it
never stops.

The second half of the bug

try_send converts Full into Ok(()) and discards the payload. That makes
the callers' own, deliberately quiet handling of Full unreachable dead code:

src/rtps/writer.rs:

TrySendError::Full(_) => (), // This is normal in case there is no receiver

src/rtps/reader.rs:

Err(mio_channel::TrySendError::Full(_)) => {
  trace!("Reader cannot send new status changes, datareader is full.");
  // It is perfectly normal to fail due to full channel, because
  // no-one is required to be listening to these.
}

Both arms are correct. Neither can ever execute. The layer below already decided,
and decided the opposite way.

Why this is a bug worth fixing

  1. The stated contract and the behaviour disagree. "Fail silently" versus a
    WARN per event. One of them is wrong, and three separate comments in the
    function say the log is the wrong one.
  2. It is unbounded and unfixable from outside. The rate scales with the
    number of participants on the domain. Applications cannot drain these
    channels — they do not own the endpoints — and cannot lower the level without
    turning off the whole rustdds::dds::statusevents target, which would also
    hide genuine problems.
  3. It buries real warnings. WARN is what production leaves on. 578 lines
    per 10 s from the MWE below is enough to make the log useless.
  4. It silently defeats deliberate error handling elsewhere. Two call sites
    went to the trouble of classifying Full as benign; the abstraction throws
    that away and loses the event payload with it.

MWE

Save the following code as new example in examples/status_channel_spam_mwe/main.rs and run it to test.

//! MWE for "StatusChannelSender cannot send new status changes, channel is
//! full." warning spam.
//!
//! RustDDS's built-in discovery endpoints (DCPSParticipant, DCPSPublication,
//! DCPSSubscription, DCPSParticipantMessage, DCPSTopic) are DataWriters and
//! DataReaders like any other, so each one gets a status channel of capacity 4
//! (`sync_status_channel(4)` in `src/dds/pubsub.rs`). Nothing ever drains them:
//! Discovery never calls `try_recv_status`, and the application has no handle
//! on these internal endpoints.
//!
//! Every discovered remote participant produces one PublicationMatched /
//! SubscriptionMatched event on each built-in endpoint. So from the 5th
//! participant onwards, every match event is dropped -- and each drop logs a
//! WARN that the application cannot switch off or drain.
//!
//! This starts 8 participants on one domain to make it deterministic without
//! needing a populated network. On a real network the same thing happens with
//! *other people's* nodes: any domain with more than ~4 participants does it.
//!
//! Run with:
//!
//!   RUST_LOG=warn,rustdds::network::udp_sender=off \
//!     cargo run --example status_channel_spam_mwe
//!
//! (The `udp_sender=off` part only hides an unrelated EAFNOSUPPORT warning on
//! hosts with IPv6-capable interfaces; drop it once that is fixed separately.)
//!
//! Expected (correct) output: nothing, or at most a bounded number of lines.
//! Actual output: hundreds of identical warnings, growing with participant
//! count and uptime.

use std::{thread, time::Duration};

use rustdds::DomainParticipantBuilder;

// An unusual domain id, so the count below is not perturbed by whatever else
// happens to be running on domain 0 on the developer's network.
const DOMAIN_ID: u16 = 47;

// Built-in endpoint status channels hold 4 events. Exceed that.
const PARTICIPANTS: usize = 8;

fn main() {
  env_logger::Builder::from_env(env_logger::Env::default().default_filter_or("warn")).init();

  let participants: Vec<_> = (0..PARTICIPANTS)
    .map(|_| {
      DomainParticipantBuilder::new(DOMAIN_ID)
        .build()
        .expect("DomainParticipant construction failed")
    })
    .collect();

  println!(
    "{} participants on domain {DOMAIN_ID}; running for 10 s",
    participants.len()
  );
  thread::sleep(Duration::from_secs(10));
}

Run the MWE with command

$ RUST_LOG=warn,rustdds::network::udp_sender=off cargo run --example status_channel_spam_mwe

With this PR the warnings dissappear.

The fix

  • StatusChannelSender::try_send now returns Err(TrySendError::Full(t)),
    handing the unsent payload back, and logs nothing. The receiver is still woken
    on a full channel, so a listener that has fallen behind is still prompted to
    drain. This revives the existing Full arms in Writer::send_status and
    Reader::send_status_change, which already do the right thing. This is not a
    breaking change in practice, because StatusChannelSender is public-but-unobtainable.
    If breaking change is ok, one could consider to set StatusChannelSender::try_send
    to be pub(crate), as it's unobtainable anyway.

  • Added StatusChannelSender::try_send_lossy for the "dropping is fine"
    case: it logs a full channel at trace! and keeps error! for genuine send
    failures. The six DomainParticipantStatusEvent senders
    (dp_event_loop.rs ×3, writer.rs, reader.rs, discovery_db.rs,
    discovery.rs) use it. Note these previously ended in
    .unwrap_or_else(|e| error!(...)), so with try_send made honest they would
    otherwise have started reporting a full channel as an error — strictly
    worse than the warning being removed.

Every status event that fits is still delivered, in order, to whoever is
listening. Nothing about matching, discovery or delivery changes.

Tests

Two new unit tests in src/dds/statusevents.rs:

  • full_channel_is_reported_to_caller_with_payload — a capacity-2 channel
    accepts two events and then returns Full with the unsent value, instead of
    a silent Ok(()).
  • channel_accepts_again_after_drain — draining makes room again, and the
    receiver sees exactly the accepted events in order; the rejected one leaves no
    gap or duplicate.

cargo test → 692 + 2 + 58 pass. cargo test --features security → 702 + 2 + 58
pass. cargo +nightly fmt and cargo +nightly clippy --tests --examples
(also --all-features) are clean.

Notes for reviewers

  • An alternative fix would be to stop creating status channels for built-in
    Discovery endpoints at all, since nothing can ever read them. That removes the
    wasted work as well as the log line, but it is a much larger change to the
    internal pubsub API, and the logging contradiction above would still be
    worth fixing on its own.
  • If you would rather keep some visibility of a full channel, the natural place
    is try_send_lossy; raising its trace! to debug! would be a one-line
    change. I kept it at trace! because the built-in endpoints hit this path
    constantly and by design.
  • The MWE above is not part of the commit; it exists only to make this report
    reproducible.

`StatusChannelSender::try_send` logged

  WARN StatusChannelSender cannot send new status changes, channel is full.

for a condition that its own doc comment ("Best-effort send. If there is no
receiver, this will fail silently.") and the very next line of its own body
("It is perfectly normal to fail due to full channel, because no-one is
required to be listening to these.") both declare to be normal.

It is not a rare condition. Every built-in Discovery endpoint
(DCPSParticipant, DCPSPublication, DCPSSubscription, DCPSParticipantMessage,
DCPSTopic) is an ordinary DataWriter/DataReader, so each gets a status channel
of capacity 4 from `sync_status_channel(4)` in pubsub.rs. Nothing ever drains
them: Discovery never calls `try_recv_status`, and the application has no
handle on these internal endpoints. Each discovered remote participant
produces one PublicationMatched/SubscriptionMatched event per built-in
endpoint, so from the 5th participant onwards every single match event is
dropped -- and warned about. The rate grows with the number of participants on
the domain and never stops, and the application cannot drain, suppress or act
on it.

Worse, `try_send` converted `Full` into `Ok(())` and dropped the payload. That
made the callers' own, deliberately quiet handling of `Full` unreachable dead
code -- `Writer::send_status` maps it to `()` with the comment "This is normal
in case there is no receiver", and `Reader::send_status_change` logs it at
`trace!`. Both were correct; neither could ever run.

Changes:

* `StatusChannelSender::try_send` now returns `Err(TrySendError::Full(t))`,
  handing the unsent payload back, and logs nothing. The receiver is still
  woken on a full channel, so a listener that has fallen behind is prompted to
  drain. This revives the existing `Full` arms in `Writer::send_status` and
  `Reader::send_status_change`.

* Added `StatusChannelSender::try_send_lossy` for the "dropping is fine" case,
  logging a full channel at `trace!` and keeping `error!` for genuine send
  failures. The six `DomainParticipantStatusEvent` senders use it; previously
  they would have reported a full channel as `error!`.

Behaviour is otherwise unchanged: every status event that fits is still
delivered, in order, to whoever is listening.

Co-authored-by: Copilot & Claude Opus 5
@jhelovuo
jhelovuo merged commit ee79e23 into Atostek:master Sep 11, 2026
6 of 7 checks passed
@jhelovuo

Copy link
Copy Markdown
Member

This seems to be an accidental regression in commit 724950c . Logging level was raised to find a bug, but it was not lowered back after the bug had been fixed. Merged as minimal version that only reverts the accident.

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.

2 participants