Python rotating file handler logging некорректный порядок отметки времени

Question

Мой руководитель хочет, чтобы я исправил проблему параллелизма в журналах, что означает, что файлы журнала, которые мы производим, имеют смешанные временные метки в начале/конце разных файлов. То есть:

• Первый файл журнала имеет в конце:

  [03/Dec/2013:13:55:19]--------------------- 
  [03/Dec/2013:13:55:20]--------------------- 
  [03/Dec/2013:13:55:20]--------------------- 
  

• Второй файл начинается с:

  [03/Dec/2013:13:40:16]--------------------- 
  [03/Dec/2013:13:40:16]--------------------- 
  [03/Dec/2013:13:40:23]--------------------- 
  

Мы используем вращательные обработчик файлов, а второй файл должны иметь отметки времени, начиная с первого конца, но это не так. Как сделать временные метки в журналах в правильном порядке во время вращения файлов?

класс "Logger", который просто использует Python модуль протоколирования:

class logger: 
    def __init__(self, logger_name='prod'): 
     self.error_logger = logging.getLogger(logger_name+'_error') 

    def error(self, msg='', level='error'): 
     if msg: 
      getattr(self.error_logger,level)(msg) 

    def log(self, msg='', level='info'): 
     if msg: 
      getattr(self.error_logger,level)(msg) 

Форматирование журналов:

class our_formatter(logging.Formatter): 

def find_topmost_stack_frame(self): 
    i = 0 
    stack = [] 
    while True: 
     try: 
      fr = sys._getframe(i) 
      if fr.f_code.co_name == '__call__': 
        break 
      stack.append(fr) 
     except: 
      break 
     i += 1 
    return "%s:%s" % (stack[-4].f_code.co_filename, stack[-4].f_lineno) 

def format(self, record): 
    try: 
     if record.done: 
       return record.msg 
    except: 
     record.done = False 

    rtime = time.strftime("%d/%b/%Y:%H:%M:%S", time.localtime(record.created)) 
    from tools.user_management import user_pack 
    email = user_pack().get_email() 

    if record.levelno > 20: 
     if email: 
      record.msg = '[%s][user:%s][%s] {%s} %s' % (rtime, email, record.levelname, self.find_topmost_stack_frame(), 
                 record.msg) 
     else: 
      record.msg = '[%s][%s] {%s} %s' % (rtime, record.levelname, self.find_topmost_stack_frame(), record.msg) 
    else: 
     if email: 
      record.msg = '[%s][user:%s][%s] %s' % (rtime, email, record.levelname, record.msg) 
     else: 
      record.msg = '[%s][%s] %s' % (rtime, record.levelname, record.msg) 

    record.done = True 
    return logging.Formatter.format(self, record) 

И, наконец, конфигурацию регистратора:

log = cherrypy.log 
log.error_file = None 

maxBytes = getattr(log, "rot_maxBytes", 10000000) 
backupCount = getattr(log, "rot_backupCount", 1000) 
fname = getattr(log, "rot_error_file", "logs/error.log") 

logger = logging.getLogger() 
logger.setLevel(0) 

# Make a new RotatingFileHandler for the error log. 
h = logging.handlers.RotatingFileHandler(fname, 'a', maxBytes, backupCount) 
h.setFormatter(rest_formatter()) 
log.error_log.addHandler(h) 

# set up custom ReST logger 
logger = logging.getLogger("rest_error") 
logger.addHandler(h) 

# set up our custom logger 
ha = logging.handlers.RotatingFileHandler(fname, 'a', maxBytes, backupCount) 
ha.setFormatter(our_formatter()) 
logger = logging.getLogger("prod_error") 
logger.addHandler(ha) 

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

Проблема заключается только в начале одного файла и в конце предыдущего (а не в середине), поэтому я думаю, что это случай резервирования файлового пространства регистратором, однако я понимаю, что он все равно должен поддерживать правильный порядок , так как должен быть указан только один экземпляр регистратора для каждого обработчика файла.

У нас есть много регистрации. По большому счету, я имею в виду, что в каждом случае часто бывает 10+ журналов.

Answer 1

Проблема, связанная с несколькими обработчиками для одного файла. Журналисты использовали разные обработчики, поэтому они пытались писать в одном файле одновременно, из-за чего создавался новый файл (а затем они писали два раза различать файлы в течение некоторого периода времени).

Удаление обработчика «ha», похоже, устраняет проблему!

Answer 2

Чтение вашего вопроса, мне кажется, что вам нужно очистить буфер записи.

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

from os import fsync 
with open(filename,'a') as fh: 
    fh.write(something) 
    fh.flush() 
    fsync(fh.fileno()) 
    # continued code 

Это необходимая процедура, когда что-то - это небольшое количество, чтобы написать.

Однако, когда файл закрыт, обычно буфер записи очищается, и его содержимое записывается в файл до его полного закрытия.
Si, Я не знаю, действительно ли этот ответ приносит вам что-то полезное.