Make the SIGKILL timeout configurable with start --timeout

CHANGELOG.rst

@@ -6,6 +6,13 @@ project endeavours to adhere to `Semantic Versioning`_.
 
 .. _Semantic Versioning: http://semver.org/
 
+Unreleased
+----------
+
+* ADDED: ``honcho start --timeout N`` (``-t N``) sets how many seconds
+  processes have to shut down gracefully before Honcho sends them SIGKILL, as
+  with Foreman. The default is still 5 seconds.
+
 2.0.0 -- 2024-10-06
 -------------------
 

doc/using_procfiles.rst

@@ -113,6 +113,15 @@ If you supply multiple comma-separated arguments to the ``-e`` option, Honcho wi
     ANIMAL_1=giraffe
     ANIMAL_2=elephant
 
+When one process exits, or when Honcho receives SIGINT or SIGTERM, Honcho sends
+SIGTERM to all the remaining processes. Any process still running 5 seconds
+after the first one exited is sent SIGKILL. Processes that need longer to shut
+down gracefully, such as a job queue worker finishing its current job, can be
+given more time with the ``-t``/``--timeout`` option to ``honcho start``, as
+with Foreman::
+
+    $ honcho start --timeout 30
+
 Differences to Foreman
 ----------------------
 

honcho/command.py

@@ -9,7 +9,7 @@
 
 from honcho import __version__, compat, environ
 from honcho.environ import Env
-from honcho.manager import Manager
+from honcho.manager import KILL_WAIT, Manager
 from honcho.printer import Printer
 from honcho.process import Popen
 
@@ -240,7 +240,8 @@ def command_start(args):
 
     manager = Manager(Printer(sys.stdout,
                               colour=(not args.no_colour),
-                              prefix=(not args.no_prefix)))
+                              prefix=(not args.no_prefix)),
+                      kill_wait=args.timeout)
 
     for p in environ.expand_processes(processes,
                                       concurrency=concurrency,
@@ -271,6 +272,11 @@ def command_start(args):
     '-q', '--quiet',
     help='process names for which to suppress output',
     type=str, metavar='process1,process2,process3')
+parser_start.add_argument(
+    '-t', '--timeout',
+    help=('seconds processes have to shut down gracefully before they are '
+          f'sent SIGKILL (default: {KILL_WAIT})'),
+    type=int, default=KILL_WAIT, metavar='N')
 parser_start.add_argument(
     'processes', nargs='*',
     help='process(es) to start (default: all processes)')

honcho/manager.py

@@ -46,10 +46,14 @@ class Manager(object):
     #: this will contain a return code that can be used with `sys.exit`.
     returncode = None
 
-    def __init__(self, printer=None):
+    def __init__(self, printer=None, kill_wait=KILL_WAIT):
         self.events = multiprocessing.Queue()
         self.returncode = None
 
+        #: Seconds the remaining processes get to exit after the first one
+        #: stops, before they are sent SIGKILL.
+        self.kill_wait = kill_wait
+
         self._colours = get_colours()
         self._clock = datetime.datetime
         self._procmgr = ProcessManager()
@@ -133,10 +137,10 @@ def _terminate(signum, frame):
                 self.terminate()
 
             if exit_start is not None:
-                # If we've been in this loop for more than KILL_WAIT seconds,
+                # If we've been in this loop for more than kill_wait seconds,
                 # it's time to kill all remaining children.
                 waiting = self._clock.now() - exit_start
-                if waiting > datetime.timedelta(seconds=KILL_WAIT):
+                if waiting > datetime.timedelta(seconds=self.kill_wait):
                     self.kill()
 
     def terminate(self):

tests/integration/test_start.py

@@ -59,3 +59,38 @@ def test_start_returncode(testenv):
     ret, out, err = testenv.run_honcho(['start'])
 
     assert ret == 42
+
+
+draining = textwrap.dedent("""
+    import signal
+    import sys
+    import time
+
+    def drain(signum, frame):
+        time.sleep(1)
+        print("drained", flush=True)
+        sys.exit(0)
+
+    signal.signal(signal.SIGTERM, drain)
+    print("ready", flush=True)
+    time.sleep(30)
+""")
+
+
+@pytest.mark.skipif(sys.platform == 'win32', reason='relies on POSIX signals')
+@pytest.mark.parametrize('testenv', [{
+    'Procfile': '\n'.join([
+        'quick: {0} -c "import time; time.sleep(1)"'.format(python_bin),
+        'slow: {0} draining.py'.format(python_bin),
+    ]),
+    'draining.py': draining,
+}], indirect=True)
+@pytest.mark.parametrize(('args', 'drained'), [
+    (['start'], True),
+    (['start', '--timeout', '0'], False),
+])
+def test_start_timeout(testenv, args, drained):
+    _, out, _ = testenv.run_honcho(args)
+
+    assert 'ready' in out
+    assert ('drained' in out) == drained

tests/test_command.py

@@ -1,6 +1,7 @@
 import pytest
 
 from honcho import command
+from honcho.manager import KILL_WAIT
 
 
 # All of the following groups of commands should parse to the same result
@@ -88,3 +89,41 @@ def _read_env(app_root, env):
     args = command.parser.parse_args(['start', '-f', 'Procfile.cli'])
     result = command.map_from(args)['procfile']
     assert result == 'Procfile.cli'
+
+
+def test_start_timeout():
+    # Nothing specified -- same as the manager's default
+    args = command.parser.parse_args(['start'])
+    assert args.timeout == KILL_WAIT
+
+    args = command.parser.parse_args(['start', '-t', '30'])
+    assert args.timeout == 30
+
+    args = command.parser.parse_args(['start', '--timeout', '0'])
+    assert args.timeout == 0
+
+
+def test_start_passes_timeout_to_manager(monkeypatch, tmp_path):
+    (tmp_path / 'Procfile').write_text('web: true\n')
+    created = {}
+
+    class FakeManager(object):
+        returncode = 0
+
+        def __init__(self, printer, kill_wait):
+            created['kill_wait'] = kill_wait
+
+        def add_process(self, *args, **kwargs):
+            pass
+
+        def loop(self):
+            pass
+
+    monkeypatch.setattr(command, 'Manager', FakeManager)
+    args = command.parser.parse_args(
+        ['-d', str(tmp_path), 'start', '-t', '30'])
+
+    with pytest.raises(SystemExit):
+        command.command_start(args)
+
+    assert created['kill_wait'] == 30

tests/test_manager.py

@@ -4,7 +4,7 @@
 
 import pytest
 
-from honcho.manager import SYSTEM_PRINTER_NAME, Manager
+from honcho.manager import KILL_WAIT, SYSTEM_PRINTER_NAME, Manager
 from honcho.printer import Message
 
 HISTORIES = {
@@ -23,6 +23,12 @@
                      ('foo', 'stop', {'returncode': 0}),
                      ('bar', 'stop', {'returncode': 0})),
     },
+    'straggler': {
+        'processes': {'bar': {}, 'foo': {}},
+        'messages': (('foo', 'start', {'pid': 123}),
+                     ('bar', 'start', {'pid': 124}),
+                     ('foo', 'stop', {'returncode': 0})),
+    },
     'returncode': {
         'processes': {'bar': {}, 'foo': {}},
         'messages': (('foo', 'start', {'pid': 123}),
@@ -59,6 +65,44 @@ def kill(self, pid):
         pass
 
 
+class TickingClock(object):
+    """A clock that moves forward one second every time it is read."""
+
+    def __init__(self):
+        self.current = datetime.datetime(2012, 8, 11, 12, 42)
+
+    def now(self):
+        self.current += datetime.timedelta(seconds=1)
+        return self.current
+
+
+class RecordingProcessManager(object):
+    """Records when processes are signalled, and stops any process it kills."""
+
+    def __init__(self, manager, clock):
+        self.manager = manager
+        self.clock = clock
+        self.terminated_at = None
+        self.killed_at = None
+        self.killed_pids = []
+
+    def terminate(self, pid):
+        if self.terminated_at is None:
+            self.terminated_at = self.clock.current
+
+    def kill(self, pid):
+        if self.killed_at is None:
+            self.killed_at = self.clock.current
+        self.killed_pids.append(pid)
+        name = next(n for n, p in self.manager._processes.items()
+                    if p.get('pid') == pid)
+        self.manager.events.put(Message(type='stop',
+                                        data={'returncode': -9},
+                                        time=datetime.datetime.now(),
+                                        name=name,
+                                        colour=None))
+
+
 class FakeProcess(object):
 
     def __init__(self, cmd, name=None, colour=None, quiet=None, env=None, cwd=None):
@@ -210,3 +254,29 @@ def test_printer_receives_lines_after_stop(self):
         self.run_history('output_after_stop')
         assert self.p.got_line(b'fishmongers\n')
         assert self.p.got_line(b'butchers\n')
+
+    def run_straggler(self, **kwargs):
+        clock = TickingClock()
+        manager = Manager(printer=self.p, **kwargs)
+        manager._clock = clock
+        manager._procmgr = RecordingProcessManager(manager, clock)
+        Harness(HISTORIES['straggler'], manager).run()
+        return manager._procmgr
+
+    # The clock also moves when the manager stamps its own log lines, so the
+    # kill may land up to two ticks after the wait has run out.
+
+    def test_kill_waits_five_seconds_by_default(self):
+        procmgr = self.run_straggler()
+        waited = procmgr.killed_at - procmgr.terminated_at
+        assert datetime.timedelta(seconds=KILL_WAIT) < waited
+        assert waited <= datetime.timedelta(seconds=KILL_WAIT + 2)
+        assert procmgr.killed_pids == [124]
+
+    @pytest.mark.parametrize('kill_wait', [0, 10])
+    def test_kill_waits_for_kill_wait_seconds(self, kill_wait):
+        procmgr = self.run_straggler(kill_wait=kill_wait)
+        waited = procmgr.killed_at - procmgr.terminated_at
+        assert datetime.timedelta(seconds=kill_wait) < waited
+        assert waited <= datetime.timedelta(seconds=kill_wait + 2)
+        assert procmgr.killed_pids == [124]