Emit dots on travis to avoid timeout (#867)

The current method of running a background sleep until travis is
finished is causing integration test runs to pass even when they should
be failing.

Instead, update the code to emit dots itself.

7 files changed, 56 insertions, 25 deletions

diff --git a/.travis.yml b/.travis.yml
index 690ab644..e112789a 100644
--- a/.travis.yml
+++ b/.travis.yml
@@ -121,16 +121,7 @@ matrix:
             # Use sudo to get a new shell where we're in the sbuild group
             - sudo -E su $USER -c 'sbuild --nolog --no-run-lintian --verbose --dist=xenial cloud-init_*.dsc'
             - ssh-keygen -P "" -q -f ~/.ssh/id_rsa
-            - sg lxd -c 'CLOUD_INIT_CLOUD_INIT_SOURCE="$(ls *.deb)" tox -e integration-tests-ci' &
-            - |
-              SECONDS=0
-              while [ -e /proc/$! ]; do
-                if [ "$SECONDS" -gt "570" ]; then
-                  echo -n '.'
-                  SECONDS=0
-                fi
-                sleep 10
-              done
+            - sg lxd -c 'CLOUD_INIT_CLOUD_INIT_SOURCE="$(ls *.deb)" tox -e integration-tests-ci'
         - python: 3.5
           env:
               TOXENV=xenial
diff --git a/tests/integration_tests/bugs/test_lp1813396.py b/tests/integration_tests/bugs/test_lp1813396.py
index 7ad0e809..68b96b1d 100644
--- a/tests/integration_tests/bugs/test_lp1813396.py
+++ b/tests/integration_tests/bugs/test_lp1813396.py
@@ -6,7 +6,7 @@ Ensure gpg is called with no tty flag.
 import pytest
 
 from tests.integration_tests.instances import IntegrationInstance
-from tests.integration_tests.log_utils import verify_ordered_items_in_text
+from tests.integration_tests.util import verify_ordered_items_in_text
 
 
 USER_DATA = """\
diff --git a/tests/integration_tests/clouds.py b/tests/integration_tests/clouds.py
index a6026309..11b57407 100644
--- a/tests/integration_tests/clouds.py
+++ b/tests/integration_tests/clouds.py
@@ -25,6 +25,7 @@ from tests.integration_tests.instances import (
     IntegrationOciInstance,
     IntegrationLxdInstance,
 )
+from tests.integration_tests.util import emit_dots_on_travis
 
 try:
     from typing import Optional
@@ -167,7 +168,8 @@ class IntegrationCloud(ABC):
             "\n".join("{}={}".format(*item) for item in kwargs.items())
         )
 
-        pycloudlib_instance = self._perform_launch(kwargs)
+        with emit_dots_on_travis():
+            pycloudlib_instance = self._perform_launch(kwargs)
         log.info('Launched instance: %s', pycloudlib_instance)
         instance = self.get_instance(pycloudlib_instance, settings)
         if kwargs.get('wait', True):
diff --git a/tests/integration_tests/log_utils.py b/tests/integration_tests/log_utils.py
deleted file mode 100644
index 40baae7b..00000000
--- a/tests/integration_tests/log_utils.py
+++ /dev/null
@@ -1,11 +0,0 @@
-def verify_ordered_items_in_text(to_verify: list, text: str):
-    """Assert all items in list appear in order in text.
-
-    Examples:
-      verify_ordered_items_in_text(['a', '1'], 'ab1')  # passes
-      verify_ordered_items_in_text(['1', 'a'], 'ab1')  # raises AssertionError
-    """
-    index = 0
-    for item in to_verify:
-        index = text[index:].find(item)
-        assert index > -1, "Expected item not found: '{}'".format(item)
diff --git a/tests/integration_tests/modules/test_power_state_change.py b/tests/integration_tests/modules/test_power_state_change.py
index eebe6608..5f3a32ac 100644
--- a/tests/integration_tests/modules/test_power_state_change.py
+++ b/tests/integration_tests/modules/test_power_state_change.py
@@ -9,7 +9,7 @@ import pytest
 
 from tests.integration_tests.clouds import IntegrationCloud
 from tests.integration_tests.instances import IntegrationInstance
-from tests.integration_tests.log_utils import verify_ordered_items_in_text
+from tests.integration_tests.util import verify_ordered_items_in_text
 
 USER_DATA = """\
 #cloud-config
diff --git a/tests/integration_tests/util.py b/tests/integration_tests/util.py
new file mode 100644
index 00000000..3ef12358
--- /dev/null
+++ b/tests/integration_tests/util.py
@@ -0,0 +1,49 @@
+import logging
+import multiprocessing
+import os
+import time
+from contextlib import contextmanager
+
+log = logging.getLogger('integration_testing')
+
+
+def verify_ordered_items_in_text(to_verify: list, text: str):
+    """Assert all items in list appear in order in text.
+
+    Examples:
+      verify_ordered_items_in_text(['a', '1'], 'ab1')  # passes
+      verify_ordered_items_in_text(['1', 'a'], 'ab1')  # raises AssertionError
+    """
+    index = 0
+    for item in to_verify:
+        index = text[index:].find(item)
+        assert index > -1, "Expected item not found: '{}'".format(item)
+
+
+@contextmanager
+def emit_dots_on_travis():
+    """emit a dot every 60 seconds if running on Travis.
+
+    Travis will kill jobs that don't emit output for a certain amount of time.
+    This context manager spins up a background process which will emit a dot to
+    stdout every 60 seconds to avoid being killed.
+
+    It should be wrapped selectively around operations that are known to take a
+    long time.
+    """
+    if os.environ.get('TRAVIS') != "true":
+        # If we aren't on Travis, don't do anything.
+        yield
+        return
+
+    def emit_dots():
+        while True:
+            log.info(".")
+            time.sleep(60)
+
+    dot_process = multiprocessing.Process(target=emit_dots)
+    dot_process.start()
+    try:
+        yield
+    finally:
+        dot_process.terminate()
diff --git a/tox.ini b/tox.ini
index 3158ebd5..bf8cb78b 100644
--- a/tox.ini
+++ b/tox.ini
@@ -153,7 +153,7 @@ deps =
 
 [testenv:integration-tests-ci]
 commands = {envpython} -m pytest --log-cli-level=INFO {posargs:tests/integration_tests}
-passenv = CLOUD_INIT_* SSH_AUTH_SOCK OS_*
+passenv = CLOUD_INIT_* SSH_AUTH_SOCK OS_* TRAVIS
 deps =
     -r{toxinidir}/integration-requirements.txt
 setenv =