Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Deserialization error when subscribing to /rosout #61

Closed
juanrh opened this issue Jan 31, 2019 · 12 comments
Closed

Deserialization error when subscribing to /rosout #61

juanrh opened this issue Jan 31, 2019 · 12 comments

Comments

@juanrh
Copy link
Contributor

juanrh commented Jan 31, 2019

Bug report

Required Info:

repositories:
  ament/ament_cmake:
    type: git
    url: https://github.com/ament/ament_cmake.git
    version: master
  ament/ament_index:
    type: git
    url: https://github.com/ament/ament_index.git
    version: master
  ament/ament_lint:
    type: git
    url: https://github.com/ament/ament_lint.git
    version: master
  ament/ament_package:
    type: git
    url: https://github.com/ament/ament_package.git
    version: master
  ament/googletest:
    type: git
    url: https://github.com/ament/googletest.git
    version: ros2
  ament/uncrustify_vendor:
    type: git
    url: https://github.com/ament/uncrustify_vendor.git
    version: master
  eProsima/Fast-CDR:
    type: git
    url: https://github.com/eProsima/Fast-CDR.git
    version: master
  eProsima/Fast-RTPS:
    type: git
    url: https://github.com/eProsima/Fast-RTPS.git
    version: master
  osrf/osrf_pycommon:
    type: git
    url: https://github.com/osrf/osrf_pycommon.git
    version: master
  osrf/osrf_testing_tools_cpp:
    type: git
    url: https://github.com/osrf/osrf_testing_tools_cpp.git
    version: master
  ros/class_loader:
    type: git
    url: https://github.com/ros/class_loader.git
    version: ros2
  ros/pluginlib:
    type: git
    url: https://github.com/ros/pluginlib.git
    version: ros2
  ros/resource_retriever:
    type: git
    url: https://github.com/ros/resource_retriever.git
    version: ros2
  ros/ros_environment:
    type: git
    url: https://github.com/ros/ros_environment.git
    version: crystal
  ros/urdfdom_headers:
    type: git
    url: https://github.com/ros/urdfdom_headers.git
    version: master
  ros-perception/laser_geometry:
    type: git
    url: https://github.com/ros-perception/laser_geometry.git
    version: ros2
  ros-planning/navigation_msgs:
    type: git
    url: https://github.com/ros-planning/navigation_msgs.git
    version: ros2
  ros-visualization/python_qt_binding:
    type: git
    url: https://github.com/ros-visualization/python_qt_binding.git
    version: crystal-devel
  ros-visualization/qt_gui_core:
    type: git
    url: https://github.com/ros-visualization/qt_gui_core.git
    version: crystal-devel
  ros-visualization/rqt:
    type: git
    url: https://github.com/ros-visualization/rqt.git
    version: crystal-devel
  ros-visualization/rqt_console:
    type: git
    url: https://github.com/ros-visualization/rqt_console.git
    version: crystal-devel
  ros-visualization/rqt_msg:
    type: git
    url: https://github.com/ros-visualization/rqt_msg.git
    version: crystal-devel
  ros-visualization/rqt_plot:
    type: git
    url: https://github.com/ros-visualization/rqt_plot.git
    version: crystal-devel
  ros-visualization/rqt_publisher:
    type: git
    url: https://github.com/ros-visualization/rqt_publisher.git
    version: crystal-devel
  ros-visualization/rqt_py_console:
    type: git
    url: https://github.com/ros-visualization/rqt_py_console.git
    version: crystal-devel
  ros-visualization/rqt_service_caller:
    type: git
    url: https://github.com/ros-visualization/rqt_service_caller.git
    version: crystal-devel
  ros-visualization/rqt_shell:
    type: git
    url: https://github.com/ros-visualization/rqt_shell.git
    version: crystal-devel
  ros-visualization/rqt_srv:
    type: git
    url: https://github.com/ros-visualization/rqt_srv.git
    version: crystal-devel
  ros-visualization/rqt_top:
    type: git
    url: https://github.com/ros-visualization/rqt_top.git
    version: crystal-devel
  ros2/ament_cmake_ros:
    type: git
    url: https://github.com/ros2/ament_cmake_ros.git
    version: master
  ros2/common_interfaces:
    type: git
    url: https://github.com/ros2/common_interfaces.git
    version: master
  ros2/console_bridge_vendor:
    type: git
    url: https://github.com/ros2/console_bridge_vendor.git
    version: master
  ros2/demos:
    type: git
    url: https://github.com/ros2/demos.git
    version: master
  ros2/examples:
    type: git
    url: https://github.com/ros2/examples.git
    version: master
  ros2/example_interfaces:
    type: git
    url: https://github.com/ros2/example_interfaces.git
    version: master
  ros2/geometry2:
    type: git
    url: https://github.com/ros2/geometry2.git
    version: ros2
  ros2/kdl_parser:
    type: git
    url: https://github.com/ros2/kdl_parser.git
    version: ros2
  ros2/launch:
    type: git
    url: https://github.com/ros2/launch.git
    version: master
  ros2/libyaml_vendor:
    type: git
    url: https://github.com/ros2/libyaml_vendor.git
    version: master
  ros2/message_filters:
    type: git
    url: https://github.com/ros2/message_filters.git
    version: master
  ros2/orocos_kinematics_dynamics:
    type: git
    url: https://github.com/ros2/orocos_kinematics_dynamics.git
    version: ros2
  ros2/poco_vendor:
    type: git
    url: https://github.com/ros2/poco_vendor.git
    version: master
  ros2/rcl_logging:
    type: git
    url: https://github.com/ros2/rcl_logging.git
    version: master
  ros2/rcl:
    type: git
    url: https://github.com/ros2/rcl.git
    version: master
  ros2/rcl_interfaces:
    type: git
    url: https://github.com/ros2/rcl_interfaces.git
    version: master
#  ros2/rclc:
#    type: git
#    url: https://github.com/ros2/rclc.git
#    version: master
  ros2/rclcpp:
    type: git
    url: https://github.com/ros2/rclcpp.git
    version: master
  ros2/rclpy:
    type: git
    url: https://github.com/ros2/rclpy.git
    version: master
  ros2/rcutils:
    type: git
    url: https://github.com/ros2/rcutils.git
    version: master
  ros2/realtime_support:
    type: git
    url: https://github.com/ros2/realtime_support.git
    version: master
  ros2/rmw:
    type: git
    url: https://github.com/ros2/rmw.git
    version: master
  ros2/rmw_connext:
    type: git
    url: https://github.com/ros2/rmw_connext.git
    version: master
  ros2/rmw_fastrtps:
    type: git
    url: https://github.com/ros2/rmw_fastrtps.git
    version: master
  ros2/rmw_implementation:
    type: git
    url: https://github.com/ros2/rmw_implementation.git
    version: master
  ros2/rmw_opensplice:
    type: git
    url: https://github.com/ros2/rmw_opensplice.git
    version: master
  ros2/robot_state_publisher:
    type: git
    url: https://github.com/ros2/robot_state_publisher.git
    version: ros2
  ros2/ros1_bridge:
    type: git
    url: https://github.com/ros2/ros1_bridge.git
    version: master
  ros2/ros2cli:
    type: git
    url: https://github.com/ros2/ros2cli.git
    version: master
  ros2/rosidl:
    type: git
    url: https://github.com/ros2/rosidl.git
    version: master
  ros2/rosidl_dds:
    type: git
    url: https://github.com/ros2/rosidl_dds.git
    version: master
  ros2/rosidl_defaults:
    type: git
    url: https://github.com/ros2/rosidl_defaults.git
    version: master
  ros2/rosidl_python:
    type: git
    url: https://github.com/ros2/rosidl_python.git
    version: master
  ros2/rosidl_typesupport:
    type: git
    url: https://github.com/ros2/rosidl_typesupport.git
    version: master
  ros2/rosidl_typesupport_connext:
    type: git
    url: https://github.com/ros2/rosidl_typesupport_connext.git
    version: master
  ros2/rosidl_typesupport_fastrtps:
    type: git
    url: https://github.com/ros2/rosidl_typesupport_fastrtps.git
    version: master
  ros2/rosidl_typesupport_opensplice:
    type: git
    url: https://github.com/ros2/rosidl_typesupport_opensplice.git
    version: master
  ros2/rviz:
    type: git
    url: https://github.com/ros2/rviz.git
    version: ros2
  ros2/sros2:
    type: git
    url: https://github.com/ros2/sros2.git
    version: master
  ros2/system_tests:
    type: git
    url: https://github.com/ros2/system_tests.git
    version: master
  ros2/tinyxml_vendor:
    type: git
    url: https://github.com/ros2/tinyxml_vendor.git
    version: master
  ros2/tinyxml2_vendor:
    type: git
    url: https://github.com/ros2/tinyxml2_vendor.git
    version: master
  ros2/tlsf:
    type: git
    url: https://github.com/ros2/tlsf.git
    version: master
#  ros2/tutorials:
#    type: git
#    url: https://github.com/ros2/tutorials.git
#    version: master
  ros2/unique_identifier_msgs:
    type: git
    url: https://github.com/ros2/unique_identifier_msgs.git
    version: master
  ros2/urdf:
    type: git
    url: https://github.com/ros2/urdf.git
    version: ros2
  ros2/urdfdom:
    type: git
    url: https://github.com/ros2/urdfdom.git
    version: ros2
  ros2/yaml_cpp_vendor:
    type: git
    url: https://github.com/ros2/yaml_cpp_vendor.git
    version: master

  • DDS implementation:

    • fastrtps
  • Client library (if applicable):

    • rclcpp

Steps to reproduce issue

mkdir -p /opt/workspace/src/ros2/
cd /opt/workspace/src/ros2/
git clone https://github.com/ros2/demos.git

apply the following diff

    diff --git a/demo_nodes_cpp/src/topics/listener.cpp b/demo_nodes_cpp/src/topics/listener.cpp
    index 056859c..a51067b 100644
    --- a/demo_nodes_cpp/src/topics/listener.cpp
    +++ b/demo_nodes_cpp/src/topics/listener.cpp
    @@ -15,10 +15,13 @@
     #include <cstdio>
     #include <memory>
     #include <string>
    +#include <stdio.h> 
     
     #include "rclcpp/rclcpp.hpp"
     #include "rcutils/cmdline_parser.h"
     
    +#include <rcl_interfaces/msg/log.hpp>
    +
     #include "std_msgs/msg/string.hpp"
     
     void print_usage()
    @@ -40,21 +43,37 @@ public:
       {
         // Create a callback function for when messages are received.
         // Variations of this function also exist using, for example UniquePtr for zero-copy transport.
    +    // auto callback =
    +    //   [this](const std_msgs::msg::String::SharedPtr msg) -> void
    +    //   {
    +    //     RCLCPP_INFO(this->get_logger(), "I heard: [%s]", msg->data.c_str());
    +    //   };
         auto callback =
    -      [this](const std_msgs::msg::String::SharedPtr msg) -> void
    +      [this](const rcl_interfaces::msg::Log::SharedPtr ros2_msg) -> void
           {
    -        RCLCPP_INFO(this->get_logger(), "I heard: [%s]", msg->data.c_str());
    +         std::cout << "I heard rcl_interfaces::msg::Log with "
    +          << "stamp=[(" << ros2_msg->stamp.sec << ", " << ros2_msg->stamp.nanosec << ")"
    +          << "], level=[" << ros2_msg->level 
    +          << "], name=[" << ros2_msg->name << "]"
    +          << "], msg=[" << ros2_msg->msg << "]"
    +          << "], file=[" << ros2_msg->file << "]"
    +          << "], function=[" << ros2_msg->function << "]"
    +          << "], line=[" << ros2_msg->line << "]"
    +          << std::endl;
    +        // RCLCPP_INFO(this->get_logger(), "I heard: [%s]", msg->data.c_str());
           };
     
         // Create a subscription to the topic which can be matched with one or more compatible ROS
         // publishers.
         // Note that not all publishers on the same topic with the same type will be compatible:
         // they must have compatible Quality of Service policies.
    -    sub_ = create_subscription<std_msgs::msg::String>(topic_name, callback);
    +    // sub_ = create_subscription<std_msgs::msg::String>(topic_name, callback);
    +    sub_ = create_subscription<rcl_interfaces::msg::Log>("/rosout", callback);
       }
     
     private:
    -  rclcpp::Subscription<std_msgs::msg::String>::SharedPtr sub_;
    +  //rclcpp::Subscription<std_msgs::msg::String>::SharedPtr sub_;
    +  rclcpp::Subscription<rcl_interfaces::msg::Log>::SharedPtr sub_;
     };
     
     int main(int argc, char * argv[])

then build and launch

cd /opt/workspace 
source /opt/ros2_ws/install/setup.bash 
colcon build --packages-select demo_nodes_cpp
source install/setup.bash
ros2 run demo_nodes_cpp talker & 
valgrind --track-origins=yes --leak-check=full --show-leak-kinds=all build/demo_nodes_cpp/listener 2>&1 | tee demo_listener.log

Expected behavior

In the standard output we see messages from the talker node like [INFO] [talker]: Publishing: 'Hello World: 35', alternating with messages I heard rcl_interfaces::msg::Log with stamp=[(1548897558, 380492253)], level=... from the modified listener node, that is listening to rosout

Actual behavior

The modified listener node that is listening to rosout has realloc errors, that are reported by valgrind in demo_listener.log as follows

==8032== Memcheck, a memory error detector
==8032== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==8032== Using Valgrind-3.13.0 and LibVEX; rerun with -h for copyright info
==8032== Command: build/demo_nodes_cpp/listener
==8032== 
==8032== Invalid free() / delete / delete[] / realloc()
==8032==    at 0x4C31D2F: realloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==8032==    by 0x739DA52: rosidl_generator_c__String__assignn (in /opt/ros2_ws/build/rosidl_generator_c/librosidl_generator_c.so)
==8032==    by 0x739DAE9: rosidl_generator_c__String__assign (in /opt/ros2_ws/build/rosidl_generator_c/librosidl_generator_c.so)
==8032==    by 0xDB3D08C: __cdr_deserialize (in /opt/ros2_ws/build/rcl_interfaces/librcl_interfaces__rosidl_typesupport_fastrtps_c.so)
==8032==    by 0x93F49A6: rmw_fastrtps_cpp::TypeSupport::deserializeROSmessage(eprosima::fastcdr::Cdr&, void*) (in /opt/ros2_ws/build/rmw_fastrtps_cpp/librmw_fastrtps_cpp.so)
==8032==    by 0x9A9EAC3: rmw_fastrtps_shared_cpp::TypeSupport::deserialize(eprosima::fastrtps::rtps::SerializedPayload_t*, void*) (in /opt/ros2_ws/build/rmw_fastrtps_shared_cpp/librmw_fastrtps_shared_cpp.so)
==8032==    by 0x9E80A6F: eprosima::fastrtps::SubscriberHistory::takeNextData(void*, eprosima::fastrtps::SampleInfo_t*) (in /opt/ros2_ws/install/fastrtps/lib/libfastrtps.so.1.7.0)
==8032==    by 0x9A97FE0: rmw_fastrtps_shared_cpp::_take(char const*, rmw_subscription_t const*, void*, bool*, rmw_message_info_t*) (in /opt/ros2_ws/build/rmw_fastrtps_shared_cpp/librmw_fastrtps_shared_cpp.so)
==8032==    by 0x9A981FC: rmw_fastrtps_shared_cpp::__rmw_take_with_info(char const*, rmw_subscription_t const*, void*, bool*, rmw_message_info_t*) (in /opt/ros2_ws/build/rmw_fastrtps_shared_cpp/librmw_fastrtps_shared_cpp.so)
==8032==    by 0x93F45B9: rmw_take_with_info (in /opt/ros2_ws/build/rmw_fastrtps_cpp/librmw_fastrtps_cpp.so)
==8032==    by 0x654CD6C: rmw_take_with_info (in /opt/ros2_ws/build/rmw_implementation/librmw_implementation.so)
==8032==    by 0x55817EF: rcl_take (in /opt/ros2_ws/build/rcl/librcl.so)
==8032==  Address 0xf938530 is 48 bytes inside a block of size 168 alloc'd
==8032==    at 0x4C3017F: operator new(unsigned long) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==8032==    by 0x12B490: __gnu_cxx::new_allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> >::allocate(unsigned long, void const*) (in /opt/workspace/build/demo_nodes_cpp/listener)
==8032==    by 0x12B18A: std::allocator_traits<std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> > >::allocate(std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> >&, unsigned long) (in /opt/workspace/build/demo_nodes_cpp/listener)
==8032==    by 0x12ACB7: std::__allocated_ptr<std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> > > std::__allocate_guarded<std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> > >(std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> >&) (in /opt/workspace/build/demo_nodes_cpp/listener)
==8032==    by 0x12A88A: std::__shared_count<(__gnu_cxx::_Lock_policy)2>::__shared_count<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >>(std::_Sp_make_shared_tag, rcl_interfaces::msg::Log_<std::allocator<void> >*, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > > const&) (in /opt/workspace/build/demo_nodes_cpp/listener)
==8032==    by 0x12A4AF: std::__shared_ptr<rcl_interfaces::msg::Log_<std::allocator<void> >, (__gnu_cxx::_Lock_policy)2>::__shared_ptr<std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >>(std::_Sp_make_shared_tag, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > > const&) (in /opt/workspace/build/demo_nodes_cpp/listener)
==8032==    by 0x129FD5: std::shared_ptr<rcl_interfaces::msg::Log_<std::allocator<void> > >::shared_ptr<std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >>(std::_Sp_make_shared_tag, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > > const&) (in /opt/workspace/build/demo_nodes_cpp/listener)
==8032==    by 0x1298FE: std::shared_ptr<rcl_interfaces::msg::Log_<std::allocator<void> > > std::allocate_shared<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >>(std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > > const&) (in /opt/workspace/build/demo_nodes_cpp/listener)
==8032==    by 0x1288A0: rclcpp::message_memory_strategy::MessageMemoryStrategy<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<void> >::borrow_message() (in /opt/workspace/build/demo_nodes_cpp/listener)
==8032==    by 0x12846E: rclcpp::Subscription<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<void> >::create_message() (in /opt/workspace/build/demo_nodes_cpp/listener)
==8032==    by 0x51ACF59: rclcpp::executor::Executor::execute_subscription(std::shared_ptr<rclcpp::SubscriptionBase>) (in /opt/ros2_ws/build/rclcpp/librclcpp.so)
==8032==    by 0x51AC9BE: rclcpp::executor::Executor::execute_any_executable(rclcpp::executor::AnyExecutable&) (in /opt/ros2_ws/build/rclcpp/librclcpp.so)
==8032== 
failed to assign string into field 'name'
I heard rcl_interfaces::msg::Log with stamp=[(1548897690, 248958130)], level=[�], name=[]], msg=[]], file=[]], function=[]], line=[0]
failed to assign string into field 'name'
I heard rcl_interfaces::msg::Log with stamp=[(1548897691, 248923210)], level=[�], name=[]], msg=[]], file=[]], function=[]], line=[0]
failed to assign string into field 'name'
I heard rcl_interfaces::msg::Log with stam

Additional information


Feature request

Feature description

Implementation considerations

@cevans87
Copy link

I am also able to repro this bug using the osrf/ros2:nightly docker image, but not in the amd64/ros:crystal image. That means the bug shows up in master but not in release?

@cevans87
Copy link

cevans87 commented Feb 21, 2019

See a pretty simple repro in my commit above. I've confirmed the repro in the osrf/ros2:nightly docker image, and that it does not repro in the amd64/ros:crystal-ros-core image. Here's the asan output I get.

=================================================================
==8077==ERROR: AddressSanitizer: attempting free on address which was not malloc()-ed: 0x60f000002e60 in thread T0
cev@f5fe104d0c8f:/Users/cev/cw_bug$     #0 0x7f4675948f40 in realloc (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xdef40)
    #1 0x7f4672d64e61 in rosidl_generator_c__String__assignn /home/jenkins-agent/workspace/packaging_linux/ws/src/ros2/rosidl/rosidl_generator_c/src/string_func
tions.c:85
    #2 0x7f466a04553c in __cdr_deserialize /home/jenkins-agent/workspace/packaging_linux/ws/build/rcl_interfaces/rosidl_typesupport_fastrtps_c/rcl_interfaces/ms
g/dds_fastrtps_c/log__type_support_c.cpp:189
    #3 0x7f466e7f73cb in rmw_fastrtps_cpp::TypeSupport::deserializeROSmessage(eprosima::fastcdr::Cdr&, void*) /home/jenkins-agent/workspace/packaging_linux/ws/s
rc/ros2/rmw_fastrtps/rmw_fastrtps_cpp/src/type_support_common.cpp:88
    #4 0x7f466e1cb161 in rmw_fastrtps_shared_cpp::TypeSupport::deserialize(eprosima::fastrtps::rtps::SerializedPayload_t*, void*) /home/jenkins-agent/workspace/
packaging_linux/ws/src/ros2/rmw_fastrtps/rmw_fastrtps_shared_cpp/src/TypeSupport_impl.cpp:100
    #5 0x7f466dcbad1f in eprosima::fastrtps::SubscriberHistory::takeNextData(void*, eprosima::fastrtps::SampleInfo_t*) /home/jenkins-agent/workspace/packaging_l
inux/ws/src/eProsima/Fast-RTPS/src/cpp/subscriber/SubscriberHistory.cpp:434
    #6 0x7f466e1c8969 in rmw_fastrtps_shared_cpp::_take(char const*, rmw_subscription_t const*, void*, bool*, rmw_message_info_t*) /home/jenkins-agent/workspace
/packaging_linux/ws/src/ros2/rmw_fastrtps/rmw_fastrtps_shared_cpp/src/rmw_take.cpp:69
    #7 0x7f467532374e in rcl_take /home/jenkins-agent/workspace/packaging_linux/ws/src/ros2/rcl/rcl/src/rcl/subscription.c:251
    #8 0x7f46755b9bc1 in rclcpp::executor::Executor::execute_subscription(std::shared_ptr<rclcpp::SubscriptionBase>) /home/jenkins-agent/workspace/packaging_lin
ux/ws/src/ros2/rclcpp/rclcpp/src/rclcpp/executor.cpp:323
    #9 0x7f46755bacb4 in rclcpp::executor::Executor::execute_any_executable(rclcpp::executor::AnyExecutable&) /home/jenkins-agent/workspace/packaging_linux/ws/s
rc/ros2/rclcpp/rclcpp/src/rclcpp/executor.cpp:273
    #10 0x7f46755c254e in rclcpp::executors::SingleThreadedExecutor::spin() /home/jenkins-agent/workspace/packaging_linux/ws/src/ros2/rclcpp/rclcpp/src/rclcpp/e
xecutors/single_threaded_executor.cpp:36
    #11 0x7f46755bf07f in rclcpp::spin(std::shared_ptr<rclcpp::node_interfaces::NodeBaseInterface>) /home/jenkins-agent/workspace/packaging_linux/ws/src/ros2/rc
lcpp/rclcpp/src/rclcpp/executors.cpp:35
    #12 0x7f46755bf32a in rclcpp::spin(std::shared_ptr<rclcpp::Node>) /home/jenkins-agent/workspace/packaging_linux/ws/src/ros2/rclcpp/rclcpp/src/rclcpp/executo
rs.cpp:42
    #13 0x563330c775c7 in main (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x
75c7)
    #14 0x7f467457db96 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b96)
    #15 0x563330c76739 in _start (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+
0x6739)

0x60f000002e60 is located 48 bytes inside of 168-byte region [0x60f000002e30,0x60f000002ed8)
allocated by thread T0 here:
    #0 0x7f467594a458 in operator new(unsigned long) (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xe0458)
    #1 0x563330c97d9d in __gnu_cxx::new_allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> >::allocate(unsigned long, void const*) (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x27d9d)
    #2 0x563330c978f6 in std::allocator_traits<std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> > >::allocate(std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> >&, unsigned long) (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x278f6)
    #3 0x563330c97061 in std::__allocated_ptr<std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> > > std::__allocate_guarded<std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> > >(std::allocator<std::_Sp_counted_ptr_inplace<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >, (__gnu_cxx::_Lock_policy)2> >&) (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x27061)
    #4 0x563330c968f0 in std::__shared_count<(__gnu_cxx::_Lock_policy)2>::__shared_count<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >>(std::_Sp_make_shared_tag, rcl_interfaces::msg::Log_<std::allocator<void> >*, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > > const&) (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x268f0)
    #5 0x563330c95f71 in std::__shared_ptr<rcl_interfaces::msg::Log_<std::allocator<void> >, (__gnu_cxx::_Lock_policy)2>::__shared_ptr<std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >>(std::_Sp_make_shared_tag, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > > const&) (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x25f71)
    #6 0x563330c95767 in std::shared_ptr<rcl_interfaces::msg::Log_<std::allocator<void> > >::shared_ptr<std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >>(std::_Sp_make_shared_tag, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > > const&) (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x25767)
    #7 0x563330c94c69 in std::shared_ptr<rcl_interfaces::msg::Log_<std::allocator<void> > > std::allocate_shared<rcl_interfaces::msg::Log_<std::allocator<void>
>, std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > >>(std::allocator<rcl_interfaces::msg::Log_<std::allocator<void> > > const&) (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x24c69)
    #8 0x563330c92e06 in rclcpp::message_memory_strategy::MessageMemoryStrategy<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<void> >::borrow_message() (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x22e06)
    #9 0x563330c924a8 in rclcpp::Subscription<rcl_interfaces::msg::Log_<std::allocator<void> >, std::allocator<void> >::create_message() (/Users/cev/cw_bug/install/examples_rclcpp_minimal_subscriber/lib/examples_rclcpp_minimal_subscriber/subscriber_not_composable+0x224a8)
    #10 0x7f46755b9b9a in rclcpp::executor::Executor::execute_subscription(std::shared_ptr<rclcpp::SubscriptionBase>) /home/jenkins-agent/workspace/packaging_linux/ws/src/ros2/rclcpp/rclcpp/src/rclcpp/executor.cpp:320

SUMMARY: AddressSanitizer: bad-free (/usr/lib/x86_64-linux-gnu/libasan.so.4+0xdef40) in realloc
==8077==ABORTING

[1]+  Exit 1                  ros2 run examples_rclcpp_minimal_subscriber subscriber_not_composable
cev@f5fe104d0c8f:/Users/cev/cw_bug$ exit

@juanrh
Copy link
Contributor Author

juanrh commented Feb 21, 2019

@cevans87
Copy link

This might help a little. Using the repro I posted above, I bisected using the build artifacts from ci.ros2.org.

  • Pass - Jan 14 build 1323
  • Fail - Jan 16 build 1327

@cevans87
Copy link

The pair of commits that expose this bug are

However, after looking through them I don't think they actually caused the bug. To recap, we do know that this is only happening with CPP subscriber/publishers and some of the code in the first commit I linked might help point to where things are broken. I setting my investigation aside for a bit. Hopefully this information helps.

@nburek
Copy link
Contributor

nburek commented Mar 6, 2019

It seems odd that a C++ Subscriber is somehow causing it to use the rosidl_generator_c__String__assign function. From the investigation we've done, it appears the realloc issue is because it's trying to realloc the pointer to the char buffer for the C++ string class. However, the C++ String class is using the short string optimization. So the pointer it is trying to realloc is actually pointing to the middle of the data in the String class, which is why the realloc fails because it's trying to realloc at a location that's in the middle of a previous alloc and not at the start.

It would be good to know why it's trying to use C code to update a C++ class. It's not clear to us if this was by design or if this is a bug with it trying to use the wrong typesupport class to deserialize. One theory we had was that the new rosout feature might be registering the C typesupport for the rosout topic and that the Subscriber written in C++ is then using that instead of the CPP typesupport provided during construction. We haven't confirmed that theory though.

@gonzodepedro
Copy link

gonzodepedro commented Mar 12, 2019

FastRTPS requiers the typesupport to be registered for every participant, this typesupport must be identified by a type_name. When a node is initialized logging_rosout registers the C typessuport but later when the subscriber attempts to register the cpp typesupport it finds that there is a typesupport already registered, (the C typesuppport the logging_rosout has already registered), and therefore it doesn't registers a CPP typesupport and later it attempts to use the C typesupport on a CPP class. This is due to the fact that the type_name generated is identical for C and CPP typesupports.

One workaround is to run the subscriber with the __log_disable_rosout:=true option which prevents the logging_rosout publisher creation and thus the registration of the C typesupport implementation for the Log messages.

A solutions would be to disambiguate the different typesupports when registering them to Fastrtps, but further investigation is needed. @wjwwood @dirk-thomas Any thoughts?

@dirk-thomas
Copy link
Member

The rosout publisher is being created with the C message type support: https://github.com/ros2/rcl/blob/1d8b831bdfe8c700a1934f4d6dc1803d49565865/rcl/src/rcl/logging_rosout.c#L168-L174

I don't see any reference of a publisher with a C++ typesupport? From where is the C++ message being published? That code likely needs to convert the C++ message into a C message.

@juanrh
Copy link
Contributor Author

juanrh commented Mar 16, 2019

I have tested the same reproduction with RMW_IMPLEMENTATION=rmw_opensplice_cpp and with RMW_IMPLEMENTATION=rmw_connext_cpp and the problem does not appear with those other DDS implementations

@gonzodepedro
Copy link

This is a bug in rmw_fastrtps. It doesn't support to have different typesupports (C and CPP) in the same Participant for the same topic.

If the use case is to have a node subscribed to /rosout to listen for log messages a workaround is to disable rosout log in that node by running with the _log_disable_rosout:=true flag.
ros2 run ros2 run demo_nodes_cpp listener _log_disable_rosout:=true

@gonzodepedro
Copy link

gonzodepedro commented Mar 21, 2019

Bug report created on ros2/rmw_fastrtps#265

@dirk-thomas
Copy link
Member

Closing in favor of ros2/rmw_fastrtps#265 since the remaining problem is FastRTPS specific.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants