Search code examples
gunicornlogrotateuvicorn

Gunicorn worker terminated due to signal 10


[2022-07-07 00:00:19 +0900] [885694] [INFO] Handling signal: usr1
[2022-07-07 00:00:19 +0900] [886183] [INFO] Handling signal: usr1
[2022-07-07 00:00:19 +0900] [886183] [WARNING] Worker with pid 887296 was terminated due to signal 10
[2022-07-07 00:00:19 +0900] [886183] [WARNING] Worker with pid 887293 was terminated due to signal 10
[2022-07-07 00:00:19 +0900] [886183] [WARNING] Worker with pid 887300 was terminated due to signal 10
[2022-07-07 00:00:19 +0900] [886183] [WARNING] Worker with pid 887298 was terminated due to signal 10
[2022-07-07 00:00:19 +0900] [885694] [WARNING] Worker with pid 887294 was terminated due to signal 10
[2022-07-07 00:00:19 +0900] [885694] [WARNING] Worker with pid 887299 was terminated due to signal 10
[2022-07-07 00:00:19 +0900] [887306] [INFO] Booting worker with pid: 887306
[2022-07-07 00:00:19 +0900] [887307] [INFO] Booting worker with pid: 887307
[2022-07-07 00:00:19 +0900] [885694] [WARNING] Worker with pid 887297 was terminated due to signal 10
[2022-07-07 00:00:19 +0900] [885694] [WARNING] Worker with pid 887292 was terminated due to signal 10

Hello,

I have gunicorn with worker-class uvicorn.workers.UvicornWorker. It is set up with logrotate.

However, I see that the worker is terminated and booted again due to USR1 (10) signal, which is odd.

Because when I look at gunicorn implementation, all it seems doing (and should be doing) is reloading the log file!

https://github.com/benoitc/gunicorn/blob/cf55d2cec277f220ebd605989ce78ad1bb553c46/gunicorn/workers/base.py#L181

def handle_usr1(self, sig, frame):
    self.log.reopen_files()

def init_signals(self):
    # reset signaling
    for s in self.SIGNALS:
        signal.signal(s, signal.SIG_DFL)

    # init new signaling 
    signal.signal(signal.SIGQUIT, self.handle_quit)
    signal.signal(signal.SIGTERM, self.handle_exit)
    signal.signal(signal.SIGINT, self.handle_quit)
    signal.signal(signal.SIGWINCH, self.handle_winch)
    signal.signal(signal.SIGUSR1, self.handle_usr1)
    signal.signal(signal.SIGABRT, self.handle_abort)

    # Don't let SIGTERM and SIGUSR1 disturb active requests
    # by interrupting system calls
    signal.siginterrupt(signal.SIGUSR1, False)

https://github.com/benoitc/gunicorn/blob/60d0474a6f5604597180f435a6a03b016783885b/gunicorn/glogging.py#L357

def reopen_files(self):
    if self.cfg.capture_output and self.cfg.errorlog != "-":
        for stream in sys.stdout, sys.stderr:
            stream.flush()

        with self.lock:
            if self.logfile is not None:
                self.logfile.close()
            self.logfile = open(self.cfg.errorlog, 'a+')
            os.dup2(self.logfile.fileno(), sys.stdout.fileno())
            os.dup2(self.logfile.fileno(), sys.stderr.fileno())

    for log in loggers():
        for handler in log.handlers:
            if isinstance(handler, logging.FileHandler):
                handler.acquire()
                try:
                    if handler.stream:
                        handler.close()
                        handler.stream = handler._open()
                finally:
                    handler.release()

Why is it killing my processes (and it does not even terminate them gracefully - it kills them while these workers are running)? Any idea with be appreciated.

Many thanks in advance.


Solution

  • https://github.com/encode/uvicorn/pull/1565

    This was a uvicorn worker bug.