core dumped in rcl_logging_external_log after ctrl+c in some case #1418
Description
Bug report
Required Info:
- Operating System:
- Ubuntu 20.04
- Installation type:
- source
- Version or commit hash:
- DDS implementation:
- Fast-RTPS
- Client library (if applicable):
- rclcpp
Steps to reproduce issue
Using directly call for the executable file can easily reproduce the issue(frequency: 1/3),
$ ./install/lib/demo_nodes_cpp/listener --ros-args --log-level debug (press ctrl+c immediately)
Expected behavior
No core dumped
Actual behavior
...
[DEBUG] [1603352071.289077304] [rcl]: Timeout calculated based on next scheduled timer: false
^C[INFO] [1603352071.813215385] [rclcpp]: signal_handler(signal_value=2)
[DEBUG] [1603352071.813371611] [rclcpp]: signal_handler(): SIGINT received, notifying deferred signal handler
[DEBUG] [1603352071.813459003] [rclcpp]: deferred_signal_handler(): woken up due to SIGINT or uninstall
[DEBUG] [1603352071.813565138] [rclcpp]: deferred_signal_handler(): SIGINT received, shutting down
[DEBUG] [1603352071.813858947] [rclcpp]: deferred_signal_handler(): shutting down rclcpp::Context @ 0x561b1ab00b50, because it had shutdown_on_sigint == true
[DEBUG] [1603352071.813943162] [rcl]: Shutting down ROS client library, for context at address: 0x561b1ab00e30
[DEBUG] [1603352071.814205573] [rcl]: Finalizing publisher
[DEBUG] [1603352071.817029627] [rcl]: Publisher finalized
[DEBUG] [1603352071.817415178] [rclcpp]: deferred_signal_handler(): waiting for SIGINT or uninstall
[DEBUG] [1603352071.814182399] [rcl]: Guard condition in wait set is ready
Segmentation fault (core dumped)
Additional information
backtrace
(gdb) bt
#0 std::__atomic_base<int>::load (__m=std::memory_order_relaxed, this=0x40) at /usr/include/c++/9/bits/atomic_base.h:419
#1 spdlog::logger::should_log (this=0x0, msg_level=spdlog::level::debug) at /home/sharedata/Linux/ROS2/docker_ros2_master/local_install/include/spdlog/logger.h:322
#2 0x00007f87fdb3305e in spdlog::logger::log (this=0x0, loc=..., lvl=spdlog::level::debug, msg=...)
at /home/sharedata/Linux/ROS2/docker_ros2_master/local_install/include/spdlog/logger.h:165
#3 0x00007f87fdb35253 in spdlog::logger::log<char const*, (char const**)0> (this=0x0, loc=..., lvl=spdlog::level::debug,
msg=@0x7ffe9ec01258: 0x7ffe9ec03780 "[DEBUG] [1603352071.814182399] [rcl]: Guard condition in wait set is ready")
at /home/sharedata/Linux/ROS2/docker_ros2_master/local_install/include/spdlog/logger.h:147
#4 0x00007f87fdb343e7 in spdlog::logger::log<char const*> (this=0x0, lvl=spdlog::level::debug,
msg=@0x7ffe9ec01258: 0x7ffe9ec03780 "[DEBUG] [1603352071.814182399] [rcl]: Guard condition in wait set is ready")
at /home/sharedata/Linux/ROS2/docker_ros2_master/local_install/include/spdlog/logger.h:140
#5 0x00007f87fdb31e66 in rcl_logging_external_log (severity=10, name=0x7f87fdd290f3 "rcl",
msg=0x7ffe9ec03780 "[DEBUG] [1603352071.814182399] [rcl]: Guard condition in wait set is ready")
at /home/sharedata/Linux/ROS2/docker_ros2_master/src/ros2/rcl_logging/rcl_logging_spdlog/src/rcl_logging_spdlog.cpp:148
#6 0x00007f87fdd0a941 in rcl_logging_ext_lib_output_handler (location=0x7f87fdd2f600 <__rcutils_logging_location.4922>, severity=10, name=0x7f87fdd290f3 "rcl",
timestamp=1603352071814182399, format=0x7f87fdd297b0 "Guard condition in wait set is ready", args=0x7ffe9ec03cd0)
at /home/sharedata/Linux/ROS2/docker_ros2_master/src/ros2/rcl/rcl/src/rcl/logging.c:204
#7 0x00007f87fdd0a570 in rcl_logging_multiple_output_handler (location=0x7f87fdd2f600 <__rcutils_logging_location.4922>, severity=10, name=0x7f87fdd290f3 "rcl",
timestamp=1603352071814182399, format=0x7f87fdd297b0 "Guard condition in wait set is ready", args=0x7ffe9ec03cd0)
at /home/sharedata/Linux/ROS2/docker_ros2_master/src/ros2/rcl/rcl/src/rcl/logging.c:154
#8 0x00007f87fe75b2e1 in rclcpp_logging_output_handler (location=0x7f87fdd2f600 <__rcutils_logging_location.4922>, severity=10, name=0x7f87fdd290f3 "rcl",
timestamp=1603352071814182399, format=0x7f87fdd297b0 "Guard condition in wait set is ready", args=0x7ffe9ec03cd0)
at /home/sharedata/Linux/ROS2/docker_ros2_master/src/ros2/rclcpp/rclcpp/src/rclcpp/context.cpp:135
#9 0x00007f87fe1a2532 in rcutils_log (location=0x7f87fdd2f600 <__rcutils_logging_location.4922>, severity=10, name=0x7f87fdd290f3 "rcl",
format=0x7f87fdd297b0 "Guard condition in wait set is ready") at /home/sharedata/Linux/ROS2/docker_ros2_master/src/ros2/rcutils/src/logging.c:544
#10 0x00007f87fdd1c854 in rcl_wait (wait_set=0x7ffe9ec09660, timeout=-1) at /home/sharedata/Linux/ROS2/docker_ros2_master/src/ros2/rcl/rcl/src/rcl/wait.c:653
#11 0x00007f87fe77a1e1 in rclcpp::Executor::wait_for_work (this=0x7ffe9ec09640, timeout=...)
at /home/sharedata/Linux/ROS2/docker_ros2_master/src/ros2/rclcpp/rclcpp/src/rclcpp/executor.cpp:724
#12 0x00007f87fe77ae52 in rclcpp::Executor::get_next_executable (this=0x7ffe9ec09640, any_executable=..., timeout=...)
at /home/sharedata/Linux/ROS2/docker_ros2_master/src/ros2/rclcpp/rclcpp/src/rclcpp/executor.cpp:873
#13 0x00007f87fe78c86b in rclcpp::executors::SingleThreadedExecutor::spin (this=0x7ffe9ec09640)
at /home/sharedata/Linux/ROS2/docker_ros2_master/src/ros2/rclcpp/rclcpp/src/rclcpp/executors/single_threaded_executor.cpp:35
#14 0x0000561b1a259220 in main (argc=4, argv=0x7ffe9ec0a338) at /home/sharedata/Linux/ROS2/docker_ros2_master/local_build/demo_nodes_cpp/rclcpp_components/node_main_listener.cpp:56
(gdb)
NOTE:
- I think we don't want to add an extra lock to fix this issue because it will slow down the log performance
- Maybe we can move
rcl_logging_finiin__delete_context
rclcpp/rclcpp/src/rclcpp/context.cpp
Lines 326 to 341 in 5d9db5d