Errors logged in console on killing nodes via ctrl+c

[AlexKaravaev]

Bug report

Required Info:

• Operating System: Linux 0ece455f6e93 5.4.0-48-generic #52-Ubuntu SMP Thu Sep 10 10:58:49 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
• Installation type: osrf/ros2:nightly docker image
• Version or commit hash: foxy
• DDS implementation: Fast-RTPS
• Client library (if applicable): rclpy

Steps to reproduce issue

I am launching two python nodes from launch file and then killing it via ctrl+c

Expected behavior

I guess only this should output

[launch]: user interrupted with ctrl-c (SIGINT)

Actual behavior

^C[WARNING] [launch]: user interrupted with ctrl-c (SIGINT)
[control_node-1] Traceback (most recent call last):
[control_node-1]   File "/dev_ws/install/shadow_control/lib/shadow_control/control_node", line 11, in <module>
[control_node-1]     load_entry_point('shadow-control==0.0.0', 'console_scripts', 'control_node')()
[control_node-1]   File "/dev_ws/install/shadow_control/lib/python3.8/site-packages/shadow_control/control_node.py", line 58, in main
[control_node-1]     rclpy.spin(minimal_subscriber)
[control_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/__init__.py", line 196, in spin
[control_node-1]     executor.spin_once()
[control_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/executors.py", line 703, in spin_once
[control_node-1]     handler, entity, node = self.wait_for_ready_callbacks(timeout_sec=timeout_sec)
[control_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/executors.py", line 689, in wait_for_ready_callbacks
[control_node-1]     return next(self._cb_iter)
[control_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/executors.py", line 586, in _wait_for_ready_callbacks
[control_node-1]     _rclpy.rclpy_wait(wait_set, timeout_nsec)
[control_node-1] KeyboardInterrupt
[control_node-1] Exception ignored in: <function Executor.__del__ at 0x7fe28b734af0>
[control_node-1] Traceback (most recent call last):
[control_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/executors.py", line 240, in __del__
[control_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/signals.py", line 39, in destroy
[control_node-1] AttributeError: 'NoneType' object has no attribute 'rclpy_unregister_sigint_guard_condition'
[control_node-1] Exception ignored in: <function SignalHandlerGuardCondition.__del__ at 0x7fe28b70e4c0>
[control_node-1] Traceback (most recent call last):
[control_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/signals.py", line 30, in __del__
[control_node-1] TypeError: catching classes that do not inherit from BaseException is not allowed
[ERROR] [control_node-1]: process has died [pid 13892, exit code -2, cmd '/dev_ws/install/shadow_control/lib/shadow_control/control_node --ros-args --params-file /dev_ws/install/shadow_launch/share/shadow_launch/config/config.yaml'].

[twaddellberkeley]

@sloretz or at @ivanpauno any update from this? Having some issues trying to run things after shutdown since they're are no shutdown hooks. Currently I just have a Try: rclpy.spin() blah blah finally: blah blah rclpy.shutdown(). But if I try and do any exception handling I get this error as well.

[ivanpauno]

I see at least two issues.

~The first one is easy, InvalidHandle should inherit from ValueError and not from Exception.~ This might be the same issue actually, as inhereting from Exception is valid.

The second issue is the _signals module being none. That seems to be a destruction order issue, though I'm not sure how it's happening.

[ivanpauno]

The issue seems related to https://stackoverflow.com/questions/18058730/python-attributeerror-on-del. Maybe the issue is solved by storing _signals as a member of the object.

@AlexKaravaev @twaddellberkeley could you try that?

[AlexKaravaev]

Tested on ros:rolling docker gives this

root@7307508d8411:~/ws/src/test_signal/launch# ros2 launch test.launch.py
[INFO] [launch]: All log files can be found below /root/.ros/log/2021-10-14-18-36-22-771763-7307508d8411-4559
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [test_node-1]: process started with pid [4561]
^C[WARNING] [launch]: user interrupted with ctrl-c (SIGINT)
[test_node-1] Traceback (most recent call last):
[test_node-1]   File "/root/ws/install/test_signal/lib/test_signal/test_node", line 11, in <module>
[test_node-1]     load_entry_point('test-signal==0.0.0', 'console_scripts', 'test_node')()
[test_node-1]   File "/root/ws/install/test_signal/lib/python3.8/site-packages/test_signal/test.py", line 7, in main
[test_node-1]     rclpy.spin(node)
[test_node-1]   File "/opt/ros/rolling/lib/python3.8/site-packages/rclpy/__init__.py", line 196, in spin
[test_node-1]     executor.spin_once()
[test_node-1]   File "/opt/ros/rolling/lib/python3.8/site-packages/rclpy/executors.py", line 701, in spin_once
[test_node-1]     handler, entity, node = self.wait_for_ready_callbacks(timeout_sec=timeout_sec)
[test_node-1]   File "/opt/ros/rolling/lib/python3.8/site-packages/rclpy/executors.py", line 687, in wait_for_ready_callbacks
[test_node-1]     return next(self._cb_iter)
[test_node-1]   File "/opt/ros/rolling/lib/python3.8/site-packages/rclpy/executors.py", line 585, in _wait_for_ready_callbacks
[test_node-1]     wait_set.wait(timeout_nsec)
[test_node-1] KeyboardInterrupt
[ERROR] [test_node-1]: process has died [pid 4561, exit code -2, cmd '/root/ws/install/test_signal/lib/test_signal/test_node --ros-args -r __node:=test -r __ns:=/'].

Tested on ros:foxy docker gives this

root@7c14186b0046:/ws/src/test_signal/launch# ros2 launch test.launch.py
[INFO] [launch]: All log files can be found below /root/.ros/log/2021-10-14-18-40-46-493181-7c14186b0046-560
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [test_node-1]: process started with pid [565]
^C[WARNING] [launch]: user interrupted with ctrl-c (SIGINT)
[test_node-1] Traceback (most recent call last):
[test_node-1]   File "/ws/install/test_signal/lib/test_signal/test_node", line 11, in <module>
[test_node-1]     load_entry_point('test-signal==0.0.0', 'console_scripts', 'test_node')()
[test_node-1]   File "/ws/install/test_signal/lib/python3.8/site-packages/test_signal/test.py", line 7, in main
[test_node-1]     rclpy.spin(node)
[test_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/__init__.py", line 191, in spin
[test_node-1]     executor.spin_once()
[test_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/executors.py", line 703, in spin_once
[test_node-1]     handler, entity, node = self.wait_for_ready_callbacks(timeout_sec=timeout_sec)
[test_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/executors.py", line 689, in wait_for_ready_callbacks
[test_node-1]     return next(self._cb_iter)
[test_node-1]   File "/opt/ros/foxy/lib/python3.8/site-packages/rclpy/executors.py", line 586, in _wait_for_ready_callbacks
[test_node-1]     _rclpy.rclpy_wait(wait_set, timeout_nsec)
[test_node-1] KeyboardInterrupt
[ERROR] [test_node-1]: process has died [pid 565, exit code -2, cmd '/ws/install/test_signal/lib/test_signal/test_node --ros-args -r __node:=test -r __ns:=/'].

I haven't been able to reproduce this issue actually. Keeping in mind that I had opened it almost year ago, could be that it was fixed by another thing. Unless @twaddellberkeley could provide some MWE

[twaddellberkeley]

@AlexKaravaev @ivanpauno Apologies for the delay, have been going down the rabbit hole on an unrelated i2c issue. Let me try and do some more testing of the issue this weekend.

[twaddellberkeley]

Apologies for the long delay, this is the output I have now (It's been awhile since i created the error and found a workaround and not sure if I recreated it properly) ^CTraceback (most recent call last): File "/home/spacecal/SpaceCAL/install/JNode_KeyboardInput/lib/JNode_KeyboardInput/JNodeInput", line 11, in load_entry_point('JNode-KeyboardInput==0.0.0', 'console_scripts', 'JNodeInput')() File "/home/spacecal/SpaceCAL/install/JNode_KeyboardInput/lib/python3.8/site-packages/JNode_KeyboardInput/keyInputNode.py", line 86, in main publisher = keyTalkerClass() File "/home/spacecal/SpaceCAL/install/JNode_KeyboardInput/lib/python3.8/site-packages/JNode_KeyboardInput/keyInputNode.py", line 44, in init self.keyTalker() File "/home/spacecal/SpaceCAL/install/JNode_KeyboardInput/lib/python3.8/site-packages/JNode_KeyboardInput/keyInputNode.py", line 81, in keyTalker listener.join() File "/home/spacecal/.local/lib/python3.8/site-packages/pynput/_util/init.py", line 252, in join super(AbstractListener, self).join(*args) File "/usr/lib/python3.8/threading.py", line 1011, in join self._wait_for_tstate_lock() File "/usr/lib/python3.8/threading.py", line 1027, in _wait_for_tstate_lock elif lock.acquire(block, timeout): KeyboardInterrupt `` On a side note because there are alternatives to the shutdown hooks seen in ROS1?

Thanks! Taylor

[tfoote]

The report in https://github.com/ros2/geometry2/issues/546 has a relatively compact reproduction of what appears to be the same issue.