модуль журнала регистрации python и многопроцессный журнал

Эта статья в основном углубляет понимание введения ведения журнала Python. Главное — обсудить, как использовать логирование для вывода логов в многопроцессорной среде и как безопасно разбивать лог-файлы.

1. Введение в модуль ведения журнала

Модуль ведения журнала Python предоставляет гибкий стандартный модуль, который позволяет любой программе Python использовать этот сторонний модуль для ведения журнала.Официальная документация по ведению журнала Python

Структура ведения журнала в основном состоит из четырех частей:

Регистраторы: интерфейс, который программа может вызывать напрямую.
Обработчики: решите назначить ведение журнала правильному месту назначения.
Фильтры: обеспечивает более точную оценку того, выводится ли журнал.
Formatters: макет формата для окончательной печати записи

2. Состав рубки

loggers

Loggers — это интерфейс журнала, который программа может напрямую вызывать и может напрямую записывать информацию журнала в регистратор. Регистратор используется не непосредственно при создании экземпляра, аlogging.getLogger(name)Для получения объекта, по сути, объект логгера — это одноэлементный режим, а логирование — многопоточное безопасное, то есть объект логгера, полученный при логировании везде в программе, одинаков. Но, к сожалению, регистратор не поддерживает многопроцессорность, это будет объяснено в следующих главах, и будут даны некоторые решения.
[Примечание] Объект loggers имеет отношение родитель-потомок.Если нет родительского объекта logger, его родительский объект является корневым.Если у него есть родительский объект, отношение родитель-потомок будет исправлено. Напримерlogging.getLogger("abc.xyz")Будут созданы два объекта регистратора: один — родительский объект abc, другой — дочерний объект xyz, а у abc нет родительского объекта, поэтому его родительский объект — root. Но на самом деле abc — это объект-заполнитель (виртуальный объект журнала), который может обрабатывать журналы без обработчика. Но корень не является объектом-заполнителем.Если объект журнала ведет журнал, его родительский объект будет получать журнал одновременно, поэтому некоторые пользователи считают, что при создании объекта журнала журнал будет записываться дважды, потому что регистратор сам created Журнал был проверен снова, и корневой объект также был снова зарегистрирован.

Каждый регистратор имеет уровень журнала. Уровень ведения журнала определяется следующим образом

Level	Numeric value
NOTSET	0
DEBUG	10
INFO	20
WARNING	30
ERROR	40
CRITICAL	50

Когда регистратор получает информацию журнала, он сначала оценивает, соответствует ли она уровню, и, если решает ее обработать, передает информацию обработчикам для обработки.

Handlers

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

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

Filters

Фильтры обеспечивают более точную оценку, чтобы решить, нужно ли печатать журнал. В принципе, если обработчик получает журнал, он будет обрабатываться единообразно в соответствии с уровнем, но если обработчик имеет фильтр, он может выполнять дополнительную обработку и оценку журнала. Например, фильтр может перехватить или изменить журнал из определенного источника или даже изменить его уровень журнала (оценка уровня после модификации).

И регистраторы, и обработчики могут устанавливать фильтры или даже устанавливать несколько фильтров последовательно.

Formatters

Форматтеры определяют макет формата для окончательной распечатки записи. Formatter объединит переданную информацию в определенную строку. По умолчанию Format будет объединять только информацию%(message)sраспечатать его напрямую. В Format можно использовать некоторые встроенные свойства LogRecord, как показано в следующей таблице:

Attribute	Format	Description
asctime	%(asctime)s	Создает время журнала в удобочитаемой форме, по умолчанию «2016-02-08 12:00:00,123» с точностью до миллисекунд.
filename	%(filename)s	имя файла, включая путь
funcName	%(funcName)s	Какая функция выдает лог
levelname	%(levelname)s	Конечный уровень лога (изменено фильтром)
message	%(message)s	информация журнала
lineno	%(lineno)d	номер строки текущего журнала
pathname	%(pathname)s	Полный маршрут
process	%(process)s	текущий процесс
thread	%(thread)s	текущий поток

У обработчика может быть только один форматтер, поэтому, если вы хотите добиться вывода в нескольких форматах, вы можете использовать только несколько обработчиков.

3. конфигурация ведения журнала

Простая конфигурация

Впервые объясненный в главе о регистраторах, у нас есть корневой объект журнала по умолчанию, преимущество этого корневого объекта журнала заключается в том, что мы можем напрямую использовать ведение журнала для настройки и регистрации. Например:

logging.basicConfig(level=logging.INFO,filename='logger.log')
logging.info("info message")

Таким образом, простая конфигурация здесь относится к корневому объекту журнала, который можно использовать в любое время. Каждый регистратор является одноэлементным объектом, поэтому его можно вызывать в любом месте программы после настройки. Нам нужно только вызвать basicConfig, чтобы легко настроить объект корневого журнала, На самом деле, этот метод довольно эффективен и прост в использовании. Это гарантирует, что при вызове любого регистратора должен быть хотя бы один обработчик, способный обрабатывать журнал. Простую конфигурацию можно примерно установить так:

logging.basicConfig(level=logging.INFO,
         format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s',
         datefmt='[%Y-%m_%d %H:%M:%S]',
         filename='../log/my.log',
         filemode='a')

Конфигурация кода

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

Конфигурация профиля

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

##############################################
[loggers]
keys=root, log02

[logger_root]
level=INFO
handlers=handler01


[logger_log02]
level=DEBUG
handler=handler02
qualname=log02
##############################################
[handlers]
keys=handler01,handler02

[handler_handler01]
class=FileHandler
level=INFO
formatter=form01
args=('../log/cv_parser_gm_server.log',"a")

[handler_handler02]
class=StreamHandler
level=NOTSET
formatter=form01
args=(sys.stdout,)
##############################################
[formatters]
keys=form01,form02

[formatter_form01]
format=%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(process)d %(message)s
datefmt=[%Y-%m-%d %H:%M:%S]

[formatter_form02]
format=(message)s
##############################################

Я считаю, что перечитав его еще раз, я нашел закономерность: я разделил несколько больших блоков знаком #. Каждый регистратор, обработчик или средство форматирования имеет имя ключа. Взяв в качестве примера регистратор, во-первых, вам нужно добавить имя ключа в конфигурацию [loggers], чтобы представить регистратор. Затем используйте [loggers_xxxx], где xxxx — имя ключа, чтобы настроить регистратор конкретно.В log02 я настроил уровень и имя обработчика.Конечно, вы можете настроить несколько обработчиков. По имени обработчика перейдите в [handlers], чтобы найти конфигурацию конкретного обработчика и т. д. Затем в коде загрузите файл конфигурации следующим образом:

logging.config.fileConfig(log_conf_file)

Есть конфигурация обработчика класса, возможно, что некоторые читатели не очень понимают. На самом деле, это какой-то класс обработчика логов, который изначально был написан, вы можете напрямую вызывать его здесь. Класс обработчика, соответствующий классу, указывающему на конкретный исполнитель процесса. В документе регистрации вы можете знать все, что здесь Классы обработчиков потокобезопасны, вы можете быть уверены, что используете. Таким образом, возникает вопрос, если несколько процессов, как это сделать. В следующей главе я в основном перепишу класс Handler, который будет реализован с использованием ведения журнала в многопроцессорной среде. Мы владеем или переписываем совершенно новый класс Handler, затем класс Handler, настроенный так, чтобы указать, что их класс может загрузить вашу собственную переписанную версию Handler.

4. Регистрация столкновения с несколькими процессами (важно)

Эта часть на самом деле является первоначальным намерением моего написания этой статьи. По какой-то исторической причине в python производительность многопоточности можно игнорировать. Поэтому, как правило, когда Python хочет реализовать параллельные операции или параллельные вычисления, он использует несколько процессов. Но вход в python не поддерживает многопроцессорность, так что мороки будет много.
На этот раз в качестве примера используется задача класса TimedRotatingFileHandler. Первоначальная цель этого обработчика — вырезать лог-файлы по дням. (Файл дня — xxxx.log, а файл вчера — xxxx.log.2016-06-01). Преимущество этого заключается в том, что, с одной стороны, журнал можно просматривать по дням, а с другой стороны, файл журнала не должен быть очень большим. Просроченные журналы также могут быть удалены по дням.
Но проблема в том, что если использовать несколько процессов для вывода лога, то будет переключаться только один процесс, а другие процессы будут продолжать играть в исходном файле.Также возможно, что при переключении одних процессов в новом уже есть другие процессы 1. Если что-то будет занесено в лог-файл, он безжалостно удалит это и создаст новый лог-файл. Всё равно будет очень грязно и грязно, и играть в удовольствие будет совершенно невозможно.
Итак, вот несколько способов решить проблему многопроцессного ведения журнала.

причина

Прежде чем решить эту проблему, давайте посмотрим, почему это так. Сначала вставьте исходный код TimedRotatingFileHandler, эта часть представляет собой операцию, выполняемую при переключении:

    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.
        """
        if self.stream:
            self.stream.close()
            self.stream = None
        # get the time that this sequence started at and make it a TimeTuple
        currentTime = int(time.time())
        dstNow = time.localtime(currentTime)[-1]
        t = self.rolloverAt - self.interval
        if self.utc:
            timeTuple = time.gmtime(t)
        else:
            timeTuple = time.localtime(t)
            dstThen = timeTuple[-1]
            if dstNow != dstThen:
                if dstNow:
                    addend = 3600
                else:
                    addend = -3600
                timeTuple = time.localtime(t + addend)
        dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
        if os.path.exists(dfn):
            os.remove(dfn)
        # Issue 18940: A file may not have been created if delay is True.
        if os.path.exists(self.baseFilename):
            os.rename(self.baseFilename, dfn)
        if self.backupCount > 0:
            for s in self.getFilesToDelete():
                os.remove(s)
        if not self.delay:
            self.stream = self._open()
        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')) and not self.utc:
            dstAtRollover = time.localtime(newRolloverAt)[-1]
            if dstNow != dstAtRollover:
                if not dstNow:  # DST kicks in before next rollover, so we need to deduct an hour
                    addend = -3600
                else:           # DST bows out before next rollover, so we need to add an hour
                    addend = 3600
                newRolloverAt += addend
        self.rolloverAt = newRolloverAt

мы наблюдаемif os.path.exists(dfn)Начиная с этой строки, логика здесь такова, что если файл dfn существует, то его нужно сначала удалить, а затем файл baseFilename будет переименован в файл dfn. Затем снова откройте файл baseFilename и начните писать. Тогда логика здесь ясна

Предположим, имя текущего файла журнала — current.log, а имя файла после разделения — current.log.2016-06-01.
Определите, существует ли current.log.2016-06-01, и удалите его, если он существует.
Переименуйте имя текущего файла журнала в current.log.2016-06-01.
Повторно откройте новый файл (я заметил, что по умолчанию в исходном коде открывается режим «a», раньше было сказано, что это «w»)

Таким образом, в случае нескольких процессов, один процесс переключается, а дескрипторы других процессов все еще находятся в current.log.2016-06-01 и будут продолжать писать в него. Или, если процесс переключается, файл current.log.2016-06-01, переименованный другим процессом, будет удален напрямую. Или бывает другая ситуация, когда один процесс что-то пишет, другой процесс уже переключается, что приведет к непредсказуемым ситуациям. Также бывает ситуация, когда два процесса одновременно нарезают файлы, первый процесс выполняет шаг 3, второй процесс только что завершил шаг 2, а затем первый процесс завершил переименование, но еще не создал новый текущий .log Второй процесс начинает переименовывать, в это время второй процесс не сможет найти Произошла ошибка тока. Если первый процесс успешно создал current.log, второй процесс сохранит этот пустой файл как current.log.2016-06-01. Тогда не только лог-файл удаляется, но и процесс не будет его снова резать, раз он думает, что сегментация завершена, а на самом деле его хэндл указывает на current.log.2016-06-01.
Ну, здесь это выглядит сложно, но на самом деле это проблема, вызванная тем, что нет ограничений на несколько процессов при работе с файлами.
Итак, как решить эту проблему элегантно. Я предложил два варианта, разумеется, ниже я предложу более осуществимые варианты, чтобы все могли попробовать.

Решение 1

Ранее мы обнаружили брешь в логике TimedRotatingFileHandler. Нам просто нужно немного изменить логику:

Определите, существует ли разделенный файл current.log.2016-06-01, если нет, переименуйте его. (Если он есть, значит вырезался другой процесс, мне его не надо резать, просто поменять хендл)
Откройте current.log в режиме "а"
Это так просто после обнаружения модификации~
talking is cheap show me the code:

class SafeRotatingFileHandler(TimedRotatingFileHandler):
    def __init__(self, filename, when='h', interval=1, backupCount=0, encoding=None, delay=False, utc=False):
        TimedRotatingFileHandler.__init__(self, filename, when, interval, backupCount, encoding, delay, utc)
    """
    Override doRollover
    lines commanded by "##" is changed by cc
    """
    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.
        
        Override,   1. if dfn not exist then do rename
                    2. _open with "a" model
        """
        if self.stream:
            self.stream.close()
            self.stream = None
        # get the time that this sequence started at and make it a TimeTuple
        currentTime = int(time.time())
        dstNow = time.localtime(currentTime)[-1]
        t = self.rolloverAt - self.interval
        if self.utc:
            timeTuple = time.gmtime(t)
        else:
            timeTuple = time.localtime(t)
            dstThen = timeTuple[-1]
            if dstNow != dstThen:
                if dstNow:
                    addend = 3600
                else:
                    addend = -3600
                timeTuple = time.localtime(t + addend)
        dfn = self.baseFilename + "." + time.strftime(self.suffix, timeTuple)
##        if os.path.exists(dfn):
##            os.remove(dfn)
            
        # Issue 18940: A file may not have been created if delay is True.
##        if os.path.exists(self.baseFilename):
        if not os.path.exists(dfn) and os.path.exists(self.baseFilename):
            os.rename(self.baseFilename, dfn)
        if self.backupCount > 0:
            for s in self.getFilesToDelete():
                os.remove(s)
        if not self.delay:
            self.mode = "a"
            self.stream = self._open()
        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')) and not self.utc:
            dstAtRollover = time.localtime(newRolloverAt)[-1]
            if dstNow != dstAtRollover:
                if not dstNow:  # DST kicks in before next rollover, so we need to deduct an hour
                    addend = -3600
                else:           # DST bows out before next rollover, so we need to add an hour
                    addend = 3600
                newRolloverAt += addend
        self.rolloverAt = newRolloverAt

Не думайте, что код такой длинный, на самом деле измененная часть - это только место, где ставится комментарий "##", а остальное копируется из исходного кода. Этот класс наследует TimedRotatingFileHandler и переписывает процесс сегментации. Это элегантное решение, требует очень мало изменений и очень эффективно. Тем не менее, некоторые пользователи сети указали, что есть одно место, которое все еще не идеально, это шаг переименования, Если это такое совпадение, если два или более процессов одновременно вводят оператор if и начинают переименовывать один за другим , журнал все равно будет удален. Это правда, что такая ситуация действительно имеет место.Так как файл делится только один раз в день, это просто совпадение, что два обработчика работают одновременно, когда файл делится, и он приходит сюда в одно и то же время, но для совершенства можно добавить напильник блокировки, если Затем добавьте блокировку, оцените ее снова после получения блокировки, а затем переименуйте этот метод. Код выкладывать не буду, он включает в себя код блокировки, что влияет на внешний вид.

Решение 2

Самое простое и эффективное решение на мой взгляд. Перепишите класс FileHandler (это класс TimedRotatingFileHandler, который должны наследовать все обработчики, записывающие файлы. Этот класс наследуется, мы можем добавить несколько простых суждений и операций. Наша логика такова:

Определите, совпадает ли текущая метка времени с указанным именем файла.
Если нет, просто переключите файл, на который указывает
Конец, не очень простая логика.
talking is cheap show me the code:

class SafeFileHandler(FileHandler):
    def __init__(self, filename, mode, encoding=None, delay=0):
        """
        Use the specified filename for streamed logging
        """
        if codecs is None:
            encoding = None
        FileHandler.__init__(self, filename, mode, encoding, delay)
        self.mode = mode
        self.encoding = encoding
        self.suffix = "%Y-%m-%d"
        self.suffix_time = ""

    def emit(self, record):
        """
        Emit a record.

        Always check time 
        """
        try:
            if self.check_baseFilename(record):
                self.build_baseFilename()
            FileHandler.emit(self, record)
        except (KeyboardInterrupt, SystemExit):
            raise
        except:
            self.handleError(record)
            
    def check_baseFilename(self, record):
        """
        Determine if builder should occur.
        
        record is not used, as we are just comparing times, 
        but it is needed so the method signatures are the same
        """
        timeTuple = time.localtime()
        
        if self.suffix_time != time.strftime(self.suffix, timeTuple) or not os.path.exists(self.baseFilename+'.'+self.suffix_time):
            return 1
        else:
            return 0
    def build_baseFilename(self):
        """
        do builder; in this case, 
        old time stamp is removed from filename and
        a new time stamp is append to the filename
        """
        if self.stream:
            self.stream.close()
            self.stream = None
        
        # remove old suffix
        if self.suffix_time != "":
            index = self.baseFilename.find("."+self.suffix_time)
            if index == -1:
                index = self.baseFilename.rfind(".")
            self.baseFilename = self.baseFilename[:index]
        
        # add new suffix
        currentTimeTuple = time.localtime()
        self.suffix_time = time.strftime(self.suffix, currentTimeTuple)
        self.baseFilename  = self.baseFilename + "." + self.suffix_time
        
        self.mode = 'a'
        if not self.delay:
            self.stream = self._open()

check_baseFilename — выполнить решение логики 1, build_baseFilename — выполнить логику 2 для дескриптора. Это так просто. Отличие этой схемы от предыдущей в том, что текущий файл — current.log.2016-06-01 , а завтра текущий файл будет current.log.2016-06-02, он не переименовывался и не удалялся. Очень просто и элегантно. Это также может решить проблему регистрации нескольких процессов.

другие решения

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

5. Ссылки

Официальная документация по ведению журнала Python
План сегментации фонарика в лесу, первый план отсюда