diff --git a/webvirtcloud/gunicorn_worker.py b/webvirtcloud/gunicorn_worker.py index 98c3a990..6672c009 100644 --- a/webvirtcloud/gunicorn_worker.py +++ b/webvirtcloud/gunicorn_worker.py @@ -33,6 +33,10 @@ class Worker(ThreadWorker): with self.started_lock: oldest = min(self.started.values(), default=None) if oldest is not None and time.monotonic() - oldest > self.cfg.timeout: - self.log.critical("A request ran past %s s: the worker exits", self.cfg.timeout) + # a log write can block (a full pipe, a handler a stuck thread holds): it gets a second + log = threading.Thread(target=self.log.critical, daemon=True, + args=("A request ran past %s s: the worker exits", self.cfg.timeout)) + log.start() + log.join(1) os._exit(1) # its threads cannot be stopped, and exit() would wait for them super().notify() diff --git a/webvirtcloud/tests/test_gunicorn_worker.py b/webvirtcloud/tests/test_gunicorn_worker.py index 6bea26ac..b91ac3e6 100644 --- a/webvirtcloud/tests/test_gunicorn_worker.py +++ b/webvirtcloud/tests/test_gunicorn_worker.py @@ -50,6 +50,17 @@ class WorkerTestCase(unittest.TestCase): w.notify() exit_.assert_called_once_with(1) notify.assert_not_called() + w.log.critical.assert_called_once() + + def test_a_log_that_blocks_does_not_keep_the_worker_from_exiting(self): + w = worker() + w.started[1] = time.monotonic() - 601 + w.log.critical.side_effect = lambda *args: threading.Event().wait(30) + started = time.monotonic() + with patch("os._exit", side_effect=SystemExit) as exit_, self.assertRaises(SystemExit): + w.notify() + exit_.assert_called_once_with(1) + self.assertLess(time.monotonic() - started, 2) if __name__ == "__main__":