Merge pull request #98 from chriskuehl/add-some-more-logging-to-tests

Be more generous with sleeps in tests, add more test output on fail

testing/__init__.py

@@ -2,6 +2,7 @@ import os
 import re
 import signal
 import sys
+import time
 from contextlib import contextmanager
 from subprocess import PIPE
 from subprocess import Popen
@@ -75,3 +76,19 @@ def process_state(pid):
     status = LocalPath('/proc').join(str(pid), 'status').read()
     m = re.search('^State:\s+[A-Z] \(([a-z]+)\)$', status, re.MULTILINE)
     return m.group(1)
+
+
+def sleep_until(fn, timeout=1.5):
+    """Sleep until fn succeeds, or we time out."""
+    interval = 0.01
+    so_far = 0
+    while True:
+        try:
+            fn()
+        except:
+            if so_far >= timeout:
+                raise
+        else:
+            break
+        time.sleep(interval)
+        so_far += interval

tests/child_processes_test.py

@@ -2,7 +2,6 @@ import os
 import re
 import signal
 import sys
-import time
 from subprocess import PIPE
 from subprocess import Popen
 
@@ -10,6 +9,7 @@ import pytest
 
 from testing import is_alive
 from testing import pid_tree
+from testing import sleep_until
 
 
 def spawn_and_kill_pipeline():
@@ -18,15 +18,15 @@ def spawn_and_kill_pipeline():
         'sh', '-c',
         "yes 'oh, hi' | tail & yes error | tail >&2"
     ))
-    time.sleep(0.1)
+
+    def assert_living_pids():
+        assert len(living_pids(pid_tree(os.getpid()))) == 6
+
+    sleep_until(assert_living_pids)
 
     pids = pid_tree(os.getpid())
-    assert len(living_pids(pids)) == 6
-
     proc.send_signal(signal.SIGTERM)
     proc.wait()
-
-    time.sleep(0.1)
     return pids
 
 
@@ -36,11 +36,15 @@ def living_pids(pids):
 
 @pytest.mark.usefixtures('both_debug_modes', 'setsid_enabled')
 def test_setsid_signals_entire_group():
-    """When dumb-init is running in setsid mode, it should only signal the
-    entire process group rooted at it.
+    """When dumb-init is running in setsid mode, it should signal the entire
+    process group rooted at it.
     """
     pids = spawn_and_kill_pipeline()
-    assert len(living_pids(pids)) == 0
+
+    def assert_no_living_pids():
+        assert len(living_pids(pids)) == 0
+
+    sleep_until(assert_no_living_pids)
 
 
 @pytest.mark.usefixtures('both_debug_modes', 'setsid_disabled')
@@ -50,9 +54,12 @@ def test_no_setsid_doesnt_signal_entire_group():
     """
     pids = spawn_and_kill_pipeline()
 
-    living = living_pids(pids)
-    assert len(living) == 4
-    for pid in living:
+    def assert_four_living_pids():
+        assert len(living_pids(pids)) == 4
+
+    sleep_until(assert_four_living_pids)
+
+    for pid in living_pids(pids):
         os.kill(pid, signal.SIGKILL)
 
 

tests/cli_test.py

@@ -92,7 +92,7 @@ def test_verbose(flag):
             b'\[dumb-init\] Child exited with status 0\. Goodbye\.\n$'
         ),
         stderr,
-    )
+    ), stderr
 
 
 @pytest.mark.parametrize('flag1', ['-v', '--verbose'])

tests/shell_background_test.py

@@ -1,11 +1,11 @@
 import os
-import time
 from signal import SIGCONT
 
 import pytest
 
 from testing import print_signals
 from testing import process_state
+from testing import sleep_until
 from testing import SUSPEND_SIGNALS
 
 
@@ -23,17 +23,10 @@ def test_shell_background_support_setsid():
             # both should now suspend
             proc.send_signal(signum)
 
-            for _ in range(1000):
-                time.sleep(0.001)
-                try:
-                    assert process_state(proc.pid) == 'stopped'
-                    assert process_state(pid) == 'stopped'
-                except AssertionError:
-                    pass
-                else:
-                    break
-            else:
-                raise RuntimeError('Timed out waiting for processes to stop.')
+            def assert_both_stopped():
+                assert process_state(proc.pid) == process_state(pid) == 'stopped'
+
+            sleep_until(assert_both_stopped)
 
             # and then both wake up again
             proc.send_signal(SIGCONT)