Fix race condition with up and setting signal handlers.

Also print stdout on wait_for_container().

Signed-off-by: Daniel Nephin <dnephin@docker.com>

compose/cli/main.py

@@ -2,6 +2,7 @@ from __future__ import absolute_import
 from __future__ import print_function
 from __future__ import unicode_literals
 
+import contextlib
 import json
 import logging
 import re
@@ -53,7 +54,7 @@ def main():
         command = TopLevelCommand()
         command.sys_dispatch()
     except KeyboardInterrupt:
-        log.error("\nAborting.")
+        log.error("Aborting.")
         sys.exit(1)
     except (UserError, NoSuchService, ConfigurationError) as e:
         log.error(e.msg)
@@ -629,18 +630,20 @@ class TopLevelCommand(DocoptCommand):
         if detached and cascade_stop:
             raise UserError("--abort-on-container-exit and -d cannot be combined.")
 
+        with up_shutdown_context(project, service_names, timeout, detached):
             to_attach = project.up(
                 service_names=service_names,
                 start_deps=start_deps,
                 strategy=convergence_strategy_from_opts(options),
                 do_build=not options['--no-build'],
                 timeout=timeout,
-            detached=detached
-        )
+                detached=detached)
 
-        if not detached:
+            if detached:
+                return
             log_printer = build_log_printer(to_attach, service_names, monochrome, cascade_stop)
-            attach_to_logs(project, log_printer, service_names, timeout)
+            print("Attaching to", list_containers(log_printer.containers))
+            log_printer.run()
 
     def version(self, project, options):
         """
@@ -740,13 +743,16 @@ def build_log_printer(containers, service_names, monochrome, cascade_stop):
     return LogPrinter(containers, monochrome=monochrome, cascade_stop=cascade_stop)
 
 
-def attach_to_logs(project, log_printer, service_names, timeout):
-    print("Attaching to", list_containers(log_printer.containers))
-    signals.set_signal_handler_to_shutdown()
+@contextlib.contextmanager
+def up_shutdown_context(project, service_names, timeout, detached):
+    if detached:
+        yield
+        return
 
+    signals.set_signal_handler_to_shutdown()
     try:
         try:
-            log_printer.run()
+            yield
         except signals.ShutdownException:
             print("Gracefully stopping... (press Ctrl+C again to force)")
             project.stop(service_names=service_names, timeout=timeout)

tests/acceptance/cli_test.py

@@ -43,7 +43,8 @@ def start_process(base_dir, options):
 def wait_on_process(proc, returncode=0):
     stdout, stderr = proc.communicate()
     if proc.returncode != returncode:
-        print(stderr.decode('utf-8'))
+        print("Stderr: {}".format(stderr))
+        print("Stdout: {}".format(stdout))
         assert proc.returncode == returncode
     return ProcessResult(stdout.decode('utf-8'), stderr.decode('utf-8'))
 
@@ -81,7 +82,6 @@ class ContainerStateCondition(object):
         self.name = name
         self.running = running
 
-    # State.Running == true
     def __call__(self):
         try:
             container = self.client.inspect_container(self.name)
@@ -707,6 +707,17 @@ class CLITestCase(DockerClientTestCase):
         os.kill(proc.pid, signal.SIGTERM)
         wait_on_condition(ContainerCountCondition(self.project, 0))
 
+    @v2_only()
+    def test_up_handles_force_shutdown(self):
+        self.base_dir = 'tests/fixtures/sleeps-composefile'
+        proc = start_process(self.base_dir, ['up', '-t', '200'])
+        wait_on_condition(ContainerCountCondition(self.project, 2))
+
+        os.kill(proc.pid, signal.SIGTERM)
+        time.sleep(0.1)
+        os.kill(proc.pid, signal.SIGTERM)
+        wait_on_condition(ContainerCountCondition(self.project, 0))
+
     def test_run_service_without_links(self):
         self.base_dir = 'tests/fixtures/links-composefile'
         self.dispatch(['run', 'console', '/bin/true'])

tests/fixtures/sleeps-composefile/docker-compose.yml

@@ -0,0 +1,10 @@
+
+version: 2
+
+services:
+  simple:
+    image: busybox:latest
+    command: sleep 200
+  another:
+    image: busybox:latest
+    command: sleep 200

tests/unit/cli/main_test.py

@@ -6,12 +6,9 @@ import logging
 from compose import container
 from compose.cli.errors import UserError
 from compose.cli.formatter import ConsoleWarningFormatter
-from compose.cli.log_printer import LogPrinter
-from compose.cli.main import attach_to_logs
 from compose.cli.main import build_log_printer
 from compose.cli.main import convergence_strategy_from_opts
 from compose.cli.main import setup_console_handler
-from compose.project import Project
 from compose.service import ConvergenceStrategy
 from tests import mock
 from tests import unittest
@@ -49,21 +46,6 @@ class CLIMainTestCase(unittest.TestCase):
         log_printer = build_log_printer(containers, service_names, True, False)
         self.assertEqual(log_printer.containers, containers)
 
-    def test_attach_to_logs(self):
-        project = mock.create_autospec(Project)
-        log_printer = mock.create_autospec(LogPrinter, containers=[])
-        service_names = ['web', 'db']
-        timeout = 12
-
-        with mock.patch('compose.cli.main.signals.signal', autospec=True) as mock_signal:
-            attach_to_logs(project, log_printer, service_names, timeout)
-
-        assert mock_signal.signal.mock_calls == [
-            mock.call(mock_signal.SIGINT, mock.ANY),
-            mock.call(mock_signal.SIGTERM, mock.ANY),
-        ]
-        log_printer.run.assert_called_once_with()
-
 
 class SetupConsoleHandlerTestCase(unittest.TestCase):