ros2_tracing

repository·rolling·Indexed 42 days ago

https://github.com/ros2/ros2_tracing

Low-overhead tracing instrumentation for core ROS 2 packages on Linux using the LTTng tracer. It enables developers to analyze system execution, debug performance, and understand message flows. Features include the `ros2 trace` CLI, launch file integration via `tracetools_launch`, snapshot mode for reduced disk I/O, and dual session tracing to capture both initialization and runtime events. Supports RMWs including rmw_connextdds, rmw_cyclonedds_cpp, rmw_fastrtps_cpp, rmw_fastrtps_dynamic_cpp, and rmw_zenoh_cpp.

Tokens
11.7K
Snippets
16
Records
42
Agent score
55%

What's inside ros2_tracing

  1. Overview of ros2_tracing

    rolling

    ros2_tracing provides tracing instrumentation for core ROS 2 packages using the LTTng tracer. It is currently only supported on Linux.

    Key features include:

    • Instrumentation: Tracepoints within core ROS 2 packages.
    • Configuration: Tools to manage tracing via the ros2 trace CLI command or a dedicated launch file action.
    • Supported RMWs: rmw_connextdds, rmw_cyclonedds_cpp, rmw_fastrtps_cpp, rmw_fastrtps_dynamic_cpp, and rmw_zenoh_cpp.
  2. Overview of ros2_tracing

    rolling

    ros2_tracing is a collection of flexible tracing tools and multipurpose instrumentation designed for the ROS 2 framework. It enables the recording of run-time data for both system-level events (e.g., process scheduling, I/O) and user-defined ROS 2 events (e.g., message arrival, timer firing, callback execution).

    Key capabilities include:

    • Instrumentation: Capturing lifecycle events for publishers, subscribers, services, clients, and executors.
    • Analysis: Processing trace data to derive metrics such as callback duration, message age, message size, and memory usage.
    • Integration: Aiming for seamless integration with the ROS 2 launch system and ros2cli for easier session setup and recording.
  3. Overview of ros2_tracing packages

    rolling

    The ros2_tracing ecosystem consists of several specialized packages:

    • lttngpy: Python bindings for liblttng-ctl.
    • ros2trace: A ros2cli extension for enabling tracing via the command line.
    • tracetools: The core library used to instrument ROS packages (Quality Level 1).
    • tracetools_launch: Tools to enable tracing via ROS 2 launch files.
    • tracetools_read: Tools for reading and analyzing trace files.
    • tracetools_trace: Tools to enable tracing.
    • tracetools_test: Testing utilities for tracing components.
  4. Overview of ROS 2 instrumentation layers and points

    rolling

    ROS 2 instrumentation is organized into three primary layers: rclcpp, rcl, and rmw. Each layer provides specific instrumentation points that allow for tracing different aspects of the ROS 2 execution flow.

    • rclcpp: High-level C++ API instrumentation (e.g., rclcpp_publish, rclcpp_executor_execute, callback_start).
    • rcl: Mid-level C API instrumentation (e.g., rcl_node_init, rcl_publisher_init, rcl_timer_init).
    • rmw: Low-level Middleware API instrumentation (e.g., rmw_publisher_init, rmw_send_request).

    Instrumentation points are categorized into:

    • Initialization events: One-time events (e.g., creating a publisher) used to collect state information and minimize runtime overhead.
    • Runtime events: Events that occur repeatedly during execution (e.g., message publishing, callback execution).
    | Layer    | Instrumentation Point                | Ref |
    |   :--:   | :--                                  | :-- |
    | `rclcpp` | `rclcpp_subscription_init`           | [*Subscription creation*](#subscription-creation) |
    |          | `rclcpp_subscription_callback_added` | [*Subscription creation*](#subscription-creation) |
    |          | `rclcpp_publish`                     | [*Message publishing*](#message-publishing) |
    |          | `rclcpp_intra_publish`               | [*Intra-process message publishing*](#intra-process-message-publishing) |
    |          | `rclcpp_take`                        | [*Subscription callbacks*](#subscription-callbacks) |
    |          | `rclcpp_service_callback_added`       | [*Service creation*](#service-creation) |
    |          | `rclcpp_timer_callback_added`        | [*Timer creation*](#timer-creation) |
    |          | `rclcpp_timer_link_node`             | [*Timer creation*](#timer-creation) |
    |          | `rclcpp_callback_register`           | [*Subscription creation*](#subscription-creation), [*Service creation*](#service-creation), [*Timer creation*](#timer-creation) |
    |          | `callback_start`                     | [*Subscription callbacks*](#subscription-callbacks), [*Service callbacks*](#service-callbacks), [*Client request/response*](#client-requestresponse), [*Timer callbacks*](#timer-callbacks) |
    |          | `callback_end`                       | [*Subscription callbacks*](#subscription-callbacks), [*Service callbacks*](#service-callbacks), [*Client request/response*](#client-requestresponse), [*Timer callbacks*](#timer-callbacks) |
    |          | `rclcpp_construct_ring_buffer`       | [*IntraProcessBuffer creation*](#intraprocessbuffer-creation) |
    |          | `rclcpp_buffer_to_ipb`               | [*IntraProcessBuffer creation*](#intraprocessbuffer-creation) |
    |          | `rclcpp_ipb_to_subscription`         | [*IntraProcessBuffer creation*](#intraprocessbuffer-creation) |
    |          | `rclcpp_ring_buffer_enqueue`        | [*Intra-process message publishing*](#intra-process-message-publishing) |
    |          | `rclcpp_ring_buffer_dequeue`         | [*Intra-process callback*](#intra-process-callback) |
    |          | `rclcpp_ring_buffer_clear`           | [*IntraProcessBuffer creation*](#intraprocessbuffer-creation) |
    |          | `rclcpp_executor_get_next_ready`     | [*Executors*](#executors) |
    |          | `rclcpp_executor_wait_for_work`      | [*Executors*](#executors) |
    |          | `rclcpp_executor_execute`            | [*Executors*](#executors), [*Timer callbacks*](#timer-callbacks), [*Subscription callbacks*](#subscription-callbacks) |
    | `rcl`    | `rcl_init`                           | [*Process creation*](#process-creation) |
    |          | `rcl_node_init`                      | [*Node/component creation*](#nodecomponent-creation) |
    |          | `rcl_publisher_init`                 | [*Publisher creation*](#publisher-creation) |
    |          | `rcl_subscription_init`              | [*Subscription creation*](#subscription-creation) |
    |          | `rcl_publish`                        | [*Message publishing*](#message-publishing) |
    |          | `rcl_take`                           | [*Subscription callbacks*](#subscription-callbacks) |
    |          | `rcl_client_init`                    | [*Client creation*](#client-creation) |
    |          | `rcl_service_init`                   | [*Service creation*](#service-creation) |
    |          | `rcl_timer_init`                     | [*Timer creation*](#timer-creation) |
    |          | `rcl_lifecycle_state_machine_init`   | [*State machine creation*](#state-machine-creation) |
    |          | `rcl_lifecycle_transition`           | [*State machine transitions*](#state-machine-transitions) |
    | `rmw`    | `rmw_publisher_init`                 | [*Publisher creation*](#publisher-creation) |
    |          | `rmw_subscription_init`              | [*Subscription creation*](#subscription-creation) |
    |          | `rmw_publish`                        | [*Message publishing*](#message-publishing) |
    |          | `rmw_take`                           | [*Subscription callbacks*](#subscription-callbacks) |
    |          | `rmw_client_init`                    | [*Client creation*](#client-creation) |
    |          | `rmw_take_request`                   | [*Service callbacks*](#service-callbacks) |
    |          | `rmw_send_response`                  | [*Service callbacks*](#service-callbacks) |
    |          | `rmw_send_request`                   | [*Client request/response*](#client-requestresponse) |
    |          | `rmw_take_response`                  | [*Client request/response*](#client-requestresponse) |
  5. What is tracing in ROS 2?

    rolling

    Tracing in the context of ROS 2 refers to the ability to record run-time data from a system. This includes:

    1. System Data: Low-level events like when a process is being scheduled or when I/O occurs.
    2. User-Defined Data: High-level ROS 2 framework events, such as:
      • When messages arrive.
      • When timers fire.
      • When specific callbacks are being executed.
  6. How ROS 2 Client/Service requests are traced

    rolling

    The tracing instrumentation for ROS 2 Client/Service requests tracks the lifecycle of a request from the initial call through the RMW (ROS Middleware) layer to the execution of the callback.

    Key tracepoints include:

    • rcl_send_request: Triggered when a request is sent via rcl.
    • rmw_send_request: Triggered when the request passes through the RMW layer.
    • rmw_take_response: Triggered when the RMW layer receives a response, including the sequence_number and source_timestamp.
    • callback_start and callback_end: Triggered when the client executes the user-provided callback in response to the received message.
  7. Requirements for ROS 2 trace analysis and visualization

    rolling

    Trace analysis tools in ros2_tracing are designed to process raw trace data into meaningful metrics. Useful analyses include:

    • Timing Metrics:
      • Callback duration.
      • Time between callbacks (e.g., between a callback end and the next start).
      • Message age (the difference between processing time and the message timestamp).
    • Resource Metrics:
      • Message size.
      • Memory usage.
      • Execution time/proportion across a process's nodes or components.
    • Scheduling & Interruptions:
      • Scheduling events occurring during a callback.
      • Delay between a thread becoming ready and its actual scheduling.
      • CPU cycles.

    These analyses should support statistical outputs like mean and standard deviation where applicable.

  8. Requirements for ROS 2 instrumentation

    rolling

    To be effective, ROS 2 instrumentation must capture specific metadata to allow for correlation and analysis.

    Core Instrumentation Requirements

    Entity Creation

    When creating publishers, subscribers, services, or clients, the instrumentation must:

    • Keep appropriate references to correlate with other tracepoints related to the same instance.
    • Include the effective topic name (including namespace and after remapping) for publishers and subscribers.

    Message Lifecycle

    When publishing a message, the trace must:

    • Link the event to its specific publisher.
    • Include message identifiers (e.g., pointers or unique IDs) to track the message through ROS abstraction layers and DDS, enabling the linking of a published message to its corresponding received message.

    Callbacks and Timers

    • Callbacks (Subscription, Service, Client, Timer): Must include the callback function symbol whenever possible, link instances to specific messages/requests, and record execution start and end times.
    • Timers: Must include information about the timer period.
    • Executors: Must include information about spin cycles and periods.

    User Code

    • Provide generic tracepoints that allow users to instrument their own custom code.
  9. Tracepoints for Client Operations

    rolling

    Tracing for clients tracks the initialization of the client and the lifecycle of requests sent to services.

    Client Creation

    Links the rcl_client_t and rmw_client_t handles to the node and the client GID.

    • TP(rmw_client_init, rmw_client_t *, gid)
    • TP(rcl_client_init, rcl_client_t *, rcl_node_t *, rmw_client_t *, service_name)

    Client Request/Response

    Captures the sequence of sending a request and receiving a response, allowing for the correlation of request sequence numbers with their corresponding responses.

    sequenceDiagram
        participant node
        participant Client
        participant rclcpp
        participant rcl
        participant rmw
        participant tracetools
    
    Note over rmw: (implementation)
    
    node->>rclcpp: create_client(service_name, options)
        Note over rclcpp: (...)
        rclcpp->>Client: Client(service_name, options)
        Note over Client: allocates a rcl_client_t handle
        Client->>rcl: rcl_client_init(out rcl_client_t *, rcl_node_t *, service_name, options)
        Note over rcl: validates and processes rcl_client_t handle
        rcl->>rmw: rmw_create_client(rmw_node_t *, service_name, qos_options): rmw_client_t
        Note over rmw: creates rmw_client_t handle
        rmw-->>tracetools: TP(rmw_client_init, rmw_client_t *, gid)
        rcl-->>tracetools: TP(rcl_client_init, rcl_client_t *, rcl_node_t *, rmw_client_t *, service_name)
  10. Identify LTTng component repositories

    rolling

    LTTng is split into several specialized repositories. Depending on your tracing needs, you may interact with different components:

    • lttng-tools: Components used to control LTTng tracing.
    • lttng-ust: Userspace instrumentation and tracing.
    • lttng-modules: Linux kernel instrumentation and tracing.
  11. How subscription callbacks are traced

    rolling

    When an executor handles a subscription, it follows a sequence of taking a message from the middleware and dispatching it to the user-defined callback.

    Tracing captures the following flow:

    1. rclcpp_executor_execute: Triggered when the executor starts executing the subscription (rcl_subscription_t *).
    2. rmw_take: Triggered by the middleware when rmw_take_with_info is called (captures rmw_subscription_t *, msg *, source_timestamp, and taken status).
    3. rcl_take: Triggered by rcl when the message is taken.
    4. rclcpp_take: Triggered by rclcpp when the message is processed.
    5. If message is taken:
      • callback_start: Triggered when rclcpp::AnySubscriptionCallback::dispatch() is called (captures rclcpp::AnySubscriptionCallback * and is_intra_process flag).
      • callback_end: Triggered when the callback function finishes (captures rclcpp::AnySubscriptionCallback *).

    Key Traced Information:

    • Link to the handle(s) of the subscription being executed.
    • The message being taken.
    • The source timestamp of the message (to link publication to consumption).
    • Link to the callback object being dispatched, including start/end timestamps.
    • Whether the callback dispatching is for intra-process or not.
  12. How subscription creation is traced

    rolling

    When a node creates a subscription via rclcpp::create_publisher() (which leads to an rclcpp::Subscription), several tracepoints (TP) are triggered across the rclcpp, rcl, and rmw layers.

    Tracing captures the following critical links:

    • The connection between rcl_subscription_t and rmw_subscription_t handles and the rclcpp::Subscription object.
    • The connection between rcl_subscription_t and rclcpp::SubscriptionIntraProcess objects (if intra-process is enabled).
    • The link to callback objects, including the callback function symbol string.
    • The link to the underlying DDS object's GID.
    • The link to the corresponding node handle.
    • The Topic name and some QoS information.

    Tracepoint Sequence:

    1. rmw_subscription_init: Triggered by rmw when creating the rmw_subscription_t handle.
    2. rcl_subscription_init: Triggered by rcl after populating the rcl_subscription_t handle.
    3. If intra-process is enabled:
      • rclcpp_subscription_callback_added: Links rcl_subscription_t to rclcpp::AnySubscriptionCallback *.
      • rclcpp_subscription_init: Links rcl_subscription_t to rclcpp::SubscriptionIntraProcess *.
      • rclcpp_callback_register: Links rclcpp::AnySubscriptionCallback * to its symbol.
    4. rclcpp_subscription_init: Links rcl_subscription_t to the Subscription object.
    5. rclcpp_subscription_callback_added: Links rcl_subscription_t to rclcpp::AnySubscriptionCallback *.
    6. rclcpp_callback_register: Links rclcpp::AnySubscriptionCallback * to its symbol.