Errors logged in console on killing nodes via ctrl+c

[AlexKaravaev]

Bug report

Required Info:

• Operating System:
  Linux 0ece455f6e93 5.4.0-48-generic fix indent #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 ros2/geometry2#546 has a relatively compact reproduction of what appears to be the same issue.