Message283511
I've been seeing some funny behavior in log files form a logging.handlers.RotatingFileHandler.
Here's my handler config snippet, in a "log.cfg":
[handlers]
keys=log_file
[formatters]
keys=access
[formatter_access]
format=%(asctime)s - %(name)s(%(funcName)s:%(lineno)s)[%(process)d] - %(levelname)s: %(message)s
datefmt=%Y-%m-%d %H:%M:%S
class=logging.Formatter
[handler_log_file]
class=logging.handlers.RotatingFileHandler
formatter=access
args=('/var/log/ml-api/access.log', 'a', 10000000, 16, 'utf8')
Specified using:
/usr/local/bin/gunicorn --worker-class=gevent --bind unix:ml-api.sock -m 007 --workers=8 --log-config=log.cfg --log-level=DEBUG app
I ran this script to show the progression of log file creation:
while true ; do ls -lrt && sleep 10; done
Initially there's one incrementing log file, fine:
-rw-r--r-- 1 ubuntu www-data 9765042 Dec 16 17:50 access.log
total 9572
-rw-r--r-- 1 ubuntu www-data 9796828 Dec 16 17:50 access.log
total 9656
-rw-r--r-- 1 ubuntu www-data 9881053 Dec 16 17:50 access.log
total 9708
-rw-r--r-- 1 ubuntu www-data 9936776 Dec 16 17:50 access.log
total 9756
-rw-r--r-- 1 ubuntu www-data 9984782 Dec 16 17:50 access.log
total 9816
But as soon as it gets rotated, I immediately get 8 log files:
-rw-r--r-- 1 ubuntu www-data 9999911 Dec 16 17:50 access.log.7
-rw-r--r-- 1 ubuntu www-data 2578 Dec 16 17:50 access.log.5
-rw-r--r-- 1 ubuntu www-data 2578 Dec 16 17:50 access.log.3
-rw-r--r-- 1 ubuntu www-data 6871 Dec 16 17:50 access.log.2
-rw-r--r-- 1 ubuntu www-data 5122 Dec 16 17:50 access.log.1
-rw-r--r-- 1 ubuntu www-data 11165 Dec 16 17:50 access.log.4
-rw-r--r-- 1 ubuntu www-data 1718 Dec 16 17:50 access.log
-rw-r--r-- 1 ubuntu www-data 2905 Dec 16 17:50 access.log.6
total 9864
-rw-r--r-- 1 ubuntu www-data 9999911 Dec 16 17:50 access.log.7
-rw-r--r-- 1 ubuntu www-data 8921 Dec 16 17:50 access.log.6
-rw-r--r-- 1 ubuntu www-data 15460 Dec 16 17:50 access.log
-rw-r--r-- 1 ubuntu www-data 10313 Dec 16 17:51 access.log.2
-rw-r--r-- 1 ubuntu www-data 7699 Dec 16 17:51 access.log.3
-rw-r--r-- 1 ubuntu www-data 21471 Dec 16 17:51 access.log.4
-rw-r--r-- 1 ubuntu www-data 6874 Dec 16 17:51 access.log.5
-rw-r--r-- 1 ubuntu www-data 11989 Dec 16 17:51 access.log.1
total 9892
-rw-r--r-- 1 ubuntu www-data 9999911 Dec 16 17:50 access.log.7
-rw-r--r-- 1 ubuntu www-data 7699 Dec 16 17:51 access.log.3
-rw-r--r-- 1 ubuntu www-data 12849 Dec 16 17:51 access.log.1
-rw-r--r-- 1 ubuntu www-data 14936 Dec 16 17:51 access.log.6
-rw-r--r-- 1 ubuntu www-data 30068 Dec 16 17:51 access.log.4
-rw-r--r-- 1 ubuntu www-data 19755 Dec 16 17:51 access.log
-rw-r--r-- 1 ubuntu www-data 11170 Dec 16 17:51 access.log.5
-rw-r--r-- 1 ubuntu www-data 15466 Dec 16 17:51 access.log.2
total 9932
Is this a consequence of the gunicorn --workers=8?
Does logging.handlers.RotatingFileHandler not work with gunicorn workers?
I tried --worker-class=gevent as well with the same result. |
|
Date |
User |
Action |
Args |
2016-12-17 20:00:59 | Bruce Edge | set | recipients:
+ Bruce Edge |
2016-12-17 20:00:59 | Bruce Edge | set | messageid: <1482004859.28.0.622019934032.issue29001@psf.upfronthosting.co.za> |
2016-12-17 20:00:59 | Bruce Edge | link | issue29001 messages |
2016-12-17 20:00:58 | Bruce Edge | create | |
|