ROS 2 rclpy rate.sleep() Blocks Forever: Why and How to Fix

한국어로 읽기

What happened when I ran it

I wrote an 8 Hz loop in rclpy the way you would with rospy.Rate in ROS 1: create a node, call node.create_rate(8.0), then run while True: ...; rate.sleep() on the main thread. The loop body ran once, and the first rate.sleep() never returned. A watchdog had to wake it 2 seconds later. When I moved rate.sleep() into a timer callback on a SingleThreadedExecutor, it hung in the same way. Two changes made it work: running the executor in a separate thread, or using a MultiThreadedExecutor with two threads.

Once the loop was running, a second question came up. What does rate.sleep() do when the work inside the loop takes longer than the period? I measured that as well. The loop doesn’t wait for the next 8 Hz tick. It just runs again as soon as the work finishes.

Here are the raw numbers. The explanation comes after them.

Setup. One script, experiment.py, runs eight cases one after another. Every case uses node.create_rate(8.0), so the target period is 0.125 s. All timing uses time.monotonic() while the script runs. In cases that hang, a watchdog calls node.destroy_rate(rate) after 2.0 s. That sets the Rate’s internal event and lets the blocked sleep() return, so the script always finishes.

  • A: no executor spinning. A main-thread while loop calls rate.sleep().
  • B, Bound, D, C: SingleThreadedExecutor.spin() runs in a daemon thread. The main loop does time.sleep(w) as stand-in work, then rate.sleep(), with w = 0.0625 s, 0.125 s, 0.15 s and 0.25 s. B gets a 5.0 s window and the others get 3.0 s. The first interval includes the phase offset between loop start and the timer, so it is reported separately. Mean, median, min and max are computed over the remaining intervals.
  • E, F1, F2: a 0.05 s timer in the node’s default (mutually exclusive) callback group fires once. Inside that callback the script calls rate.sleep() up to 8 times. E uses SingleThreadedExecutor, F1 uses MultiThreadedExecutor(num_threads=1) and F2 uses MultiThreadedExecutor(num_threads=2).

Environment. Image ros:jazzy-ros-base (ros@sha256:066420e07f60aa18262f2479981def87ebcfcec42eefb0c0c57c4a46098348ca), ROS 2 Jazzy, Python 3.12.3, rclpy 7.1.12-1noble.20260902.053513, RMW rmw_fastrtps_cpp (default), no network, limits 1 CPU and 1 GiB, use_sim_time off. Inside the container, os.sched_getaffinity(0) reported 2 CPUs and os.cpu_count() reported 2, even with the 1 CPU limit. I ran the same script 5 times. All 5 runs exited with code 0 and took 22.37 s to 22.46 s each.

Results: prediction vs measured (ranges cover all 5 runs; I wrote the predictions in plan.md before running)

Case Prediction Measured (5 runs)
A: no spin, main loop body runs once, first sleep() never returns, 0 returns before watchdog loop_bodies_run 1, sleep_returns_before_watchdog 0, last sleep() blocked 2.0003 to 2.0004 s (until the watchdog)
B: spin thread, work 0.0625 s, 5 s interval ≈ 0.125 s, wait ≈ 0.0625 s, ≈ 40 loop starts 40 loop starts; mean interval 0.125 s (min 0.1244, max 0.1256); mean wait in sleep() 62.375 to 62.378 ms; effective 8.0 to 8.0002 Hz
Bound: work 0.125 s (= period), 3 s wait ≈ 0, interval ≈ 0.125 s, 24 loop starts, slightly below 8 Hz 24 loop starts; mean interval 0.1251 s; mean wait 0.016 to 0.021 ms; effective 7.9919 to 7.9929 Hz
D: work 0.15 s, 3 s interval ≈ 0.15 s (not rounded up to 0.25 s), wait ≈ 0, 20 loop starts 20 loop starts; mean interval 0.1501 s (min 0.1501, max 0.1502); mean wait 0.024 to 0.027 ms; effective 6.6602 to 6.6606 Hz
C: work 0.25 s, 3 s interval ≈ 0.25 s, ≈ 4 Hz, wait ≈ 0, 12 loop starts 12 loop starts; mean interval 0.2501 to 0.2506 s; min 0.2501, max 0.2544 (run 2); mean wait 0.015 to 0.017 ms; effective 3.9909 to 3.9977 Hz
E: rate.sleep() in a SingleThreadedExecutor callback 0 returns before watchdog 0 returns; finished_without_watchdog false in all 5 runs
F1: MultiThreadedExecutor, 1 thread same as single-threaded: 0 returns 0 returns; finished_without_watchdog false in all 5 runs
F2: MultiThreadedExecutor, 2 threads returns, interval ≈ 0.125 s 8 of 8 returns; finished without watchdog in 1.0033 to 1.0036 s; first interval 0.0752 to 0.0753 s, then mean 0.125 s (min 0.1247, max 0.1251); effective 8.0008 to 8.0026 Hz

Raw output lines from run 1 (one JSON line per case):

{"case": "env", "sched_getaffinity_cpus": 2, "os_cpu_count": 2, "rmw": "default", "ros_distro": "jazzy"}
{"case": "A_no_spin_main_loop", "rate_hz": 8.0, "watchdog_s": 2.0, "loop_bodies_run": 1, "sleep_returns_before_watchdog": 0, "last_sleep_blocked_s": 2.0003, "elapsed_s": 2.0037, "error": null}
{"case": "C_spin_thread_work_0.25", "rate_hz": 8.0, "work_s": 0.25, "window_s": 3.0, "loop_starts_in_window": 12, "first_sleep_wait_ms": 0.032, "mean_sleep_wait_ms": 0.016, "max_sleep_wait_ms": 0.025, "spin_thread_stopped": true, "first_interval_s": 0.2501, "n_intervals": 10, "mean_interval_s": 0.2501, "median_interval_s": 0.2501, "min_interval_s": 0.2501, "max_interval_s": 0.2504, "stdev_interval_s": 0.0001, "effective_hz": 3.9977}
{"case": "E_single_threaded_callback", "rate_hz": 8.0, "sleep_attempts": 8, "watchdog_s": 2.0, "callback_entered": true, "sleep_returns_before_watchdog": 0, "finished_without_watchdog": false, "callback_exited": true, "elapsed_s": 2.0035, "error": null, "spin_thread_stopped": true}
{"case": "F2_multi_threaded_2_threads_callback", "rate_hz": 8.0, "sleep_attempts": 8, "watchdog_s": 2.0, "callback_entered": true, "sleep_returns_before_watchdog": 8, "finished_without_watchdog": true, "callback_exited": true, "elapsed_s": 1.0036, "error": null, "spin_thread_stopped": true, "first_interval_s": 0.0753, "n_intervals": 7, "mean_interval_s": 0.125, "median_interval_s": 0.1251, "min_interval_s": 0.1248, "max_interval_s": 0.1251, "stdev_interval_s": 0.0001, "effective_hz": 8.0008}

Every run printed this warning to stderr in case F1. It was expected, because F1 uses one thread on purpose:

/opt/ros/jazzy/lib/python3.12/site-packages/rclpy/executors.py:979: UserWarning: MultiThreadedExecutor is used with a single thread.
Use the SingleThreadedExecutor instead.

All eight cases matched what I predicted from the source. In short: rate.sleep() hangs when no thread is free to run the Rate’s timer callback. It runs slow when the loop body takes longer than the period.

Why rate.sleep() blocks forever: it waits for a timer callback

In ROS 1, rospy.Rate.sleep() handled timing on its own. It read the current time, worked out how much of the period was left, and slept for that long (rospy timer.py L90–L113). Nothing else had to be running.

rclpy works differently. Everything below comes from the Jazzy source at commit 4e607c0 (rclpy 7.1.12):

  1. node.create_rate(frequency) computes period = 1.0 / frequency and creates an ordinary ROS timer with no callback. The timer goes into the node’s private _rate_group, and the method wraps it in a Rate object (node.py L1803–L1823).
  2. Rate.__init__ creates a threading.Event and sets the timer’s callback to self._event.set (timer.py L121–L136).
  3. Rate.sleep() calls self._event.wait() with no timeout. Afterwards it clears the event, but only when no other thread is still sleeping on the same Rate (timer.py L146–L177).

So rate.sleep() doesn’t measure time at all. It waits for a flag, and only the timer callback raises that flag. The executor is what calls timer callbacks. The ROS 2 Jazzy “About Executors” page puts it this way: the executor “uses one or more threads of the underlying operating system to invoke the callbacks of subscriptions, timers, …”. The wait set detects that the timer has expired, but nothing calls the callback until an executor thread is free.

That gives two ways to hang:

  • Nothing is spinning (case A). The timer expires every 0.125 s, but no executor ever calls _event.set. The first sleep() waits forever.
  • The only executor thread is the one sleeping (cases E and F1). The callback that called rate.sleep() is holding the executor’s single thread. The Rate’s timer is ready, but there’s no thread left to run it. The sleep() docstring warns about this directly: “This may block forever if called in a callback in a SingleThreadedExecutor.” (timer.py L166–L172). A MultiThreadedExecutor with one thread is the same situation, and rclpy warns you about it (executors.py L951–L983).

Case F2 works because of a detail most tutorials skip. The Rate timer does not go into the node’s default callback group. It goes into self._rate_group = ReentrantCallbackGroup() (node.py L178), and a reentrant group always allows execution (callback_groups.py L80–L90). With two threads, one thread can sit in your callback’s rate.sleep() while the other runs the Rate’s timer callback. That is why F2 returned 8 times out of 8.

A side effect explains the 0.075 s first interval in F2. The trigger timer fired at about 0.05 s and the Rate’s first tick came at 0.125 s, so the first wait was roughly 0.125 − 0.05 = 0.075 s. After that, the intervals settled at the 0.125 s grid.

The watchdog in the experiment also shows how to unstick a blocked sleep(). node.destroy_rate(rate) and rclpy.shutdown() both set the event (timer.py L138–L144). The official tests check this behavior (test_destroy_wakes_rate and test_shutdown_wakes_rate in test_rate.py L106–L138).

Why the loop runs slower than the Rate: work time vs period

A slow loop is a different problem from a hung one, and it has a different cause. The Rate timer raises the flag every T seconds, and the flag stays up until sleep() returns and clears it. Assuming the executor is running, two things follow:

  • If your work takes w < T, the flag isn’t up yet when you call sleep(), so you wait about T − w. In case B, T − w = 0.125 − 0.0625 = 0.0625 s, and the measured wait was about 62.4 ms. The loop held 8 Hz.
  • If w ≥ T, at least one tick happens while the work is running. The flag is already up when you call sleep(), so it returns right away. The measured waits in cases Bound, D and C were all well under 0.1 ms.

The effective loop period is therefore about max(T, w). Two details are easy to get wrong:

  • The loop doesn’t snap to the next tick. With w = 0.15 s, you might expect the loop to wait for the 0.25 s tick and run at 4 Hz. It doesn’t. It ran every 0.1501 s, about 6.66 Hz (case D).
  • There’s no catch-up burst. With w = 0.25 s, two ticks happen during each loop, but they only raise the same single flag. You get one immediate return, not two. In case C, the shortest interval in any run was 0.2501 s, so no iteration ran fast to make up for lost ticks. The loop simply ran at about 4 Hz. (ROS 1 rospy.Rate handled this differently: it reset its schedule when it fell more than two periods behind.)

The boundary case w = T shows there is no margin at all. Loop overhead made each interval 0.1251 s instead of 0.125 s. That’s 7.99 Hz instead of 8, and the waits were essentially zero. Any jitter in your work goes straight into the period.

To check your own loop, compute T = 1/f and estimate how long your work takes. If you can’t estimate it, measure it. Then log how long rate.sleep() takes:

t0 = time.monotonic()
rate.sleep()
waited = time.monotonic() - t0   # ≈ T − w when healthy, ≈ 0 when the work exceeds the period

If a loop counter stops increasing, the problem is how your executor is set up. If the counter increases but waited is near zero, your work is longer than the period, and changing the executor won’t help.

How to fix it: three working setups

1. Spin in a background thread and run the Rate loop on the main thread. Cases B through C used this pattern, and it’s also the structure of the official test_rate.py:

import threading
import rclpy
from rclpy.executors import SingleThreadedExecutor

rclpy.init()
node = rclpy.create_node('fixed_rate_loop')
executor = SingleThreadedExecutor()
executor.add_node(node)
threading.Thread(target=executor.spin, daemon=True).start()

rate = node.create_rate(8.0)
while rclpy.ok():
    do_work()        # your loop body
    rate.sleep()

The executor thread can now run the Rate’s timer callback, so sleep() returns on time. The measured script uses this structure. It doesn’t loop on rclpy.ok(), though, and shutdown handling wasn’t measured. When rclpy.shutdown() runs during a sleep(), the source raises ROSInterruptException (timer.py L146–L177), so catch it if you need a clean exit. If do_work() reads data that your subscription callbacks write, those callbacks now run on a different thread. Protect the shared state with a lock.

2. Use a MultiThreadedExecutor with at least two threads when the Rate has to be called inside a callback (case F2):

from rclpy.executors import MultiThreadedExecutor
executor = MultiThreadedExecutor(num_threads=2)   # set it explicitly

Set num_threads yourself. By default rclpy uses len(os.sched_getaffinity(0)) (executors.py L951–L983). In my container that reported 2 even though the CPU quota was 1. On a machine or container that reports one CPU, you’d silently get the single-thread setup from case F1, which hangs. Also note that while your callback sleeps, it still holds its own callback group. If that’s the node’s default mutually exclusive group, every other callback in that group is blocked until the loop ends (Using Callback Groups). A callback that never returns isn’t really a callback anymore. Use option 1 or 3 for long-running loops.

3. Drop the Rate and put the loop body in a timer callback, using node.create_timer(1.0 / f, step). Nothing blocks, so neither way of hanging can happen. This is usually the simplest choice for new nodes. I didn’t measure this setup. In particular, what happens when step takes longer than the period depends on how the rcl timer schedules its next call, not on the Rate’s flag. This article’s numbers don’t cover it.

Limits of this measurement

  • The work was simulated with time.sleep(w), which releases the GIL. Real CPU-bound Python work holds the GIL, which can delay the executor thread and add jitter. I didn’t measure that.
  • Work time was constant. I didn’t test variable work times, use_sim_time with /clock, or other distributions. According to the source, the Rate timer uses the node’s ROS clock (node.py L237–L238, time_source.py L87–L100), so it should follow simulation time when use_sim_time is on. That isn’t verified here, and neither is the behavior before the first /clock message arrives.
  • The source references are rclpy Jazzy (7.1.12). Humble and Rolling may implement Rate differently. Check rclpy/timer.py in your own install.
  • This was a Python process in a CPU-limited container, not a simulator or a robot. Holding 8 Hz here says nothing about real-time deadline guarantees. If a loop like this sends robot commands, a slow loop delays them and a hung sleep() stops them entirely. Whether the robot stops safely when commands stop depends on its driver and controller, which I didn’t test.
  • Each case ran once per run, over 5 runs. The 0.2544 s maximum interval in case C, run 2, was a single outlier. With this few samples, the jitter numbers are rough.

Reproduce it

The script, plan and raw results are in experiments/rclpy-rate-sleep-timer-executor-loop-period. Here are the files pinned to the commit used for this article:

  • experiment.py: all eight cases, about 200 lines, standard library plus rclpy
  • plan.md: predictions written before the runs, plus the trial-and-error notes
  • results.json: full stdout and stderr of all 5 runs

From the directory that contains experiment.py:

docker run --rm --network none --cpus 1 --memory 1g -v /path/to/experiment-dir:/work \
  ros@sha256:066420e07f60aa18262f2479981def87ebcfcec42eefb0c0c57c4a46098348ca \
  bash -c "source /opt/ros/jazzy/setup.bash && python3 /work/experiment.py"

One run takes about 22 seconds. The script has a hard 55 s deadline, so a hang can’t stall your terminal.

Sources