Deserialization error when subscribing to /rosout #61

juanrh · 2019-01-31T01:22:33Z

Bug report

Required Info:

Operating System:
Ubuntu 16.04 with ROS running inside a docker container FROM ubuntu:bionic
Installation type:
Build from source following https://index.ros.org/doc/ros2/Installation/Linux-Development-Setup/, using https://raw.githubusercontent.com/ros2/ros2/master/ros2.repos
Version or commit hash:

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

The text was updated successfully, but these errors were encountered:

cevans87 · 2019-02-20T18:28:23Z

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 · 2019-02-21T02:03:29Z

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 · 2019-02-21T02:41:21Z

Most recent changes in files related to that trace

cevans87 · 2019-02-21T18:18:46Z

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 · 2019-02-25T18:46:02Z

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 · 2019-03-06T00:14:57Z

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 · 2019-03-12T22:03:23Z

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 · 2019-03-15T21:31:32Z

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 · 2019-03-16T00:04:10Z

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 · 2019-03-20T17:37:46Z

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 · 2019-03-21T19:42:11Z

Bug report created on ros2/rmw_fastrtps#265

dirk-thomas · 2019-05-16T15:40:00Z

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

juanrh mentioned this issue Jan 31, 2019

failed to create 2to1 bridge for topic '/rosout' with ROS 2 type ros2/ros1_bridge#159

Closed

juanrh mentioned this issue Mar 26, 2019

Add mapping file for ROS 1 bridge #67

Merged

gonzodepedro mentioned this issue May 15, 2019

Support field selection ros2/ros1_bridge#174

Merged

dirk-thomas closed this as completed May 16, 2019

dirk-thomas mentioned this issue May 16, 2019

Using different typesupports on same node and topic ends in segfault ros2/rmw_fastrtps#265

Closed

dirk-thomas mentioned this issue Aug 16, 2019

ros1_bridge tests fail in Linux packaging jobs ros2/build_farmer#229

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Deserialization error when subscribing to /rosout #61

Deserialization error when subscribing to /rosout #61

juanrh commented Jan 31, 2019

cevans87 commented Feb 20, 2019

cevans87 commented Feb 21, 2019 •

edited

Loading

juanrh commented Feb 21, 2019

cevans87 commented Feb 21, 2019

cevans87 commented Feb 25, 2019

nburek commented Mar 6, 2019

gonzodepedro commented Mar 12, 2019 •

edited

Loading

dirk-thomas commented Mar 15, 2019

juanrh commented Mar 16, 2019

gonzodepedro commented Mar 20, 2019

gonzodepedro commented Mar 21, 2019 •

edited

Loading

dirk-thomas commented May 16, 2019

Deserialization error when subscribing to /rosout #61

Deserialization error when subscribing to /rosout #61

Comments

juanrh commented Jan 31, 2019

Bug report

Steps to reproduce issue

Expected behavior

Actual behavior

Additional information

Feature request

Feature description

Implementation considerations

cevans87 commented Feb 20, 2019

cevans87 commented Feb 21, 2019 • edited Loading

juanrh commented Feb 21, 2019

cevans87 commented Feb 21, 2019

cevans87 commented Feb 25, 2019

nburek commented Mar 6, 2019

gonzodepedro commented Mar 12, 2019 • edited Loading

dirk-thomas commented Mar 15, 2019

juanrh commented Mar 16, 2019

gonzodepedro commented Mar 20, 2019

gonzodepedro commented Mar 21, 2019 • edited Loading

dirk-thomas commented May 16, 2019

cevans87 commented Feb 21, 2019 •

edited

Loading

gonzodepedro commented Mar 12, 2019 •

edited

Loading

gonzodepedro commented Mar 21, 2019 •

edited

Loading