From 2d7e23864e99eb47c7348896b28139feb56aa075 Mon Sep 17 00:00:00 2001 From: catborise Date: Tue, 3 Nov 2026 00:12:55 +0300 Subject: [PATCH] fix(webvirtcloud): a worker past its request timeout exits even if its log blocks The worker wrote "A request ran past ... s" and then exited. A log write can block, on a full pipe or on a handler lock a stuck request thread holds; the worker would then not exit, and gunicorn's own heartbeat timeout would end it only some ten minutes later, after the short claims it holds had expired. The line is written from another thread; the worker waits for it at most a second, then exits. --- webvirtcloud/gunicorn_worker.py | 6 +++++- webvirtcloud/tests/test_gunicorn_worker.py | 11 +++++++++++ 2 files changed, 16 insertions(+), 1 deletion(-) 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__":