Rclcpp: Undefined behavior in subscription_options.hpp

[zhoulaifu]

Undefined behavior is detected by running a unit test from the tf2_ros package with Undefined Behavior Sanitizer (UBSAN, https://www.kernel.org/doc/html/v4.14/dev-tools/ubsan.html). The unit test used here is tf2_ros_test_message_filter from the geometry2 package.

Tested on ros2 eloquent. The error points to /opt/ros/eloquent/include/rclcpp/subscription_options.hpp:79:62: runtime error: reference binding to null pointer of type 'struct allocator'.

Below is the full error message.

root@b49ee72fcb7b:/opt/ros_ws# ./build/tf2_ros/tf2_ros_test_message_filter
[==========] Running 3 tests from 1 test case.
[----------] Global test environment set-up.
[----------] 3 tests from tf2_ros_message_filter
[ RUN      ] tf2_ros_message_filter.construction_and_destruction
[       OK ] tf2_ros_message_filter.construction_and_destruction (20 ms)
[ RUN      ] tf2_ros_message_filter.multiple_frames_and_time_tolerance
/opt/ros/eloquent/include/rclcpp/subscription_options.hpp:79:62: runtime error: reference binding to null pointer of type 'struct allocator'
/usr/include/c++/7/bits/shared_ptr.h:707:42: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/move.h:74:36: runtime error: reference binding to null pointer of type 'struct allocator'
/usr/include/c++/7/bits/shared_ptr.h:691:39: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/shared_ptr.h:344:64: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/shared_ptr_base.h:1295:35: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/shared_ptr_base.h:638:28: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/shared_ptr_base.h:526:39: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/alloc_traits.h:475:4: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/ext/new_allocator.h:136:46: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/ext/new_allocator.h:136:4: runtime error: reference binding to null pointer of type 'const struct allocator'

[INFO] [tf2_ros_message_filter]: filter callback: trigger(0)
[INFO] [tf2_ros_message_filter]: filter callback: trigger(2)
[INFO] [tf2_ros_message_filter]: filter callback: trigger(2)
[INFO] [tf2_ros_message_filter]: filter callback: trigger(4)
[INFO] [tf2_ros_message_filter]: filter callback: trigger(4)
[INFO] [tf2_ros_message_filter]: filter callback: trigger(6)
[       OK ] tf2_ros_message_filter.multiple_frames_and_time_tolerance (6043 ms)
[ RUN      ] tf2_ros_message_filter.failure_reason_string_conversion
[       OK ] tf2_ros_message_filter.failure_reason_string_conversion (0 ms)
[----------] 3 tests from tf2_ros_message_filter (6063 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test case ran. (6063 ms total)
[  PASSED  ] 3 tests.

[zhoulaifu]

Just found out that the same error can be triggered by running tf2_monitor of geometry2, with Undefined Behavior Sanitizer on.

root@f4ceac09462e:/opt/ros_ws# ./build/tf2_ros/tf2_monitor
/opt/ros/eloquent/include/rclcpp/subscription_options.hpp:79:62: runtime error: reference binding to null pointer of type 'struct allocator'
/usr/include/c++/7/bits/shared_ptr.h:707:42: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/move.h:74:36: runtime error: reference binding to null pointer of type 'struct allocator'
/usr/include/c++/7/bits/shared_ptr.h:691:39: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/shared_ptr.h:344:64: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/shared_ptr_base.h:1295:35: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/shared_ptr_base.h:638:28: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/shared_ptr_base.h:526:39: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/bits/alloc_traits.h:475:4: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/ext/new_allocator.h:136:46: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/7/ext/new_allocator.h:136:4: runtime error: reference binding to null pointer of type 'const struct allocator' 

[clalancette]

@zhoulaifu Can you try with rolling or from sources instead of Eloquent? Eloquent is out of support, and we've had more than a year of fixes since then, so these results aren't too helpful.

[zhoulaifu]

On foxy, these are what I got.
Let me know if you need a dockerfile to reproduce the errors.

root@19a4c225d2e4:/opt/ros_ws# ./build/tf2_ros/tf2_ros_test_message_filter
[==========] Running 3 tests from 1 test case.
[----------] Global test environment set-up.
[----------] 3 tests from tf2_ros_message_filter
[ RUN      ] tf2_ros_message_filter.construction_and_destruction
[       OK ] tf2_ros_message_filter.construction_and_destruction (48 ms)
[ RUN      ] tf2_ros_message_filter.multiple_frames_and_time_tolerance
/opt/ros/foxy/include/rclcpp/subscription_options.hpp:104:62: runtime error: reference binding to null pointer of type 'struct allocator'
/usr/include/c++/9/bits/shared_ptr.h:718:42: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/move.h:75:36: runtime error: reference binding to null pointer of type 'struct allocator'
/usr/include/c++/9/bits/shared_ptr.h:702:39: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/shared_ptr.h:359:59: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/shared_ptr_base.h:1344:71: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/shared_ptr_base.h:680:47: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/shared_ptr_base.h:548:39: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/alloc_traits.h:484:4: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/ext/new_allocator.h:147:46: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/ext/new_allocator.h:147:4: runtime error: reference binding to null pointer of type 'const struct allocator'
[INFO] [1612722523.985853300] [tf2_ros_message_filter]: filter callback: trigger(0)
[INFO] [1612722524.984741100] [tf2_ros_message_filter]: filter callback: trigger(1)
[INFO] [1612722525.986539800] [tf2_ros_message_filter]: filter callback: trigger(2)
[INFO] [1612722526.985085800] [tf2_ros_message_filter]: filter callback: trigger(3)
[INFO] [1612722527.984925100] [tf2_ros_message_filter]: filter callback: trigger(4)
[INFO] [1612722528.985593000] [tf2_ros_message_filter]: filter callback: trigger(5)
[INFO] [1612722529.985126000] [tf2_ros_message_filter]: filter callback: trigger(6)
[       OK ] tf2_ros_message_filter.multiple_frames_and_time_tolerance (7029 ms)
[ RUN      ] tf2_ros_message_filter.failure_reason_string_conversion
[       OK ] tf2_ros_message_filter.failure_reason_string_conversion (0 ms)
[----------] 3 tests from tf2_ros_message_filter (7077 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test case ran. (7078 ms total)
[  PASSED  ] 3 tests.


root@19a4c225d2e4:/opt/ros_ws# ./build/tf2_ros/tf2_monitor
/opt/ros/foxy/include/rclcpp/subscription_options.hpp:104:62: runtime error: reference binding to null pointer of type 'struct allocator'
/usr/include/c++/9/bits/shared_ptr.h:718:42: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/move.h:75:36: runtime error: reference binding to null pointer of type 'struct allocator'
/usr/include/c++/9/bits/shared_ptr.h:702:39: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/shared_ptr.h:359:59: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/shared_ptr_base.h:1344:71: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/shared_ptr_base.h:680:47: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/shared_ptr_base.h:548:39: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/bits/alloc_traits.h:484:4: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/ext/new_allocator.h:147:46: runtime error: reference binding to null pointer of type 'struct type'
/usr/include/c++/9/ext/new_allocator.h:147:4: runtime error: reference binding to null pointer of type 'const struct allocator'
Gathering data on all frames for 10 seconds...

[fujitatomoya]

could we have a complete procedure to reproduce this issue? i want to check if this happens with source build.

[zhoulaifu]

You can use this Dockerfile here to reproduce the environmental setting. In the docker container, you have a rox:foxy system with geometry2 compiled with the Undefined Behavior Sanitizer (UBSan). Then run the two binaries from the tf2_ros package to reproduce the bugs:

First, run ${ROS_WS}/build/tf2_ros/tf2_ros_test_message_filter
Then, run ${ROS_WS}/build/tf2_ros/tf2_monitor

i hope it helps.

[fujitatomoya]

I cannot reproduce this issue with source build https://github.com/ros2/ros2/commit/9552559b4d811f4cc613d5c65e3d560b18579b2c.

colcon_ws# VERBOSE=1 CXX="g++" CXXFLAGS="--coverage -g -fsanitize=undefined" colcon build --event-handlers console_direct+ --packages-select test_tf2
colcon_ws# ./build/tf2_ros/tf2_ros_test_message_filter
[==========] Running 3 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 3 tests from tf2_ros_message_filter
[ RUN      ] tf2_ros_message_filter.construction_and_destruction
[       OK ] tf2_ros_message_filter.construction_and_destruction (11 ms)
[ RUN      ] tf2_ros_message_filter.multiple_frames_and_time_tolerance
[INFO] [1612786758.938836787] [tf2_ros_message_filter]: filter callback: trigger(1)
[INFO] [1612786759.938814515] [tf2_ros_message_filter]: filter callback: trigger(2)
[INFO] [1612786760.938823356] [tf2_ros_message_filter]: filter callback: trigger(3)
[INFO] [1612786761.938804123] [tf2_ros_message_filter]: filter callback: trigger(4)
[INFO] [1612786762.938330639] [tf2_ros_message_filter]: filter callback: trigger(5)
[INFO] [1612786763.938811528] [tf2_ros_message_filter]: filter callback: trigger(6)
[       OK ] tf2_ros_message_filter.multiple_frames_and_time_tolerance (6012 ms)
[ RUN      ] tf2_ros_message_filter.failure_reason_string_conversion
[       OK ] tf2_ros_message_filter.failure_reason_string_conversion (0 ms)
[----------] 3 tests from tf2_ros_message_filter (6023 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test suite ran. (6023 ms total)
[  PASSED  ] 3 tests.
colcon_ws# ./build/tf2_ros/tf2_monitor
Gathering data on all frames for 10 seconds...



RESULTS: for all Frames

Frames:

All Broadcasters:



RESULTS: for all Frames
<...snip>

[zhoulaifu]

That is good to know. Thanks.

BTW, which ROS version do you refer to by "source build"? Does a bug reported on ROS foxy remain relevant?

[clalancette]

BTW, which ROS version do you refer to by "source build"?

All of the development for ROS 2 is done on the "master" or "ros2" branches of the repositories. After we fix whatever issues are happening, we then determine if we can backport it to still supported distributions (which are Foxy and Dashing at the moment).

You can build from source by following the instructions here: https://index.ros.org/doc/ros2/Installation/Rolling/Linux-Development-Setup/

Does a bug reported on ROS foxy remain relevant?

Yes, Foxy bug reports are still relevant. It is best to see first if it is fixed on the latest sources. If that is fixed, then checking if it is fixed on Foxy is a good second step (since we sometimes forget to backport things to Foxy).

In this case, since @fujitatomoya says it is fixed on master, I'm going to change the title to reflect that it is still a problem on Foxy. @zhoulaifu if you'd like to look into backporting the fix to Foxy, that would be welcome.

[zhoulaifu]

@fujitatomoya Perhaps you are aware of this: above, you were compiling with --packages-select test_tf2, but later ran package in the command line but then ran a unit test in tf2_ros, tf2_ros/tf2_ros_test_message_filter. A bit strange. Maybe double check you indeed had compiled tf2_ros with ASan before doing the test.

[zhoulaifu]

Besides, @fujitatomoya . FYI, I just checked that the errors remain in ros:rolling, but I have not tried with the upstream branch.

[clalancette]

This actually looks similar to https://github.com/ros2/rclcpp/issues/849 , though this is for the subscription_options instead of the publisher_options.

[fujitatomoya]

A bit strange. Maybe double check you indeed had compiled tf2_ros with ASan before doing the test.

yeah, my bad 😢 it's mixed up with https://github.com/ros2/rclcpp/issues/1545. but i reconfirmed that the problem is gone with master.

colcon_ws# VERBOSE=1 CXX="g++" CXXFLAGS="--coverage -g -fsanitize=address" colcon build --event-handlers console_direct+ --packages-select tf2_ros

colcon_ws# ./build/tf2_ros/tf2_ros_test_message_filter
[==========] Running 3 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 3 tests from tf2_ros_message_filter
[ RUN      ] tf2_ros_message_filter.construction_and_destruction
[       OK ] tf2_ros_message_filter.construction_and_destruction (18 ms)
[ RUN      ] tf2_ros_message_filter.multiple_frames_and_time_tolerance
[INFO] [1612825180.590877307] [tf2_ros_message_filter]: filter callback: trigger(1)
[INFO] [1612825181.590406434] [tf2_ros_message_filter]: filter callback: trigger(2)
[INFO] [1612825182.590851689] [tf2_ros_message_filter]: filter callback: trigger(3)
[INFO] [1612825183.590830722] [tf2_ros_message_filter]: filter callback: trigger(4)
[INFO] [1612825184.590407055] [tf2_ros_message_filter]: filter callback: trigger(5)
[INFO] [1612825185.590855275] [tf2_ros_message_filter]: filter callback: trigger(6)
[       OK ] tf2_ros_message_filter.multiple_frames_and_time_tolerance (6016 ms)
[ RUN      ] tf2_ros_message_filter.failure_reason_string_conversion
[       OK ] tf2_ros_message_filter.failure_reason_string_conversion (0 ms)
[----------] 3 tests from tf2_ros_message_filter (6034 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test suite ran. (6034 ms total)
[  PASSED  ] 3 tests.

colcon_ws# ./build/tf2_ros/tf2_monitor
Gathering data on all frames for 10 seconds...



RESULTS: for all Frames

Frames:

All Broadcasters:

i've done quick code scan, i am not sure which commit fixes this issue yet.

[fujitatomoya]

I tried to use https://github.com/ros2/ros2/tree/foxy, but i was unable to reproduce the issue with my environment.

[fujitatomoya]

https://github.com/ros2/rclcpp/pull/1324 is not really related to this issue, though it will remove the runtime error: reference binding to null pointer of type because the error code will be removed. but it is originally introduced for different bug for allocate/de-allocate.

i believe that the problem here is not to use get_allocator() in to_rcl_subscription_options. the following could fix the runtime problem and make it consistent with to_rcl_publisher_options.

diff --git a/rclcpp/include/rclcpp/subscription_options.hpp b/rclcpp/include/rclcpp/subscription_options.hpp
index c3d5096..ade1bb8 100644
--- a/rclcpp/include/rclcpp/subscription_options.hpp
+++ b/rclcpp/include/rclcpp/subscription_options.hpp
@@ -104,7 +104,7 @@ struct SubscriptionOptionsWithAllocator : public SubscriptionOptionsBase
     rcl_subscription_options_t result = rcl_subscription_get_default_options();
     using AllocatorTraits = std::allocator_traits<Allocator>;
     using MessageAllocatorT = typename AllocatorTraits::template rebind_alloc<MessageT>;
-    auto message_alloc = std::make_shared<MessageAllocatorT>(*allocator.get());
+    auto message_alloc = std::make_shared<MessageAllocatorT>(*this->get_allocator().get());
     result.allocator = allocator::get_rcl_allocator<MessageT>(*message_alloc);
     result.qos = qos.get_rmw_qos_profile();
     result.rmw_subscription_options.ignore_local_publications = this->ignore_local_publications;

[fujitatomoya]

@zhoulaifu it would be really appreciated if you had a chance to try https://github.com/ros2/rclcpp/pull/1547 to see if the problem is fixed on your environment.

[zhoulaifu]

@fujitatomoya you said you were not able to reproduce the bug on Foxy. That looks like a bigger issue to me. Above, I reported the errors with this dockerfile. Do you think there is anything wrong with my dockerfile?

I will check #1547

[zhoulaifu]

BTW, @fujitatomoya I suppose #1547 is on master but not on rolling yet, right? Is there a pre-built docker image corresponding to the master branch of ros2? So far the best I got is ros:rolling, but as @clalancette mentioned, ros:rolling is still behind master.

[fujitatomoya]

@zhoulaifu thanks for quick response!

along with https://index.ros.org/doc/ros2/Installation/Rolling/Linux-Development-Setup/, https://github.com/ros2/rclcpp/pull/1547 can be patched. (as far as i know, this procedure pulls repo file from master branch, that is the same source build environment that i have)

Do you think there is anything wrong with my dockerfile?

No, i don't think so. i use Ubuntu18 host system for development and docker images ubuntu20.04, probably kernel config or something in the host system.

[fujitatomoya]

foxy backport: https://github.com/ros2/rclcpp/pull/1548

[fujitatomoya]

@zhoulaifu Just FYI, here is the foxy based fix: https://github.com/ros2/rclcpp/pull/1548

[clalancette]

@fujitatomoya Now that the fix has been merged both into master and foxy, can we close out this issue?

[zhoulaifu]

Is the prebuilt Docker image ros:foxy updated? Just tried with that one and got memory leaks. Maybe I misuse something, or maybe it is no more an rclcpp issue? tf2_ros_tesT_message_filter passes but triggers memory leaks; tf2_monitor now works. I am testing with the same dockerfile.

oot@e4c9a080ebb4:/opt/ros_ws# ./build/tf2_ros/tf2_ros_test_message_filter
[==========] Running 3 tests from 1 test case.
[----------] Global test environment set-up.
[----------] 3 tests from tf2_ros_message_filter
[ RUN      ] tf2_ros_message_filter.construction_and_destruction
[       OK ] tf2_ros_message_filter.construction_and_destruction (73 ms)
[ RUN      ] tf2_ros_message_filter.multiple_frames_and_time_tolerance
[INFO] [1613055867.257212200] [tf2_ros_message_filter]: filter callback: trigger(0)
[INFO] [1613055868.254499900] [tf2_ros_message_filter]: filter callback: trigger(1)
[INFO] [1613055869.255782300] [tf2_ros_message_filter]: filter callback: trigger(2)
[INFO] [1613055870.257558500] [tf2_ros_message_filter]: filter callback: trigger(3)
[INFO] [1613055871.254597000] [tf2_ros_message_filter]: filter callback: trigger(4)
[INFO] [1613055872.259758300] [tf2_ros_message_filter]: filter callback: trigger(5)
[INFO] [1613055873.255602300] [tf2_ros_message_filter]: filter callback: trigger(6)
[       OK ] tf2_ros_message_filter.multiple_frames_and_time_tolerance (7069 ms)
[ RUN      ] tf2_ros_message_filter.failure_reason_string_conversion
[       OK ] tf2_ros_message_filter.failure_reason_string_conversion (0 ms)
[----------] 3 tests from tf2_ros_message_filter (7143 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test case ran. (7144 ms total)
[  PASSED  ] 3 tests.

=================================================================
==32==ERROR: LeakSanitizer: detected memory leaks

Direct leak of 56 byte(s) in 1 object(s) allocated from:
    #0 0x7fcd3ac86bc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
    #1 0x7fcd3a8eb892  (/opt/ros/foxy/lib/librcl.so+0x15892)
    #2 0x7fcd3aa03d0a in rclcpp::graph_listener::GraphListener::GraphListener(std::shared_ptr<rclcpp::Context>) (/opt/ros/foxy/lib/librclcpp.so+0xe2d0a)
    #3 0x7fcd3aa2781b in std::shared_ptr<rclcpp::graph_listener::GraphListener> rclcpp::Context::get_sub_context<rclcpp::graph_listener::GraphListener, std::shared_ptr<rclcpp::Context> >(std::shared_ptr<rclcpp::Context>&&) (/opt/ros/foxy/lib/librclcpp.so+0x10681b)

Indirect leak of 64 byte(s) in 1 object(s) allocated from:
    #0 0x7fcd3ac88947 in operator new(unsigned long) (/lib/x86_64-linux-gnu/libasan.so.5+0x10f947)
    #1 0x7fcd3752eaf7 in rmw_fastrtps_shared_cpp::__rmw_create_guard_condition(char const*) (/opt/ros/foxy/lib/librmw_fastrtps_shared_cpp.so+0x2caf7)

Indirect leak of 24 byte(s) in 1 object(s) allocated from:
    #0 0x7fcd3ac88947 in operator new(unsigned long) (/lib/x86_64-linux-gnu/libasan.so.5+0x10f947)
    #1 0x7fcd3752eae7 in rmw_fastrtps_shared_cpp::__rmw_create_guard_condition(char const*) (/opt/ros/foxy/lib/librmw_fastrtps_shared_cpp.so+0x2cae7)

SUMMARY: AddressSanitizer: 144 byte(s) leaked in 3 allocation(s).
root@e4c9a080ebb4:/opt/ros_ws#
root@e4c9a080ebb4:/opt/ros_ws#
root@e4c9a080ebb4:/opt/ros_ws#
root@e4c9a080ebb4:/opt/ros_ws#
root@e4c9a080ebb4:/opt/ros_ws# ./build/tf2_ros/tf2_monitor
Gathering data on all frames for 10 seconds...



RESULTS: for all Frames

Frames:

All Broadcasters:

[clalancette]

We've merged into Foxy, but we haven't done a release (which means it isn't in the binary packages yet). So you'd have to build rclcpp from source on Foxy to see the fix.

In any case, though, what you are showing above is memory leaks, not undefined behavior. This issue is particularly about fixing the undefined behavior we were seeing.

[fujitatomoya]

@zhoulaifu i am closing this one, but just in case if you see the problem again, please do feel free to open another issue. thanks!