ROS 2 inference node latency / timeout: what is slowing the loop
A ROS 2 inference node that is slow, spiky, or timing out is almost always one of three families. The first call is slow and the rest are fine: model warm-up, from CUDA graph capture, cuDNN algorithm selection, or an engine build. Every call is slow and the timers stall: an executor is serializing callbacks behind the inference. The data arrives stale or not at all: a silent QoS mismatch or an old transform. Measure first with topic statistics, read the printed string, and fix the family it names. A timeout is a hold decision, not a retry.
Everything below was checked against ROS 2 Jazzy Jalisco on October 27 2026. Jazzy is the long-term-support distribution, supported to May 2029. docs.ros.org now defaults to Lyrical Luth, released in May 2026. The Jazzy pages still carry their own banner: the version is older but still supported. Where a string is distribution specific, the page says so. Every quoted string was read from its source on that day, byte for byte. Each one carries a cause, a fix, and a prevention.
First, measure: the numbers ROS 2 already prints
Guessing the family costs hours. ROS 2 ships the measurement. Topic Statistics reports two metrics in milliseconds for any subscription you enable it on. message_age is how old each message was when it arrived. message_period is the gap between arrivals. The Jazzy tutorial enables it in C++ with subscription options:
auto options = rclcpp::SubscriptionOptions();
options.topic_stats_options.state = rclcpp::TopicStatisticsState::Enable;
options.topic_stats_options.publish_period = std::chrono::seconds(10);
Statistics publish to /statistics by default. Watch them from the CLI while the loop runs:
ros2 topic echo /statistics
Each message carries the metric name, the unit, a time window, and five statistics. Decode data_type as follows: 1 average, 2 minimum, 3 maximum, 4 standard deviation, 5 sample count. Read the maximum and the average together. A message_age maximum far above its average says data sometimes arrives already stale. That is family three. A message_period that swings while the publisher rate holds steady says the subscriber or the middleware is falling behind. That smells like family two.
For a quick rate check on one topic:
ros2 topic hz /camera/image_color
One caution, printed by the tool itself. When the clock the tool reads jumps, it prints time has reset, resetting counters and starts over. Nodes that mix sim time and wall clock trigger exactly that. Make use_sim_time consistent before trusting any rate number.
The strings, and the family each one names
Read the string before you read any advice. Each row below is verbatim from the source that prints it, fetched October 27 2026.
| The string, verbatim | Where it prints | What it tells you |
|---|---|---|
Lookup would require extrapolation into the future. Requested time ... but the latest data is at time ... | tf2, raised on lookup | you asked for a transform newer than the buffer holds; the tf data is late (two spaces after the period are real) |
Lookup would require extrapolation into the past. Requested time ... but the earliest data is at time ... | tf2, raised on lookup | you asked older than the oldest buffered transform; a clock jump or a bag replay |
Lookup would require extrapolation at time ..., but only time ... is in the buffer | tf2, raised on lookup | the buffer holds data for a single instant; typical of the first lookup of a run |
Message Filter dropping message: frame '...' at time ... for reason '...' | tf2_ros MessageFilter | a synchronized drop; the reason string carries the why |
the timestamp on the message is earlier than all the data in the transform cache | MessageFilter reason | the sensor stamp lags every buffered transform (family three) |
did not find a valid transform, this usually happens at startup ... | MessageFilter reason | the tf buffer is still filling; a warm-up race, often benign |
discarding message because the queue is full | MessageFilter reason | the filter fell behind; overload, which smells like family two |
WARNING: topic [...] does not appear to be published yet | ros2 topic echo and hz | no visible publisher on that topic; with a QoS mismatch this is the only line you get |
History set to KEEP_LAST without a depth setting. | rclpy InvalidQoSProfileException | your QoSProfile lacks depth; fails fast at construction, before the loop |
policy_inference_timeout stale_observation image_timeout observation_sync_timeout | PolicyBridge-ROS2 termination reasons | the robot side's named timeouts, each with a defined hold |
The three families and the timeout section carry each row's cause, fix, and prevention.
Family one: the first call is slow, the rest are fine
The cause. The first pass through a model pays work that never repeats. PyTorch's cuDNN front end has a flag, torch.backends.cudnn.benchmark. Its documentation reads: "A bool that, if True, causes cuDNN to benchmark multiple convolution algorithms and select the fastest." Benchmarking happens on first use of each shape. Model cards say it plainly. The MolmoAct2 card ships CUDA graph capture on by default and states: "The first few calls can be slow because the model warms up and captures CUDA graphs. run several random warm-up calls before measuring deployment latency." TensorRT goes further and turns your model into a different artifact. It "compiles them into engines, which are optimized executable artifacts for a specific deployment configuration". The first run of a new configuration pays that build.
The fix. Warm the model inside node startup, before the executor serves the loop. Use several calls on the same tensor shapes as real traffic. The warm-up belongs in your configure or load step, not on the first real tick. If you time the model, time it after warm-up. Otherwise you are timing construction. On a Jetson Orin, also pin the clocks for the run, with the commands the platform guide itself prints:
sudo nvpmodel -m 0
sudo /usr/bin/jetson_clocks
The guide describes the second one exactly: "The jetson_clocks.sh script maximizes a Jetson Orin performance by setting the static maximum frequencies of the CPU, GPU and EMC clocks." Treat MAXN as a benchmarking setting, not a deployment setting. The same guide warns that "this mode does not guarantee the best performance for all use cases because hardware throttling is engaged when the total module power exceeds the TDP budget". It also warns against "running heavy workloads for prolonged periods in this mode".
The prevention. Keep one warm-up pass in the startup path forever. A process restart then cannot leak a slow first call into an episode. Keep the process warm across episodes when your architecture allows it. Re-run warm-up whenever the input shape set changes. A new shape is a new first call.
Family two: the executor is serializing the loop
The cause. A plain node spin is single threaded. The executors concept page prints it: "The call to spin(node) basically expands to an instantiation and invocation of the Single-Threaded Executor". Messages do not queue in your node while the executor is busy. The same page: "an incoming message is not stored in a queue on the Client Library layer but kept in the middleware until it is taken for processing by a callback function." So when your inference callback runs long, everything else on that node waits. Camera callbacks wait. Timers wait. Worse, your callbacks share one group by default: "All subscriptions, timers, etc. that are created without the indication of a callback group are assigned to the default callback group". In rclpy that group is a MutuallyExclusiveCallbackGroup, created as such in Node.__init__. Its API description is one sentence: "Allow only one callback to be executing at a time." Under sustained overload the order degrades too. The executor works "in a round-robin fashion - but not in FIFO order". Messages "will be queued on the lower layers of the stack". And "Callbacks may suffer from priority inversion. Higher priority callbacks may be blocked by lower priority callbacks." That is the mechanism behind "my node stopped updating while inference ran".
The fix. Get the heavy call out of the callback, or give the executor room to overlap. Three printed options, in order of preference. First, hand off. The subscription callback copies the message and posts the inference job to a dedicated thread or process, then returns. The control timer reads the latest result. This fixes family two for both client libraries. Second, split callback groups and use a MultiThreadedExecutor. The rclpy API describes the class in one line: "Runs callbacks in a pool of threads." When num_threads is None the count comes from the OS CPU affinity; if the OS does not provide that information, the pool "defaults to 2". Put the inference subscription in a ReentrantCallbackGroup ("Allow callbacks to be executed in parallel without restriction.") or in its own mutually exclusive group. Other callbacks are then not queued behind it:
self.infer_group = MutuallyExclusiveCallbackGroup() # store as a member
self.sub = self.create_subscription(
Image, "/camera/image_color", self.on_image, 5,
callback_group=self.infer_group)
Third, run two executors on two nodes. One serves the control loop; the other serves everything slow. One law from the docs applies to all three options: "The callback group must be stored throughout execution of the node (e.g. as a class member), or otherwise the executor won't be able to trigger the callbacks." A local variable group silently stops firing. In rclpy, note that Python threads share the interpreter lock. Pure Python compute still serializes. The split pays off when the heavy work runs in C extensions, on the GPU, or in another process. That last point is practice, not a doc quote.
The prevention. Decide the executor layout when you design the node. Do not wait for the first latency spike. Keep every control-path callback small enough to finish inside one control period. Store every callback group as a member. Re-measure with topic statistics after the change. The message_period standard deviation is your before and after.
Family three: silent staleness, QoS and transforms
The QoS half. A publisher and a subscription that disagree on reliability never connect, and nothing errors. The QoS concept page prints the rule as a table. A Best effort publisher with a Reliable subscription is marked No, incompatible. The page also states: "if different profiles are used, it is possible that they will be incompatible, preventing the delivery of messages." The trap direction is the common one. Camera and sensor drivers ship the sensor data profile, which the docs describe as using "best effort reliability and a smaller queue size". In the rmw headers that profile is KEEP_LAST, depth 5, BEST_EFFORT. Your subscription defaults to the reliable profile with "a queue size of 10". Result: zero messages, no exception, and a CLI warning as the only clue: WARNING: topic [...] does not appear to be published yet.
The fix. Make both ends state the same profile, explicitly. Then check the pairing from the shell. The verbose topic info flag prints, per its own help text, the "QoS Profile of the publishers and subscribers" on a topic:
ros2 topic info -v /camera/image_color
Match what you see. If the publisher offers best effort, take best effort. Use SensorDataQoS on the subscriber side, or set reliability to match. While editing profiles you may meet rclpy's own guard: History set to KEEP_LAST without a depth setting. A QoSProfile with KEEP_LAST history and no depth raises InvalidQoSProfileException at construction. Size depth for the worst burst you intend to survive while the executor is busy. With family two fixed, depth 5 to 10 covers a camera spike.
The tf half. Transforms go stale for different reasons than images, and tf2 says which. The MessageFilter drop line, Message Filter dropping message: frame '...' at time ... for reason '...', carries one of four reason strings. the timestamp on the message is earlier than all the data in the transform cache says the sensor stamp predates the whole buffer. Check clock offsets between the machines, or stamping at capture versus at publish. did not find a valid transform, this usually happens at startup ... is the warm-up race between the first frames and the first transforms. It self-corrects. A growing queue size on the filter absorbs it. discarding message because the queue is full is overload. The filter is dropping because nobody drains it fast enough. That points back at family two. The extrapolation exceptions are buffer bounds, in three shapes. Into the future: you asked for newer than the newest transform. Into the past: older than the oldest, so a clock jump or replay. And the single-instant case, which names the only time in the buffer. Note the print shape. The future and past strings carry two spaces after the internal period. If you grep your own logs for them with one space, you will find nothing and conclude the error never fired.
The tf fix is sequencing, not retries. Ensure the transform publisher runs faster than your lookup rate. Or look up a stamp slightly older than now rather than the newest frame. Let a MessageFilter with a real queue size do the waiting instead of polling in the callback. The prevention: synchronize clocks on every host in the loop, with chrony or an equivalent. Set use_sim_time consistently. Alert on the drop reason strings instead of on latency alone. The reason names the family for you.
When the call does not come back: timeouts and holds
A slow call that misses its budget is a control decision, and a real ROS 2 policy runtime prints the decision. PolicyBridge-ROS2, validated on ROS 2 Humble with "204 tests passed in the recorded ROS 2 Humble validation", defines named termination reasons. policy_inference_timeout aborts the step, holds, and ignores the late result. stale_observation holds the latest valid joint state. image_timeout reports "No valid image arrived in time; hold requested". observation_sync_timeout reports that fresh streams did not form a new pair. Its default per-call limit is inference_timeout_seconds at 1.0. The image and pair timeouts also default to 1.0. The safety edge is stated in one line. If no valid state exists to hold, the runtime reports safe_stop_unavailable_no_valid_state and "never fabricates a zero target".
That is the whole shape. Timeout. Hold on the last valid state. Drop the late result. Keep the reason for the log. The full decision order for a robot loop, hold versus halt versus replay, is its own problem. The websocket robot loop guide takes it step by step. One rule matters here: never widen the timeout to make the error go away. If 1.0 second is not enough, the fix is in one of the three families above, not in the constant.
Prevention: the checklist
- Warm the model in node startup, before the executor serves. Keep the pass in the path across restarts.
- Time only after warm-up. A benchmark that includes construction measures construction.
- Pin Jetson clocks for measurement runs:
sudo nvpmodel -m 0, thensudo /usr/bin/jetson_clocks. Do not ship prolonged heavy work in MAXN. - Choose the executor layout deliberately. Hand inference to its own thread or process, or split callback groups. Store every group as a class member.
- Match QoS profiles at both ends. State them explicitly. Check pairings with
ros2 topic info -v. - Size queue depth for the burst you must survive, not the average rate.
- Synchronize clocks on every host in the loop. Keep
use_sim_timeconsistent. - Give every timeout a named hold behavior. Never fabricate a state to fill a gap.
- Run with Topic Statistics on in integration, so regressions show as numbers, not vibes.
A hosted lane for the same loop
Running the policy on robot hardware is one shape. Another is a hosted action route. One call serves one action step. Camera frames, instruction, and state go in. An action chunk comes back. No long-lived socket needs keeping alive. The pi 0.5 model page describes the family. As of October 27 2026 the robot models were not on the public list. The models index shows the current catalog. When the call is that small, the loop's timeout and hold rules above still apply unchanged.
Common questions
Why is the first inference slow and the rest fast?
Warm-up, and it is printed behavior, not a defect. cuDNN benchmarks convolution algorithms on first use. CUDA graph capture happens on the first calls through the graph. TensorRT builds an engine for a new deployment configuration before it can run. Run warm-up calls at node startup with real tensor shapes, then measure.
My subscription stops firing while inference runs. Why?
Your node almost certainly spins a single-threaded executor. Every callback lives in the default callback group, which allows only one callback at a time. The inference callback blocks the rest. Messages wait in the middleware, not in a queue inside your node. Move the heavy work off the callback, or split callback groups under a MultiThreadedExecutor. Store the groups as class members.
The topic exists but my subscriber gets nothing, and there is no error. What is that?
The classic silent QoS mismatch. A best effort publisher against a reliable subscription is an incompatible pair. No connection is made. No message is ever delivered. The only hint is the CLI line WARNING: topic [...] does not appear to be published yet. Check both ends with ros2 topic info -v. Match the reliability setting.
What does the Message Filter dropping line mean in the first seconds after startup?
Usually the startup race. Transforms have not arrived yet for the frames in your messages. The filter drops with did not find a valid transform, this usually happens at startup .... Give the filter a queue and let it pass. If it drops with the queue-full reason instead, your loop is too slow to drain it. That is family two, not a tf problem.
The extrapolation error fired once and never again. Do I raise a timeout?
No. It means a lookup asked for a time outside the transform buffer. Newer than the newest is the future case. Older than the oldest is the past case. The third shape means the buffer held a single instant. Fix the sequencing: publish transforms faster than you look them up, look up a slightly older stamp, or let a MessageFilter do the waiting. The error names which bound you crossed.
How do I find where the time actually goes?
Turn on Topic Statistics and read /statistics. message_age splits arrival staleness from processing. message_period shows delivery gaps. The data types give you the maximum, not just the average. Pair it with ros2 topic hz on the source topic. Time the model itself only after warm-up. Two of those three numbers will point at one family.
Where this leaves you
Measure first. Read the string. Fix the family. Keep the hold rules for whatever still misses its budget. Three sibling guides go deeper on the neighbors of this problem. What a control rate buys you, and what 10 Hz means for a policy, is in the inference frequency guide. The policy server explainer covers the serving pattern behind most ROS 2 policy nodes. One real model end to end, warm-up included, is the MolmoAct2 guide. For the catalog there is the models index; for cost questions, the one place is the pricing page, and signup is the way in.
Last verified: 2026-10-27