Skip to content

Publishing from inside a subscriber callback hangs forever #249

Description

@YuanYuYuan

Part of #282 — instance of the re-entrancy defect class; fixed by #250. The class, the shared fix shape and the merge order are stated in #282.

What a user does

Subscribes to two topics on one node and lets each callback publish to the other — the ordinary "react to a message by emitting a message" shape.

let node = ctx.create_node("relay").build()?;

let to_b = Arc::new(node.create_pub::<Tick>("/b").build()?);
let _a = node.create_sub::<Tick>("/a")
    .build_with_callback(move |m: Tick| { let _ = to_b.publish(&Tick { n: m.n + 1 }); })?;

let to_a = Arc::new(node.create_pub::<Tick>("/a").build()?);
let _b = node.create_sub::<Tick>("/b")
    .build_with_callback(move |m: Tick| { let _ = to_a.publish(&Tick { n: m.n + 1 }); })?;

// kick the loop
node.create_pub::<Tick>("/a").build()?.publish(&Tick { n: 0 })?;
std::thread::sleep(Duration::from_secs(5));

Nothing here is unusual and nothing requires internal knowledge. The single-topic variant (subscribe to /a, republish to /a) deadlocks identically.

What happens

The process hangs at the first publish, permanently. No error, no panic, no log line, no traceback. The only way out is to kill it.

Through the Python bindings the symptom is worse: the entire interpreter freezes. Not one blocked thread — every thread. A watchdog thread ticking every 50 ms into a flushed log stops dead at the line before the re-entrant publish and emits nothing further; the process has to be killed externally and pytest never writes a single byte of output. That is the difference between a diagnosable hang and an undiagnosable one, and it was the symptom that started this investigation.

Under TransientLocal durability the same thing happens by a slightly different route, so both QoS profiles must be exercised.

Root cause

Three mechanisms, stacked:

  1. crates/hiroz/src/pubsub.rs, ZSubBuilder::build_internal declared every subscriber as a zenoh-ext AdvancedSubscriber, unconditionally. AdvancedSubscriber's sample callback takes a std::sync::Mutex (sub_callback -> zlock!(statesref)) and then invokes the user callback under that guard, via handle_sample. std::sync::Mutex is not reentrant.

  2. Zenoh core dispatches a same-session sample synchronously, inline on the thread that called putSession::resolve_put drops the session lock and then calls call_local, which invokes the subscriber callbacks directly. There is no spawn, no channel, no runtime hop; publisher.put(x).await is not async either, its into_future is std::future::ready(self.wait()).

So a callback that publishes into its own topic graph re-enters a mutex its own thread already holds further up its own stack. Zenoh core is not at fault — it drops its own lock before invoking local callbacks precisely so that re-entrant publishing is safe there. The unconditional .advanced() is.

  1. Removing the lock is necessary but not sufficient. With the lock gone, the same synchronous inline dispatch means a callback that publishes recurses instead of iterating, until the stack overflows.

In the Python bindings, ZPublisher.publish additionally held the GIL across the blocking zenoh publish, which is what turned one stuck thread into a dead interpreter.

Minimal repro

The Rust snippet above, run under a wall-clock deadline so it fails rather than wedging CI. In Python:

import threading, hiroz_py

node = ctx.create_node("relay")
b = node.create_publisher("/b", Tick)
a = node.create_publisher("/a", Tick)
node.create_subscription("/a", Tick, lambda m: b.publish(Tick(n=m.n + 1)))
node.create_subscription("/b", Tick, lambda m: a.publish(Tick(n=m.n + 1)))

alive = threading.Thread(target=lambda: [print("tick", flush=True) or time.sleep(0.05) for _ in range(200)])
alive.start()
a.publish(Tick(n=0))          # interpreter goes dark here on an unfixed build

Run it under an external timeout. On an unfixed build the process exits with rc=124 and the watchdog output stops at the publish; on a fixed build the watchdog keeps ticking and the run completes.

How this was found

Not a user report. Found by an audit of hiroz's locking, and then given the repros above.

Detector evidence, both directions

The Rust detectors below were re-run against the fix branch, in both directions. Baseline: reentrant_publish is 10 passed in 10.37 s with --features ros-msgs,jazzy.

  • Reverting the whole production change and keeping the tests, four fail on their deadline — callback_cycle_across_two_topics_does_not_deadlock, callback_republishing_on_same_topic_does_not_deadlock, intra_closed_loop_runs_iteratively, self_feeding_callback_loop_iterates_without_a_depth_cap — and the run then wedges permanently on transient_local_callback_cycle_across_two_topics_does_not_deadlock. That test's own deadline does not rescue it: the blocked thread is the one the harness would need in order to report the failure, so the binary has to be killed externally. Anyone trying the revert should expect a hung run rather than a clean red.
  • Reverting only the dispatch decision (local_publish_active() -> false), exactly two tests die with fatal runtime error: stack overflow, abortingself_feeding_callback_loop_iterates_without_a_depth_cap and intra_closed_loop_runs_iteratively. The other eight still pass, including every TransientLocal variant, which keeps zenoh-ext's own dispatcher and is therefore insensitive to this half of the change.
  • Python, two release wheels differing only in the production change. On the fixed wheel the hiroz-py suite is 55 passed, 2 skipped. On the unfixed wheel, each cell run in its own process under an external 60 s wall-clock timeout — checked per cell, because a cell that did not hang would prove nothing:
rc=124  test_same_topic_republish[volatile]                      0 bytes written
rc=124  test_same_topic_republish[transient_local]               0 bytes written
rc=124  test_two_topic_cycle[volatile]                           0 bytes written
rc=124  test_two_topic_cycle[transient_local]                    0 bytes written
rc=124  test_self_feeding_loop_iterates[volatile]                0 bytes written
rc=124  test_self_feeding_loop_iterates[transient_local]         0 bytes written
rc=124  test_interpreter_stays_alive_during_reentrant_publish    0 bytes written

Not merely failing: hanging. rc=124 is the external timeout killing the process, and the 0 bytes column is the whole point — pytest never writes a single byte, not even a collection header, because every thread is frozen. There is no failure report to read, which is why an external timeout is required and why an in-process deadline could not have caught this.

Fixed by

#250.

Note that #250 changes an observable semantic: session-local delivery becomes asynchronous, so a publisher no longer knows the sample has been delivered when publish() returns. See that PR's description.

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