logging.handler.TimedRotatingFileHandler никогда не меняет журнал

У меня есть скрипт, который синхронизирует время на Linux-серверах (CentOS 6) и записывает смещение в журнал. Хочу сделать через 10 дней текущий лог (ntp.log) скопировать в старый (ntp.log-date), но так не получается. Скрипт продолжает писать в один файл и не вращается. Он запускается cron каждые 5 минут. Я использую Python версии 2.6. Я специально установил интервал в секундах для проверки. Что я делаю не так?

#!/usr/bin/env python
import ntplib
import logging
from logging.handlers import TimedRotatingFileHandler
from time import ctime
import os
import socket

hostname = socket.gethostname()
logHandler = TimedRotatingFileHandler('/root/ntp/log/ntp.log', when='S', interval=300)
logFormatter = logging.Formatter('%(asctime)s %(message)s', datefmt='%d/%m/%Y %H:%M:%S')
logHandler.setFormatter(logFormatter)
logger = logging.getLogger('MyLogger')
logger.addHandler(logHandler)
logger.setLevel(logging.INFO)


c = ntplib.NTPClient()
response = c.request('1.rhel.pool.ntp.org')
logger.info('| %s time offset is | %s' % (hostname, response.offset))
datestr = ctime(response.tx_time)
os.system('date -s "%s"' % datestr)

python logging log-rotation
person reddaemon    schedule 01.06.2015    source источник
comment
Я настоятельно рекомендую использовать ntpd и logrotate, а не изобретать велосипед. Логика ntpd куда более разумна, чем периодические разовые синхронизации.   -  person ivan_pozdeev    schedule 01.06.2015
comment
про logrotate надо посмотреть, а ntpd не могу пользоваться, нужны логи синхронизации   -  person reddaemon    schedule 01.06.2015
comment
ntpd работает намного умнее, чем просто синхронизация, он использует API дисциплины времени ядра и предназначен для того, чтобы фактически заставить вас забыть о синхронизации раз и навсегда (eecis.udel.edu/~mills/ntp/html/discipline.html#house : если оставленный работать непрерывно, клиент NTP в быстрой локальной сети в домашней или офисной среде может поддерживать синхронизацию номинально в течение одной миллисекунды.) Не волнуйтесь, он регистрирует это всякий раз, когда он делает что-либо с системными часами.   -  person ivan_pozdeev    schedule 01.06.2015
comment
мне нужно пользовательское ведение журнала, потому что оно используется в веб-приложении   -  person reddaemon    schedule 01.06.2015
comment
Вы ожидаете, что я куплю это как оправдание? Уверяю вас, лучше ntpd у вас не получится синхронизироваться. И если вам нужна регулярная синхронизация, зачем вам регулярно отчитываться об этом? Если вам нужно сообщить о чем-то, внимательно изучите, что точно вы должны сообщить, и определите способ сделать это, не жертвуя фактической работой.   -  person ivan_pozdeev    schedule 01.06.2015
comment
Кстати, если вы все еще не уверены, вот ошибка в вашем алгоритме: response.tx_time (Отметка времени передачи) — это время, когда полученный пакет покинул сервер. Время между его уходом и date вызовом stime() не учтено.   -  person ivan_pozdeev    schedule 01.06.2015

Ответы (2)


arrow_upward
1
arrow_downward

Не говоря уже о том, что ваш алгоритм явно неверен, я отвечу на вопрос, касающийся проблемы с логированием.

Вот соответствующая логика logging.handlers.TimedRotatingFileHandler:

def __init__(<...>):
    <...>
    if self.when == 'S':
        self.interval = 1 # one second
    <...>
    self.interval = self.interval * interval # multiply by units requested
    <...>
    if os.path.exists(filename):
        t = os.stat(filename)[ST_MTIME]
    else:
        t = int(time.time())
    self.rolloverAt = self.computeRollover(t)

def computeRollover(self, currentTime):
    result = currentTime + self.interval
    <special logic that doesn't apply in your case>
    return result

Таким образом, время перехода в режиме 'S' вычисляется из mtime во время инициализации вашего скрипта. mtime изменяется каждый раз, когда вы записываете файл.

Таким образом, ролловер будет выполнен только в том случае, если вы войдете в систему через interval секунд с момента запуска вашего скрипта. Чего никогда не бывает, так как он стоит гораздо меньше.

Возможные исправления:

  • заставить скрипт работать так долго, например. с бесконечным циклом, как вы предложили. Если он будет работать бесконечно, его, вероятно, следует сделать демоном.
  • change the rollover moment calculation algorithm
    • this is not possible with the stock logic (the "special logic" in TimedRotatingFileHandler.computeRollover() only applies to 'MIDNIGHT' and 'Wn' cases), so you need to replace your handler's computeRollover()
    • по сути, вам нужно установить время прокрутки на следующий «контрольный момент» после mtime текущего файла.
person ivan_pozdeev    schedule 01.06.2015
comment
Подскажите, пожалуйста, что мне нужно изменить, чтобы алгоритм работал так, как мне нужно? - person reddaemon; 01.06.2015
comment
Может быть, я должен запустить его не через cron и сделать бесконечный цикл. Или я просто должен увеличить интервал? - person reddaemon; 01.06.2015
comment
Бесконечный цикл будет работать. Теперь я посмотрю, будут ли другие параметры обработчика. - person ivan_pozdeev; 01.06.2015

arrow_upward
0
arrow_downward

Это может вам помочь (прокрутка журнала, если журнал был создан кратно 10-му дню, а журнал последний раз изменялся за день до этого)

 #!/usr/bin/env python
import ntplib
import logging
from logging.handlers import TimedRotatingFileHandler
from time import ctime
import os
import socket

hostname = socket.gethostname()
logHandler = TimedRotatingFileHandler('/root/ntp/log/ntp.log', when='D', interval=10)
logFormatter = logging.Formatter('%(asctime)s %(message)s', datefmt='%d/%m/%Y %H:%M:%S')
logHandler.setFormatter(logFormatter)
#Get File creation Time
log_ctime = datetime.fromtimestamp(os.path.getctime("/root/ntp/log/ntp.log")).date()
log_mtime = datetime.fromtimestamp(os.path.getmtime("/root/ntp/log/ntp.log")).date()
delta_c = datetime.now().date() - log_ctime 
delta_m = datetime.now().date() - log_mtime 
if delta_c.days %10 == 0 and delta_m.days>=1:
   logHandler.doRollover()
logger = logging.getLogger('MyLogger')
logger.addHandler(logHandler)
logger.setLevel(logging.INFO)


c = ntplib.NTPClient()
response = c.request('1.rhel.pool.ntp.org')
logger.info('| %s time offset is | %s' % (hostname, response.offset))
datestr = ctime(response.tx_time)
os.system('date -s "%s"' % datestr)
person kishore.jannarapu    schedule 14.04.2021