ROS Resources: Documentation | Support | Discussion Forum | Index | Service Status | ros @ Robotics Stack Exchange
Ask Your Question
1

How to run code profiler for your ROS2 nodes ?

asked 2021-08-31 11:03:31 -0500

updated 2021-08-31 11:21:38 -0500

I would like to optimize my application. In order to do that I need determine time consumed by each function call.

How can I do that in ROS2 ?

edit retag flag offensive close merge delete

1 Answer

Sort by ยป oldest newest most voted
3

answered 2021-08-31 11:21:04 -0500

updated 2021-08-31 11:24:52 -0500

Use valgrind's tool named callgrind. Add the following prefix to your node in launch file.

planner_server_node = Node(
        package='planning',
        executable='planner_server',
        name='planner_server_rclcpp_node',
        namespace='',
        output='screen',
        prefix=['valgrind --tool=callgrind --dump-instr=yes -v --instr-atstart=no'],
        parameters=[params],
    )

Note that starting a node in valgrind can slow down the program significantly. Therefore the above prefix does not start callgrind right after you launch. It will listen for a command from you in order to start logging information. To make callgrind to logging, in a seperate terminal do ;

 callgrind_control -i on

you should be able to see something like;

PID 237154: /home/ ...... 
  OK.

indicating the success of start of logging. Now Let your program run for a while. After you think you have "captured" enough function calls, do following to dump log file for analysis.

callgrind_control -d

A file with callgrind.out.* regex should be dumped to your working directory. For me this was the colcon_ws directory.

Now you can visually see the analysis with gui tool kcachegrind;

kcachegrind callgrind.out.*

image description

At upper left side select ELF object, locate your executable or library and click. You can now see each function call and their execution costs from ELF object that you selected. Try to determine the function that takes unexpected amount of time and see whether there is room for optimization.

For further information on how to interpret the results with kcachegrind, see here

edit flag offensive delete link more

Comments

Following your instructions by inserting the code to the call of rgbd_odometry in rtabmap_ros actually crashes the program. Is this because it slows the process down so very much that rtabmap stops working properly? I wanted to find out which function in rgbd_odometry which is the "heaviest" node in rtabmap is the one consuming most of the computing power ...

TurBot gravatar image TurBot  ( 2022-04-19 09:18:28 -0500 )edit

I am not if the slow process would crash rtabmap, at what command this it crashes ? is there any meaningful error message ?

Fetullah Atas gravatar image Fetullah Atas  ( 2022-04-19 09:25:35 -0500 )edit

Actually ... it doesn't crash explicitly, it's just that it doesn't process the images anymore. I run a Realsense camera and do rtabmap on it's images ... without the valgrind line it works perfectly. In realsense_d400.launch.py I added your line of code (both with a value for namespace and without): ... Node( package='rtabmap_ros', executable='rgbd_odometry', name='rgbd_odometry', namespace='rgbd_odometry', output='screen', prefix=['valgrind --tool=callgrind --callgrind-out-file=/home/user/test.log'], parameters=parameters, remappings=remappings), ... Messages: rtabmapviz-3] [WARN] [1650380692.426253395] [rcl.logging_rosout]: Publisher already registered for provided node name...

TurBot gravatar image TurBot  ( 2022-04-19 10:13:47 -0500 )edit

Second error message: [rtabmap-2] [WARN] [1650380696.160814319] [rtabmap]: rtabmap: Did not receive data since 5 seconds! .... And btw: thanks for your fast reply :)

TurBot gravatar image TurBot  ( 2022-04-19 10:13:59 -0500 )edit

Question Tools

3 followers

Stats

Asked: 2021-08-31 11:03:31 -0500

Seen: 2,612 times

Last updated: Aug 31 '21