Logging in signal handlers may be unsafe

[vanschelven]

In the arbiter's signal-handling code, there are many uses of logging. E.g.

https://github.com/benoitc/gunicorn/blob/master/gunicorn/arbiter.py#L252

however, the docs say this:

If you are implementing asynchronous signal handlers using the signal module, you may not be able to use logging from within such handlers. This is because lock implementations in the threading module are not always re-entrant, and so cannot be invoked from such signal handlers.

https://docs.python.org/3/library/logging.html#thread-safety

elsewhere Gregory Smith says the following:

I'd still rank "doing IO" even in a python signal handler (which is effectively possible to be executed between any given bytecode and between some operations using the C API that check the internal signal context) as a bad idea.

What the consequences of the above remarks are... may depend on how many signals you send.

[pajod]

Related: #2816

We do have suggested changes, notably #3148 attempting to address this.

[hendrikmuhs]

I've run into various issues issues with signals/logging/uvicorn. This issue contains the root cause for the problems we saw.

A summary that explains/connects various reported issues and might help others running into this:

• logging is ok for most of the signals, because signals are not handled directly, but added to a queue which moves handling to the main thread
• except for SIGCHLD, this signal is not queued by design
• SIGCHLD handling calls logging iff the exit code of the worker != 0, which might result in RuntimeError: reentrant call inside <_io.BufferedWriter name='<stderr>'> (# 2667)  #2816
• the reason for a non-zero exit code can be the use of uvicorn workers: Bad file descriptor problem still exists as of today with uvicorn workers #3013
• the uvicorn socket error on exit is non-critical, however it can cause a cascade effect: uvicorn error -> non-zero exit code -> logging call -> Runtime Error
• if you use SIGHUP to reload workers, the almost simultaneous restart of workers cause a lot of these errors and in some situations can cause the the master process to get stuck

Mitigation

The issue can be mitigated by decoupling logging using QueueHandler and QueueListener, provided by a custom logconfig(_dict/_json)