[launch_testing]: Tests without a unittest to run concurrently with the processes under test throw an exception

[clalancette]

Bug report

I've been debugging https://github.com/ros2/rcutils/issues/204 . The test that causes the problem is at https://github.com/ros2/rcutils/blob/e31371df45afdfac545752777cd61a3a64769ee2/test/test_logging_output_format.py . In that test, you can see that there is a post_shutdown_test, but no test to run concurrently with the processes[1]. When running this test, a stack trace is printed:

[INFO] [launch]: All log files can be found below /home/ubuntu/.ros/log/2020-02-14-17-44-05-848290-ros2-bionic-1149925
[INFO] [launch]: Default logging verbosity is set to INFO

----------------------------------------------------------------------
Ran 0 tests in 0.000s

OK
Task exception was never retrieved
future: <Task finished coro=<LaunchService._process_one_event() done, defined at /home/ubuntu/ros2_ws/install/launch/lib/python3.6/site-packages/launch/launch_service.py:293> exception=RuntimeError('Signal event received before subprocess transport available.',)>
Traceback (most recent call last):
  File "/home/ubuntu/ros2_ws/install/launch/lib/python3.6/site-packages/launch/launch_service.py", line 295, in _process_one_event
    await self.__process_event(next_event)
  File "/home/ubuntu/ros2_ws/install/launch/lib/python3.6/site-packages/launch/launch_service.py", line 315, in __process_event
    visit_all_entities_and_collect_futures(entity, self.__context))
  File "/home/ubuntu/ros2_ws/install/launch/lib/python3.6/site-packages/launch/utilities/visit_all_entities_and_collect_futures_impl.py", line 38, in visit_all_entities_and_collect_futures
    sub_entities = entity.visit(context)
  File "/home/ubuntu/ros2_ws/install/launch/lib/python3.6/site-packages/launch/action.py", line 108, in visit
    return self.execute(context)
  File "/home/ubuntu/ros2_ws/install/launch/lib/python3.6/site-packages/launch/actions/opaque_function.py", line 75, in execute
    return self.__function(context, *self.__args, **self.__kwargs)
  File "/home/ubuntu/ros2_ws/install/launch/lib/python3.6/site-packages/launch/actions/execute_process.py", line 385, in __on_signal_process_event
    raise RuntimeError('Signal event received before subprocess transport available.')
RuntimeError: Signal event received before subprocess transport available.

I'll also note that this doesn't cause the test to fail, it's just a pretty ugly and worrying side-effect.

From my untrained eye, it kind of looks like an empty, rogue unittest process is being launched, but since the launch framework doesn't know about it, the exiting of this process causes it to be upset. It's possible to work around this by adding in a test that runs concurrently with the processes under test, but it would be a much nicer user experience to not have to do that.

[1] As a side note, it's hard to refer to these testcases that run in parallel with the processes under test. Maybe we should add another annotation for them.

Required Info:

• Operating System:
  • Ubuntu 18.04
• Installation type:
  • Source
• Version or commit hash:
  • b99eb3811b80fe9c685151543b5dbb690a52674b
• DDS implementation:
  • Fast-RTPS
• Client library (if applicable):
  • rcutils

Steps to reproduce issue

colcon test --packages-select rcutils

Expected behavior

test_logging_output_format.py completes without errors

Actual behavior

Stack trace above is printed.

[pbaughman]

@clalancette Not helpful to your actual problem at hand, but re:

[1] As a side note, it's hard to refer to these testcases that run in parallel with the processes under test. Maybe we should add another annotation for them.

These are called "Active" tests in this roscon presentation https://roscon.ros.org/2019/talks/roscon2019_launch_testing_presentation.pdf I don't have a good idea for making this information more official or discoverable though.

[fred-apex-ai]

@clalancette I got the same error message as you in https://github.com/ros2/rcutils/issues/204 running on foxy. Are you planning to fix the root cause? I tried the work around suggested in https://github.com/ros2/rcutils/pull/209 but it didn't help, still getting

RuntimeError: Signal event received before subprocess transport available.

[fred-apex-ai]

@clalancette I got the same error message as you in ros2/rcutils#204 running on foxy. Are you planning to fix the root cause? I tried the work around suggested in ros2/rcutils#209 but it didn't help, still getting

RuntimeError: Signal event received before subprocess transport available.

@clalancette I have this issue occurring again and again; e.g. here Can you tell me if you have any idea how to fix it, please?

[hidmic]

@fred-apex-ai see this rcl launch test for an example on how to wait for fixture processes to end. Note that launch_testing won't terminate them gracefully for you if these don't self terminate. It's on you to shut them down (e.g. sending process-specific Shutdown events).

I know launch_testing has some rough edges. Contributions are most welcome.

[fred-apex-ai]

It's on you to shut them down

@hidmic Thanks for the advice. Who should send a Shutdown event? The active test before calling proc_info.assertWaitForShutdown(process=executable_under_test, timeout=10)? Or do I have to add an extra executable to my launch description that does this?

[hidmic]

The active test before calling proc_info.assertWaitForShutdown(process=executable_under_test, timeout=10)? Or do I have to add an extra executable to my launch description that does this?

Any of the two would work.