Add test actions #178

ivanpauno · 2019-02-07T17:32:26Z

Connected to #176. This pull request add two actions GTest and PyTest, to run tests.
I'm doing this over #167, as running the old test with the legacy API generated a run-time asyncio error ('event loop is closed'), because of bad test interaction.
Also migrated to ament_cmake package, in order to build the dummy cpp test (maybe it exists a better way of doing this).

hidmic

Left some comments. Thanks @ivanpauno!

hidmic · 2019-02-08T18:21:33Z

launch_testing/dummy_tests/locking.py

@@ -12,12 +12,8 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.



@ivanpauno please update the copyright year.

hidmic · 2019-02-08T18:24:35Z

launch_testing/launch_testing/__init__.py

+__all__ = [
+    'actions',
+]
+


@ivanpauno I'm not sure we want all to behave like this (see here). Maybe we should add the class defined below and the output module as well?

hidmic · 2019-02-08T18:25:02Z

launch_testing/launch_testing/actions/gtest.py

@@ -0,0 +1,48 @@
+# Copyright 2018 Open Source Robotics Foundation, Inc.


@ivanpauno 2018 -> 2019

hidmic · 2019-02-08T18:26:22Z

launch_testing/launch_testing/actions/pytest.py

+        :param: path the path of the test to be executed.
+        """
+        cmd = [FindExecutable(name='python3'), '-m pytest', path]
+        super().__init__(cmd=cmd, shell=True, **kwargs)


@ivanpauno I think that using FindExecutable precludes the need for shell=True.

It fails without shell=True

hidmic · 2019-02-08T18:28:17Z

launch_testing/launch_testing/actions/test.py

+        # Setup a timer to send us a SIGKILL if the test locks
+        sigkill_timer = TimerAction(period=self.__timeout, actions=[
+            EmitEvent(event=SignalProcess(
+                signal_number=signal.SIGKILL,


@ivanpauno maybe we could send a SIGINT instead? It's slightly more polite :)

Sounds good, but maybe it should be escalated to SIGKILL after an extra timeout. WDYT?

That's ExecuteProcess action behavior upon shutdown already. Maybe we could try to reuse its __shutdown_process() method somehow?

hidmic · 2019-02-08T18:30:54Z

launch_testing/CMakeLists.txt

+
+ament_python_install_package(${PROJECT_NAME})
+
+add_executable(locking dummy_tests/locking.cpp)


@ivanpauno consider relocating your dummy applications below test/.

hidmic · 2019-02-08T18:31:41Z

launch_testing/test/launch_testing/test_gtest.py

+from launch_testing.actions import GTest
+
+
+def test_gtest():


@ivanpauno consider adding tests for real googletest and pytest instances, here and below respectively.

ivanpauno · 2019-02-13T13:18:23Z

@wjwwood I'm having a problem here, in a test that is locking forever.
I'm adding two actions to run gtest and pytest, which after a timeout are killed. I'm reusing the on_shutdown actions of ExecuteProcess, in order to not re-implement the same thing again.
The first timer is ending fine, SIGINT is being emited, and the gtest action is ending fine. Then the two other timers (for escalating to SIGTERM and SIGKILL) are cancelled, but the loop continues waiting for them and never ends. Is this the expected behavior?

How to repro:

I added an extra on_process_exit handler to avoid the error in test_gtest.py, comment it:

launch/launch_testing/test/launch_testing/test_gtest.py

Lines 41 to 43 in cea2cb2

    
           RegisterEventHandler(OnProcessExit( 
        
                   on_exit=on_gtest_exited, 
        
                   target_action=gtest_action

It's better only running the test_gtest.py, and not all the tests.
Also, I added some extra printing before the _is_iddle LaunchService method for debugging
print(number_of_entity_future_pairs) print(self._entity_future_pairs) print(self.__context._completion_futures)

Outputs:

Output commenting out the extra on_process_exit handler (pytest -s test_gtest.py)

platform linux -- Python 3.6.7, pytest-4.2.0, py-1.7.0, pluggy-0.8.1
rootdir: /home/ivanpauno/ros2_ws/src/ros2/launch/launch_testing/test/launch_testing, inifile:
plugins: rerunfailures-6.0, repeat-0.7.0, cov-2.6.1
collected 1 item                                                                                                                                                                                           

test_gtest.py 0
[]
[]
processing event: '<launch.events.include_launch_description.IncludeLaunchDescription object at 0x7ffbda5fcf28>'
processing event: '<launch.events.include_launch_description.IncludeLaunchDescription object at 0x7ffbda5fcf28>' ✓ '<launch.event_handlers.on_include_launch_description.OnIncludeLaunchDescription object at 0x7ffbda5fce80>'
2
[(<launch_testing.actions.gtest.GTest object at 0x7ffbda5fccf8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7ffbda58a4a8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]
processing event: '<launch.events.process.process_started.ProcessStarted object at 0x7ffbda4b20b8>'
2
[(<launch_testing.actions.gtest.GTest object at 0x7ffbda5fccf8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7ffbda58a4a8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]
processing event: '<launch.events.timer_event.TimerEvent object at 0x7ffbda58aa20>'
processing event: '<launch.events.timer_event.TimerEvent object at 0x7ffbda58aa20>' ✓ '<launch.event_handler.EventHandler object at 0x7ffbda58aa90>'
3
[(<launch_testing.actions.gtest.GTest object at 0x7ffbda5fccf8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7ffbda4b23c8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7ffbda4b24a8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]
processing event: '<launch.events.process.signal_process.SignalProcess object at 0x7ffbda4b24e0>'
processing event: '<launch.events.process.signal_process.SignalProcess object at 0x7ffbda4b24e0>' ✓ '<launch.event_handler.EventHandler object at 0x7ffbda58a320>'
3
[(<launch_testing.actions.gtest.GTest object at 0x7ffbda5fccf8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7ffbda4b23c8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7ffbda4b24a8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]
processing event: '<launch.events.process.process_exited.ProcessExited object at 0x7ffbda4b24e0>'
processing event: '<launch.events.process.process_exited.ProcessExited object at 0x7ffbda4b24e0>' ✓ '<launch.event_handlers.on_process_exit.OnProcessExit object at 0x7ffbda58a908>'
2
[(<launch.actions.timer_action.TimerAction object at 0x7ffbda4b23c8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7ffbda4b24a8>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]

With the extra on_process_exit handler (pytest -s test_gtest.py)

platform linux -- Python 3.6.7, pytest-4.2.0, py-1.7.0, pluggy-0.8.1
rootdir: /home/ivanpauno/ros2_ws/src/ros2/launch/launch_testing/test/launch_testing, inifile:
plugins: rerunfailures-6.0, repeat-0.7.0, cov-2.6.1
collected 1 item                                                                                                                                                                                           

test_gtest.py 0
[]
[]
processing event: '<launch.events.include_launch_description.IncludeLaunchDescription object at 0x7f25d5074048>'
processing event: '<launch.events.include_launch_description.IncludeLaunchDescription object at 0x7f25d5074048>' ✓ '<launch.event_handlers.on_include_launch_description.OnIncludeLaunchDescription object at 0x7f25d510f978>'
2
[(<launch_testing.actions.gtest.GTest object at 0x7f25d513ff60>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7f25d50de668>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]
processing event: '<launch.events.process.process_started.ProcessStarted object at 0x7f25d5020160>'
2
[(<launch_testing.actions.gtest.GTest object at 0x7f25d513ff60>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7f25d50de668>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]
processing event: '<launch.events.timer_event.TimerEvent object at 0x7f25d50debe0>'
processing event: '<launch.events.timer_event.TimerEvent object at 0x7f25d50debe0>' ✓ '<launch.event_handler.EventHandler object at 0x7f25d50dec50>'
3
[(<launch_testing.actions.gtest.GTest object at 0x7f25d513ff60>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7f25d5020588>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7f25d5020668>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]
processing event: '<launch.events.process.signal_process.SignalProcess object at 0x7f25d50206a0>'
processing event: '<launch.events.process.signal_process.SignalProcess object at 0x7f25d50206a0>' ✓ '<launch.event_handler.EventHandler object at 0x7f25d50de4e0>'
3
[(<launch_testing.actions.gtest.GTest object at 0x7f25d513ff60>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7f25d5020588>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7f25d5020668>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]
processing event: '<launch.events.process.process_exited.ProcessExited object at 0x7f25d50206a0>'
processing event: '<launch.events.process.process_exited.ProcessExited object at 0x7f25d50206a0>' ✓ '<launch.event_handlers.on_process_exit.OnProcessExit object at 0x7f25d510feb8>'
processing event: '<launch.events.process.process_exited.ProcessExited object at 0x7f25d50206a0>' ✓ '<launch.event_handlers.on_process_exit.OnProcessExit object at 0x7f25d50deac8>'
2
[(<launch.actions.timer_action.TimerAction object at 0x7f25d5020588>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>), (<launch.actions.timer_action.TimerAction object at 0x7f25d5020668>, <Future pending created at /usr/lib/python3.6/asyncio/base_events.py:284>)]
[]
processing event: '<launch.events.shutdown.Shutdown object at 0x7f25d5020160>'
processing event: '<launch.events.shutdown.Shutdown object at 0x7f25d5020160>' ✓ '<launch.event_handlers.on_shutdown.OnShutdown object at 0x7f25d50de588>'
processing event: '<launch.events.shutdown.Shutdown object at 0x7f25d5020160>' ✓ '<launch.event_handlers.on_shutdown.OnShutdown object at 0x7f25d510ffd0>'
0
[]
[]

wjwwood · 2019-02-14T01:13:50Z

Those timers do need to hold up shutdown, but not all timers need to do so (see: #181), but ExecuteProcess action cancels those timers when the process exits before they expire, preventing them from holding up shutdown when the process exits quickly. Perhaps you're missing that part.

I haven't had time to fully review this, so I can't speak to how you're reusing the parts of execute process, though I'm a bit curious why you're not inheriting from it if you're both running a subprocess and wanting it to be killed gracefully (with escalating signals).

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>

I've pushed changes, can't be a reviewer anymore.

hidmic · 2019-03-06T17:32:02Z

@wjwwood the added Test action and its subclasses do inherit from ExecuteProcess. @ivanpauno showed me the issue he's describing above. It's not that timers are holding up the loop, but the shutdown_on_idle feature that (it seems to me) has a race:

The executable exits and a ProcessExit event is sent.
The timers are canceled (i.e. their cancelling future is resolved).
The main loop awakes first and handles the event sent.
The main loop goes on and awaits for more events since the timers' completion futures have not been resolved yet.
The timers' coroutines are awaken and their completion futures resolved.
The main loop never wakes up because no event was emitted nor will be emitted.

hidmic · 2019-03-06T17:32:06Z

On a side note, may I ask you guys @mjcarroll @sloretz (and maybe @wjwwood if you feel like it) to review this? I've touched it, so I can't review it anymore.

wjwwood · 2019-03-06T19:41:01Z

All the waiting occurs here:

launch/launch/launch/launch_service.py

Lines 230 to 237 in d5ace50

    
           while not done: 
        
               done, pending = await asyncio.wait( 
        
                   entity_futures, 
        
                   loop=self.__loop_from_run_thread, 
        
                   timeout=1.0, 
        
                   return_when=asyncio.FIRST_COMPLETED) 
        
               if not done: 
        
                   _logger.debug('still waiting on futures: {}'.format(entity_futures))

Do you see debug output for "still waiting on ..."? I'm not initially convinced by your bullet point scenario above that there is a race, but it's been a while since I've steeped myself in this code, so maybe.

hidmic · 2019-03-06T20:34:20Z

But that's if you've received a shutdown event. In the case described above, we were hoping the loop would trigger the shutdown itself once it detects it's idle:

launch/launch/launch/launch_service.py

Lines 210 to 214 in d5ace50

    
           is_idle = self._is_idle()  # self._entity_future_pairs is pruned here 
        
           if not self.__shutting_down and self.__shutdown_when_idle and is_idle: 
        
               coroutine = self._shutdown(reason='idle', due_to_sigint=False) 
        
               await coroutine 
        
               continue

But it seems to be getting stuck in:

launch/launch/launch/launch_service.py

Lines 239 to 240 in d5ace50

	await process_one_event_task

hidmic · 2019-03-08T16:13:59Z

@mjcarroll ping

hidmic · 2019-03-12T19:17:27Z

@mjcarroll can we get this one in? I need the test action concept for ApexAI/apex_rostest#19.

Running CI just in case:

Linux
Linux-aarch64
macOS
Windows

Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>

…encies. Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>

hidmic · 2019-03-12T19:40:22Z

And that's why running CI is important :)

mjcarroll

I'm not super well-versed in this bit of code, but with green CI it LGTM.

Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>

hidmic · 2019-03-14T11:50:37Z

Alright, CI is passing. Merging! Thanks for taking a look @mjcarroll !

ivanpauno added the in review Waiting for review (Kanban column) label Feb 7, 2019

ivanpauno self-assigned this Feb 7, 2019

ivanpauno requested review from hidmic and mjcarroll February 7, 2019 20:52

hidmic previously requested changes Feb 8, 2019

View reviewed changes

ivanpauno force-pushed the ivanpauno/add-test-actions branch from 16982aa to cea2cb2 Compare February 13, 2019 13:07

ivanpauno force-pushed the ivanpauno/add-test-actions branch from cea2cb2 to 8e6b6c1 Compare February 13, 2019 13:22

ivanpauno force-pushed the ivanpauno/add-test-actions branch from 8e6b6c1 to 74cd5a7 Compare February 14, 2019 12:50

ivanpauno mentioned this pull request Feb 14, 2019

Asyncio traceback when closing #185

Closed

hidmic mentioned this pull request Feb 28, 2019

Ability to run tests with a freshly launched system ApexAI/apex_rostest#9

Open

pbaughman mentioned this pull request Feb 28, 2019

Give special treament to test processes ApexAI/apex_rostest#21

Open

hidmic changed the base branch from hidmic/drop-legacy-launch to master March 6, 2019 16:35

ivanpauno and others added 12 commits March 6, 2019 13:35

Adding GTest and PyTest actions

7c36a07

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Corrected bugs in GTest and PyTest actions

6f26e7b

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Migrated to ament_cmake package. Avoided pytest-timeout dependency

7bac4f8

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Adding missing licenses

15d0c04

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Uncommented all tests

83696f1

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Added substitutions support. Deleted extra getter in Test action

57fa669

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Correct path handling in tests

5206ba5

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Added documentation

0c3a2ec

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Corrected with PR comments.

6393e36

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Reusing ExecuteProcess on_shutdown actions in test timeout

cb6c3c2

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Added non-locking test. Avoided using shell option in pytest execution

909532a

Signed-off-by: ivanpauno <ivanpauno@ekumenlabs.com>

Clean up PyTest and GTest actions and their tests.

0b2b07c

Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>

hidmic force-pushed the ivanpauno/add-test-actions branch from 74cd5a7 to 0b2b07c Compare March 6, 2019 17:18

hidmic added 2 commits March 12, 2019 16:19

Add ament_cmake as launch_testing build dependency.

ac367c6

Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>

Add ament_cmake_gtest and ament_cmake_python as launch_testing depend…

315176e

…encies. Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>

mjcarroll approved these changes Mar 12, 2019

View reviewed changes

hidmic added 2 commits March 13, 2019 12:40

Stop assuming python3 naming in launch_testing PyTest action.

cec56d4

Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>

More launch_testing package.xml fixes.

35551f6

Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>

hidmic force-pushed the ivanpauno/add-test-actions branch from 5c96ac0 to 35551f6 Compare March 13, 2019 19:47

hidmic merged commit 7611f7b into master Mar 14, 2019

hidmic deleted the ivanpauno/add-test-actions branch March 14, 2019 11:50

hidmic removed the in review Waiting for review (Kanban column) label Mar 14, 2019

hidmic mentioned this pull request Mar 14, 2019

Add actions for running gtest and pytests #176

Closed

4 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add test actions #178

Add test actions #178

ivanpauno commented Feb 7, 2019 •

edited by hidmic

Loading

hidmic left a comment

hidmic Feb 8, 2019

hidmic Feb 8, 2019

hidmic Feb 8, 2019

hidmic Feb 8, 2019

ivanpauno Feb 13, 2019

hidmic Feb 8, 2019

ivanpauno Feb 8, 2019

hidmic Feb 11, 2019

hidmic Feb 8, 2019

hidmic Feb 8, 2019

ivanpauno commented Feb 13, 2019 •

edited by hidmic

Loading

wjwwood commented Feb 14, 2019

hidmic commented Mar 6, 2019 •

edited

Loading

hidmic commented Mar 6, 2019

wjwwood commented Mar 6, 2019

hidmic commented Mar 6, 2019

hidmic commented Mar 8, 2019

hidmic commented Mar 12, 2019 •

edited

Loading

hidmic commented Mar 12, 2019

mjcarroll left a comment

hidmic commented Mar 14, 2019

		@@ -12,12 +12,8 @@
		# See the License for the specific language governing permissions and
		# limitations under the License.

		@@ -0,0 +1,48 @@
		# Copyright 2018 Open Source Robotics Foundation, Inc.


		ament_python_install_package(${PROJECT_NAME})

		add_executable(locking dummy_tests/locking.cpp)

Add test actions #178

Add test actions #178

Conversation

ivanpauno commented Feb 7, 2019 • edited by hidmic Loading

hidmic left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ivanpauno commented Feb 13, 2019 • edited by hidmic Loading

wjwwood commented Feb 14, 2019

hidmic commented Mar 6, 2019 • edited Loading

hidmic commented Mar 6, 2019

wjwwood commented Mar 6, 2019

hidmic commented Mar 6, 2019

hidmic commented Mar 8, 2019

hidmic commented Mar 12, 2019 • edited Loading

hidmic commented Mar 12, 2019

mjcarroll left a comment

Choose a reason for hiding this comment

hidmic commented Mar 14, 2019

ivanpauno commented Feb 7, 2019 •

edited by hidmic

Loading

ivanpauno commented Feb 13, 2019 •

edited by hidmic

Loading

hidmic commented Mar 6, 2019 •

edited

Loading

hidmic commented Mar 12, 2019 •

edited

Loading