Reentrant call to stderr on interrupted Launch on Windows + Opensplice

[dhood]

Using last night's packaging job:

This only happens for rmw_opensplice_cpp:

C:\J\workspace\packaging_windows\ws>ros2 launch demo_nodes_cpp talker_listener.launch.py
[INFO] [launch]: process[talker.EXE-1]: started with pid [800]
[INFO] [launch]: process[listener.EXE-2]: started with pid [6560]
[INFO] [talker]: Publishing: 'Hello World: 1'
[INFO] [listener]: I heard: [Hello World: 1]
[INFO] [talker]: Publishing: 'Hello World: 2'
[INFO] [listener]: I heard: [Hello World: 2]
ssignal_handler(2)
[WARNING] [launch.LaunchService]: user interrupted with ctrl-c (SIGINT)
--- Logging error ---
Traceback (most recent call last):
  File "c:\python36\lib\logging\__init__.py", line 995, in emit
    stream.write(self.terminator)
RuntimeError: reentrant call inside <_io.BufferedWriter name='<stderr>'>

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "c:\python36\lib\logging\__init__.py", line 995, in emit
    stream.write(self.terminator)
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\launch\utilities\signal_management.py", line 121, in __on_sigint
    __custom_sigint_handler(signum, frame)
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\launch\launch_service.py", line 291, in _on_sigint
    _logger.warn(base_msg)
  File "c:\python36\lib\logging\__init__.py", line 1323, in warn
    self.warning(msg, *args, **kwargs)
  File "c:\python36\lib\logging\__init__.py", line 1318, in warning
    self._log(WARNING, msg, args, **kwargs)
  File "c:\python36\lib\logging\__init__.py", line 1442, in _log
    self.handle(record)
  File "c:\python36\lib\logging\__init__.py", line 1452, in handle
    self.callHandlers(record)
  File "c:\python36\lib\logging\__init__.py", line 1514, in callHandlers
    hdlr.handle(record)
  File "c:\python36\lib\logging\__init__.py", line 863, in handle
    self.emit(record)
  File "c:\python36\lib\logging\__init__.py", line 998, in emit
    self.handleError(record)
  File "c:\python36\lib\logging\__init__.py", line 915, in handleError
    sys.stderr.write('--- Logging error ---\n')
RuntimeError: reentrant call inside <_io.BufferedWriter name='<stderr>'>
Call stack:
  File "C:\J\workspace\packaging_windows\ws\install\Scripts\ros2-script.py", line 11, in <module>
    load_entry_point('ros2cli==0.4.0', 'console_scripts', 'ros2')()
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\ros2cli\cli.py", line 69, in main
    rc = extension.main(parser=parser, args=args)
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\ros2launch\command\launch.py", line 78, in main
    debug=args.debug
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\ros2launch\api\api.py", line 127, in launch_a_python_launch_file
    return launch_service.run()
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\launch\launch_service.py", line 314, in run
    self.__loop_from_run_thread.run_until_complete(run_loop_task)
  File "c:\python36\lib\asyncio\base_events.py", line 455, in run_until_complete
    self.run_forever()
  File "c:\python36\lib\asyncio\base_events.py", line 422, in run_forever
    self._run_once()
  File "c:\python36\lib\asyncio\base_events.py", line 1432, in _run_once
    handle._run()
  File "c:\python36\lib\asyncio\events.py", line 145, in _run
    self._callback(*self._args)
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\launch\launch_service.py", line 177, in _process_one_event
    await self.__process_event(next_event)
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\launch\launch_service.py", line 186, in __process_event
    entities = event_handler.handle(event, self.__context)
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\launch\event_handlers\on_process_io.py", line 73, in handle
    return self.__on_stdout(event)
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\launch_ros\default_launch_description.py", line 57, in _on_process_output
    print(text, end='')
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\launch\utilities\signal_management.py", line 121, in __on_sigint
    __custom_sigint_handler(signum, frame)
  File "C:\J\workspace\packaging_windows\ws\install\Lib\site-packages\launch\launch_service.py", line 291, in _on_sigint
    _logger.warn(base_msg)
Message: 'user interrupted with ctrl-c (SIGINT)'
Arguments: ()
ignal_handler(2)
[ERROR] [launch]: process[listener.EXE-2] process has died [pid 6560, exit code 3221225786, cmd 'C:\J\workspace\packaging_windows\ws\install\lib\demo_nodes_cpp\listener.EXE'].
[ERROR] [launch]: process[talker.EXE-1] process has died [pid 800, exit code 3221225786, cmd 'C:\J\workspace\packaging_windows\ws\install\lib\demo_nodes_cpp\talker.EXE'].

Works fine for e.g. connext:

C:\J\workspace\packaging_windows\ws>set RMW_IMPLEMENTATION=rmw_connext_cpp

C:\J\workspace\packaging_windows\ws>ros2 launch demo_nodes_cpp talker_listener.launch.py
RTI Data Distribution Service Evaluation License issued to OSRF (OSRF01) dthomas@osrfoundation.org For non-production use only.
Expires on 5-Nov-2018 See www.rti.com for more information.
[INFO] [launch]: process[talker.EXE-1]: started with pid [7312]
[INFO] [launch]: process[listener.EXE-2]: started with pid [10856]
RTI Data Distribution Service Evaluation License issued to OSRF (OSRF01) dthomas@osrfoundation.org For non-production use only.
Expires on 5-Nov-2018 See www.rti.com for more information.
RTI Data Distribution Service Evaluation License issued to OSRF (OSRF01) dthomas@osrfoundation.org For non-production use only.
Expires on 5-Nov-2018 See www.rti.com for more information.
[INFO] [talker]: Publishing: 'Hello World: 1'
[INFO] [listener]: I heard: [Hello World: 1]
[INFO] [talker]: Publishing: 'Hello World: 2'
[INFO] [listener]: I heard: [Hello World: 2]
[WARNING] [launch.LaunchService]: user interrupted with ctrl-c (SIGINT)
signal_handler(2)
signal_handler(2)
[INFO] [launch]: process[listener.EXE-2]: process has finished cleanly
[INFO] [launch]: process[talker.EXE-1]: process has finished cleanly

[wjwwood]

Our best guess is that our Python signal handler which prints to stderr is getting interrupted by a signal, which causes the reentrant behavior.

Also, this happens because of a cascading SIGINT effect where signaled children also signal the parent (the launch script itself) resulting it two or more SIGINT signals in quick succession.

[dhood]

resolved by #92