benoitc / gunicorn

gunicorn 'Green Unicorn' is a WSGI HTTP Server for UNIX, fast clients and sleepy applications.
http://www.gunicorn.org
Other
9.71k stars 1.74k forks source link

Ignoring RootLogger while doing reopen_files #1427

Closed rocknrollnerd closed 1 month ago

rocknrollnerd commented 7 years ago

Hi!

I've encountered what seems to be the instance of the old logrotate bug when despite of sending USR1-signal correctly after rotating gunicorn still continues to log to the old logfile. However, the issue seemed to occur with root (top-level) logger only.

My logging config looks somewhat like this:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'file_root': {
            'class': 'logging.FileHandler',
            'filename': '/var/log/myproject/main.log'
        },
        'file_a': {
            'class': 'logging.FileHandler',
            'filename': '/var/log/myproject/a.log'
        },
        'file_b': {
            'class': 'logging.FileHandler',
            'filename': '/var/log/myproject/b.log'
        },
    },
    'loggers': {
        '': {
            'level': logging.INFO,
            'handlers': ['file_root']
        },
        'a': {
            'level': 'INFO',
            'handlers': ['file_a']
        },
        'b': {
            'level': 'INFO',
            'handlers': ['file_b']
        },
    }
}

a and b loggers are rotated correctly, however '' (root) logger is not.

This seems to happen because loggers() function only returns child loggers, ignoring root logger itself. Could that be fixed just by adding something like return [logging.getLogger(name) for name in existing] + [root]?

Thanks.

kahlertl commented 7 years ago

I can confirm this bug. We run gunicorn in a Docker container with the following configs

/app/config/gunicorn.py:

#
# Gunicorn Settings
#
worker_class = 'aiohttp.worker.GunicornWebWorker'

bind = '0.0.0.0:5000'

pid = '/run/gunicorn.pid'

# @see https://github.com/KeepSafe/aiohttp/issues/705
access_log_format = '%a %l %u %t "%r" %s %b'

# Number of web worker processes that should be spawned
workers = 4

# Log to stdout / stderr
accesslog = '/app/logs/gunicorn/access.log'
errorlog  = '/app/logs/gunicorn/error.log'

/etc/logrotate.d/gunicorn:

/app/logs/gunicorn/*.log {
    daily
    missingok
    rotate 52
    compress
    delaycompress
    notifempty
    create 640 root root
    sharedscripts
    postrotate
        [ ! -f /run/gunicorn.pid ] || kill -USR1 `cat /run/gunicorn.pid`
    endscript
}

/app/logs/gunicorn/access.log.1 and app/logs/gunicorn/error.log.1 are correctly moved, but gunicorn still writes into this files.

tuukkamustonen commented 7 years ago

Is this a duplicate of https://github.com/benoitc/gunicorn/issues/1317?

I am using gunicorn 19.6.0 and can't reproduce this, but then, I don't provide custom --log-config anyway. Does it reproduce only when you do? I configure logging within (at the start of) my WSGI application. In gunicorn configs I just:

accesslog = '...'
access_log_format = '...'
errorlog = '...'
loglevel = 'info'

And I send -USR1 by a harsh killall instead of by PID (until I have time to improve that).