Skip to content

Schema-discovery failure is swallowed: hu meter echo exits 0 with no output, hu meter delay runs on forever #297

Description

@YuanYuYuan

hu meter echo <topic> and hu meter delay <topic> need a message schema, because they decode message content. The host fetches that schema by querying the publisher's ~/get_type_description service. When that query fails, the host discards the failure. Neither command reports it.

Measured against a publisher that serves no type description:

command exit elapsed stdout what the user sees
hu meter echo /chatter 0 30 s 0 bytes nothing, then a clean exit
hu meter delay /chatter killed at 45 s 0 bytes nothing, indefinitely

The two differ by design, not by accident. echo sets DEFAULT_ECHO_TIMEOUT_TICKS = 30 as "a safety bound so echo can never hang forever". delay keeps duration_ticks = 0, "matching the always-running behavior" of hz and bw. That is defensible for hz and bw, because they print as they go. delay prints nothing, so a reader cannot tell it from a hang.

The one diagnostic is hidden by default

The host logs the cause once, at warn:

$ RUST_LOG=warn hu meter echo /chatter
WARN hu::plugin::wasm::host::ros: WASM plugin: schema discovery failed for /chatter:
type description service timed out: no response from node 'Pub' on service '/Pub/get_type_description'

That line does not appear at the default level. crates/hiroz-union/src/core/logger.rs:9 builds the default filter as:

EnvFilter::new("hiroz=info,zenoh=warn")

The filter names hiroz and zenoh. It does not name hu, so EnvFilter suppresses the hu::plugin::wasm::host::ros target entirely.

The result is worse than silence. A default run writes 11 INFO lines from hiroz to stderr, and none of them is the warning. The user sees startup noise, no messages, and exit 0.

Reproduction

Three terminals, from a checkout:

# 1. router
hu router

# 2. a publisher — z_pubsub's node does NOT enable the type description service
cargo run --example z_pubsub -- --role talker

# 3. observe
hu meter echo /chatter

Controls that isolate it

These four commands run against the same graph, at the same time:

command result what it shows
hu meter echo /chatter --raw 00 01 00 00 12 00 00 00 48 65 6c 6c 6f 20 68 69 72 6f 7a ... (Hello hiroz) messages arrive
hu meter hz /chatter /chatter: 1.000 Hz (1 samples) the subscription works
hu meter bw /chatter reports bandwidth the subscription works
hu meter info topic /chatter Type: std_msgs::msg::dds_::String_ liveliness resolves the type name

hz, bw, list and info pass because none of them decode message content. Only the two commands that decode content fail.

Root cause

crates/hiroz-union/src/plugin/wasm/host/ros.rs:58, fn subscribe:

let (tx, rx) = flume::bounded::<String>(256);          // :65
let handle = tokio::spawn(async move {
    let sub = match node.create_dyn_sub_auto(&topic_clone, Duration::from_secs(5)).await {  // :71
        Ok(s) => s,
        Err(e) => {
            tracing::warn!("WASM plugin: schema discovery failed for {}: {e}", topic_clone);  // :77
            return;                                     // task exits -> tx dropped
        }
    };
    loop {
        match sub.try_recv() {
            Some(Ok(msg)) => { /* send json */ }
            Some(Err(_)) => {}                          // :91  decode error, discarded
            None => { sleep(5ms).await }
        }
    }
});
// ...
Ok(Resource::new_own(rep))                              // :107

Two paths swallow the failure:

  1. Discovery failure at :77. The host logs at warn and returns. The task drops tx. try_recv at :242 does .ok() on the channel, so a closed channel becomes None, and the plugin sees an idle subscription forever.
  2. Decode error at :91. The host discards it. No log, no counter.

subscribe() returns Ok at :107 before it attempts discovery. It only spawns the task. The plugin's own error path therefore cannot fire for a discovery failure:

// crates/hiroz-union/plugins/hu-meter/src/lib.rs:267
let sub = match ros::subscribe(&topic) {
    Ok(s) => s,
    Err(e) => { render::eprintln(&format!("Failed to subscribe to {topic}: {e}")); ... }
};

That message exists and reads correctly. This class of failure never reaches it.

Suggested fix

  1. Await the outcome of create_dyn_sub_auto inside subscribe(), or propagate it another way. A discovery failure then returns Err. The plugin's Failed to subscribe to {topic}: {e} branch fires with the real reason.
  2. Stop discarding Some(Err(_)) at :91. Log it at minimum. Better, count decode errors so a partly undecodable stream looks different from an idle one.
  3. Add hu to the default EnvFilter, so a host-side warn! is visible without RUST_LOG. This is worth doing even after fix 1, because it covers every other host warning too.

Fixes 1 and 2 stay inside the host. The plugin already handles the error correctly.

Scope

This issue covers the silence. It does not cover why the schema was unavailable. Two separate issues cover those questions:

This fix alone does not make hu meter echo decode the example's messages. It makes the command report why it cannot. A regression test can therefore assert on the error message. Asserting on decoded output needs one of the two issues above.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions