python的logging库中TimedRotatingFileHandler类问题

来源：互联网发布：怎么在淘宝找开病假条编辑：程序博客网时间：2024/05/17 22:32

原文网址：http://www.5dcode.com/?p=545

第一次用python，第一次用logging，第一次用TimedRotatingFileHandler，居然发现了其中的BUG，记录下吧。

用TimedRotatingFileHandler的目的是让其自动在日志文件名后面加上日期时间，可以按秒、分、时、天、周或者其倍数来设置，BUG出现的场景是：手动设置时间，并把时间往未来时间调（比如把2012-03-15调成2014-03-15），这时就出问题了，这时产生每条日志后会产生一个日志文件，这并不是我们想要的效果，如果把当前时间再往历史时间调（比如把2012-03-15调成2010-03-15），这时也会产生问题：所有产生的日志都会记录到一个没有日期后缀的文件，并不会按日期分类。如果时间是正确的并按正常的流程走并不会产生问题，所以想看看logging是怎么实现的，看了其源码：C:\Python25\Lib\logging\handlers.py，果然不出所料，它的设计是有问题的，根本不考虑手动调时间或者时间可能不对需要同步的情况：

def shouldRollover(self, record):
"""
Determine if rollover should occur
record is not used, as we are just comparing times, but it is needed so
the method siguratures are the same
"""
t = int(time.time())
if t >= self.rolloverAt:
return 1
#print "No need to rollover: %d, %d" % (t, self.rolloverAt)
return 0
def doRollover(self):
"""
do a rollover; in this case, a date/time stamp is appended to the filename
when the rollover happens. However, you want the file to be named for the
start of the interval, not the current time. If there is a backup count,
then we have to get a list of matching filenames, sort them and remove
the one with the oldest suffix.
"""
self.stream.close()
# get the time that this sequence started at and make it a TimeTuple
t = self.rolloverAt - self.interval
timeTuple = time.localtime(t)
dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
if os.path.exists(dfn):
os.remove(dfn)
os.rename(self.baseFilename, dfn)
if self.backupCount > 0:
# find the oldest log file and delete it
s = glob.glob(self.baseFilename + ".20*")
if len(s) > self.backupCount:
s.sort()
os.remove(s[0])
#print "%s -> %s" % (self.baseFilename, dfn)
if self.encoding:
self.stream = codecs.open(self.baseFilename, 'w', self.encoding)
else:
self.stream = open(self.baseFilename, 'w')
self.rolloverAt = self.rolloverAt + self.interval

第9行判断中只判断时间大的情况，并没有判断时间小的情况，第41行中self.rolloverAt永远是上一次的值加上self.interval，如果时间往大的调的话，第9行判断就会永远是True，所以就会产生问题，如果时间往小的调，第9行判断就会永远是False，也会产生问题。上面的python版本是2.5.4，再看最新的版本：3.1，这个版本修复了def doRollover(self)，但并没有修复def shouldRollover(self, record)，所以综合这两个版本的考虑，还是自己来实现吧，修复之后的代码如下（测试成功通过）：

def shouldRollover(self, record):
"""
Determine if rollover should occur
record is not used, as we are just comparing times, but it is needed so
the method siguratures are the same
"""
t = int(time.time())
#print "self.rolloverAt: %d. currentTime: %d." % (self.rolloverAt, t)
#start: recompare slef.rolloverAt, Modify by 5dcode. 2012-03-14
if t >= self.rolloverAt or t < (self.rolloverAt - self.interval):
return 1
#end: recompare slef.rolloverAt, Modify by 5dcode. 2012-03-14
#print "No need to rollover: %d, %d" % (t, self.rolloverAt)
return 0
def doRollover(self):
"""
do a rollover; in this case, a date/time stamp is appended to the filename
when the rollover happens. However, you want the file to be named for the
start of the interval, not the current time. If there is a backup count,
then we have to get a list of matching filenames, sort them and remove
the one with the oldest suffix.
"""
self.stream.close()
# get the time that this sequence started at and make it a TimeTuple
t = self.rolloverAt - self.interval
timeTuple = time.localtime(t)
dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
if os.path.exists(dfn):
os.remove(dfn)
os.rename(self.baseFilename, dfn)
if self.backupCount > 0:
# find the oldest log file and delete it
s = glob.glob(self.baseFilename + ".20*")
if len(s) > self.backupCount:
s.sort()
os.remove(s[0])
#print "%s -> %s" % (self.baseFilename, dfn)
if self.encoding:
self.stream = codecs.open(self.baseFilename, 'w', self.encoding)
else:
self.stream = open(self.baseFilename, 'w')
#start: recompute self.rolloverAt, Modify by 5dcode. 2012-03-14
currentTime = int(time.time())
newRolloverAt = currentTime + self.interval
if self.when == 'MIDNIGHT' or self.when.startswith('W'):
# This could be done with less code, but I wanted it to be clear
t = time.localtime(currentTime)
currentHour = t[3]
currentMinute = t[4]
currentSecond = t[5]
# r is the number of seconds left between now and midnight
r = _MIDNIGHT - ((currentHour * 60 + currentMinute) * 60 +
currentSecond)
newRolloverAt = currentTime + r
#newRolloverAt = self.computeRollover(currentTime)
while newRolloverAt <= currentTime:
newRolloverAt = newRolloverAt + self.interval
#If DST changes and midnight or weekly rollover, adjust for this.
if self.when == 'MIDNIGHT' or self.when.startswith('W'):
dstNow = time.localtime(currentTime)[-1]
dstAtRollover = time.localtime(newRolloverAt)[-1]
if dstNow != dstAtRollover:
if not dstNow: # DST kicks in before next rollover, so we need to deduct an hour
newRolloverAt = newRolloverAt - 3600
else: # DST bows out before next rollover, so we need to add an hour
newRolloverAt = newRolloverAt + 3600
self.rolloverAt = newRolloverAt
#print "self.rolloverAt: %d." % self.rolloverAt
#end: recompute self.rolloverAt, Modify by 5dcode. 2012-03-14