3

EDIT:

Looks like other people are having a similar issue with TimedRotatingFileHandler.

Python TimedRotatingFileHandler not rotating at midnight till something new is written to the log file. How to fix this?

Why doesn't my TimedRotatingFileHandler rotate at midnight?

Apparently, the logs don't rotate unless there is some activity happening in the logs. Is there a way I can achieve the scheduled rotating functionality I want using the builtin Handlers without having to create a custom rotator?


ORIGINAL POST:

I'm using the TimedRotatingFileHandler of Python's logging module to rotate my logs regularly.

I've specified the configurations in logging.conf for my app's loggers and handlers as such:

[logger_worker]
level=DEBUG
propogate=0
qualname=worker
handlers=workerHandler

[handler_workerHandler]
class=handlers.TimedRotatingFileHandler
level=DEBUG
formatter=standardFormatter
args=("/var/log/app/worker.log","M",1,30,None,False,False)
  • Note: for testing purposes I've configured the handler to rotate the logs on every minute, but ideally the logs will be rotated on a daily basis at midnight.

In my app, I am creating the logger like this:

logging.config.fileConfig("logging.conf")
log = logging.getLogger("worker")

log.debug('Hello world')

It is not working as I expected it to work:

  1. It is not rotating all the logs
  2. It is not rotating every minute as it is configured to do

Observe the ls -l output of the log directory:

-rw-r--r-- 1 root root       0 Apr 19 18:22 dpv.log
-rw-r----- 1 root root    5092 Apr 20 11:47 emperor.log
-rw-r--r-- 1 root root   88939 Apr 20 11:47 uwsgi.log
-rw-r--r-- 1 root root     494 Apr 20 11:46 worker.log
-rw-r--r-- 1 root root   45906 Apr 20 02:08 worker.log.2016-04-20_02-08
-rw-r--r-- 1 root root     494 Apr 20 11:34 worker.log.2016-04-20_11-34
-rw-r--r-- 1 root root     494 Apr 20 11:36 worker.log.2016-04-20_11-36
-rw-r--r-- 1 root root     494 Apr 20 11:44 worker.log.2016-04-20_11-44

What am I doing wrong? Is it possible to rotate the logs on a scheduled term even when nothing is being written to the logs?

Community
  • 1
  • 1
tamjd1
  • 876
  • 1
  • 10
  • 29
  • How oft did you call `log.debug('Hello world')`? – qvpham Apr 20 '16 at 16:21
  • @julivico, The app is full of logs in many places. For each request that comes the app logs approximately 100+ lines of logs in various places. So I guess that depends on how many requests there are in a given period of time. The incoming requests may be 50/second or 1/hour, it's total variable and up to the users. But I still want the logs to rotate even if there is no activity. Possible? – tamjd1 Apr 20 '16 at 16:27
  • If there is no activity, the logging is inactive too. Because of that, the logs will be not rotated. I think, you won't have this problem with daily rotating. Or you can use `logrotate` on linux system – qvpham Apr 20 '16 at 16:37
  • I will consider `logrotate` as an alternative... Thanks @julivico. – tamjd1 Apr 20 '16 at 16:45

2 Answers2

1

Seems TimedRotatingFileHandler doesn't have the functionality that you need. You can try the following function for rotating the log files at the certain time.

def log_rollover(folder_path):
    # folder_path: the absolute path to your log folder 
    today = str(datetime.date.today()).replace('-', '')
    list_of_files = os.listdir(folder_path)
    for log_file in list_of_files:
        file_path = folder_path + '/' + log_file
        if log_file.endswith('.log') and os.stat(file_path).st_size > 0:
            new_file_path = file_path.split('.')[-2] + '-' + today + '.log'
            subprocess.check_call(['cp', file_path, new_file_path])
            subprocess.check_call(['gzip', new_file_path])
            subprocess.check_call(['cp', '/dev/null', file_path]) 

Also you need to use a cron job to run the function at the certain time. APScheduler can be a good option. For example if you want to run the cron job at 3 AM, you can use:

folderPath = '/var/log/app'  # The path to your log folder
scheduler = BlockingScheduler()
scheduler.add_job(log_rollover, trigger='cron', args=[folderPath], hour=3, minute=0)
scheduler.start()

Don't forget to set your timezone for APScheduler.

ali.karimi
  • 36
  • 3
1

I had the same issue and came up with a different approach:

from datetime import datetime
import os

def rotate_log_if_new_day(self):
    now = datetime.now().date()
    file_date = datetime.fromtimestamp(os.path.getmtime("manager.err")).date()
    if file_date != now:
        self.logger.debug("Date changed with no events - rotating the log...")
        self._errhandler.doRollover()

rotate_log_if_new_day() is called during the manager's update cycle (every 15 minutes) which guarantees the log will rotate within 15 minutes of midnight. If the log has already rotated (ie: an error was logged or it already did the manual rotation), it does nothing.

Originally I had a guard to prevent the os.path... call unless the date had changed, but timeit() shows a negligible speedup gained by caching the current date (1.85μs vs 5.7μs) to verify no action required.

TemporalWolf
  • 7,727
  • 1
  • 30
  • 50