Why logging.handlers.TimedRotatingFileHandler log file create time is "drifting" causing headache for ETL

Question

I'm having an issue with python's logging module's TimeRotatingFileHandler where each consecutive log file's create time appears to be "drifting" away from the desired top of the hour rotation. See example:

-rw-rw-r--. 1 user user 1278 Oct 13 18:58 activity.log.2014-10-13_18
-rw-rw-r--. 1 user user 1260 Oct 13 19:58 activity.log.2014-10-13_19
-rw-rw-r--. 1 user user 1512 Oct 13 21:00 activity.log.2014-10-13_20
-rw-rw-r--. 1 user user 1266 Oct 13 22:05 activity.log.2014-10-13_21
-rw-rw-r--. 1 user user 2128 Oct 13 23:10 activity.log.2014-10-13_22
-rw-rw-r--. 1 user user 3234 Oct 14 00:10 activity.log.2014-10-13_23
-rw-rw-r--. 1 user user 3739 Oct 14 01:10 activity.log.2014-10-14_00
-rw-rw-r--. 1 user user 3388 Oct 14 02:11 activity.log.2014-10-14_01
-rw-rw-r--. 1 user user 3122 Oct 14 03:11 activity.log.2014-10-14_02
-rw-rw-r--. 1 user user 3108 Oct 14 04:12 activity.log.2014-10-14_03
-rw-rw-r--. 1 user user 3066 Oct 14 05:12 activity.log.2014-10-14_04
-rw-rw-r--. 1 user user 3178 Oct 14 06:12 activity.log.2014-10-14_05
-rw-rw-r--. 1 user user 3126 Oct 14 07:12 activity.log.2014-10-14_06
-rw-rw-r--. 1 user user 3532 Oct 14 08:12 activity.log.2014-10-14_07
-rw-rw-r--. 1 user user 2954 Oct 14 09:12 activity.log.2014-10-14_08
-rw-rw-r--. 1 user user 3463 Oct 14 10:12 activity.log.2014-10-14_09
-rw-rw-r--. 1 user user 3743 Oct 14 11:12 activity.log.2014-10-14_10
-rw-rw-r--. 1 user user 3867 Oct 14 12:12 activity.log.2014-10-14_11
-rw-rw-r--. 1 user user 3687 Oct 14 13:12 activity.log.2014-10-14_12
-rw-rw-r--. 1 user user 4141 Oct 14 14:12 activity.log.2014-10-14_13
-rw-rw-r--. 1 user user 4172 Oct 14 15:13 activity.log.2014-10-14_14
-rw-rw-r--. 1 user user 4186 Oct 14 16:13 activity.log.2014-10-14_15
-rw-rw-r--. 1 user user 4578 Oct 14 17:13 activity.log.2014-10-14_16

The log here is capturing sporadic events that occur on my web app. I implemented a cron job to ping the webapp (to trigger a roll) every minute on 10/14 at 11pm, so you'll notice that the "drift" is improved but still occurs gradually over the course of the day. This is causing a major headache for my database ETL jobs that are cron'd to run at specific hours.

Anyone have any ideas on how to resolve this so that it rolls over at a single minute every hour of every day? Thanks for the help in advance!

Answer 1

Created a work-around by modifying a cron'd python script to ping my webapp every second for a minute +/- the last log creation minute. This appears to be triggering the log to roll over consistently at the same time in the subsequent hours and avoid the "drift".