logging-cookbook.md

1> **Источник:** https://python-all.ru/3.5/howto/logging-cookbook.html2>3> «Документация Python на русском» – неофициальный перевод официальной документации Python: версии от 2.6 до 3.16, полнотекстовый поиск, английский оригинал рядом с переводом. Эта Markdown-версия страницы предназначена для работы с LLM: вставьте её в ChatGPT, Claude или Cursor.45---67# Сборник рецептов по логированию89| Автор: | Vinay Sajip \<vinay\_sajip at red-dove dot com\> |10| --- | --- |1112На этой странице представлен ряд рецептов, связанных с логированием, которые оказались полезными на практике.1314## Использование логирования в нескольких модулях1516Многократные вызовы `logging.getLogger('someLogger')` возвращают ссылку на один и тот же объект логгера. Это верно не только в пределах одного модуля, но и для разных модулей, если они выполняются в одном процессе интерпретатора Python. Кроме того, код приложения может определить и настроить родительский логгер в одном модуле, а затем создать (но не настраивать) дочерний логгер в другом модуле – все вызовы логгера у дочернего будут передаваться родительскому. Вот главный модуль:1718```python19import logging20import auxiliary_module2122# создать логгер с именем 'spam_application'23logger = logging.getLogger('spam_application')24logger.setLevel(logging.DEBUG)25# создать файловый обработчик, записывающий даже отладочные сообщения26fh = logging.FileHandler('spam.log')27fh.setLevel(logging.DEBUG)28# создать консольный обработчик с более высоким уровнем логирования29ch = logging.StreamHandler()30ch.setLevel(logging.ERROR)31# создать форматтер и добавить его к обработчикам32formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')33fh.setFormatter(formatter)34ch.setFormatter(formatter)35# добавить обработчики к логгеру36logger.addHandler(fh)37logger.addHandler(ch)3839logger.info('creating an instance of auxiliary_module.Auxiliary')40a = auxiliary_module.Auxiliary()41logger.info('created an instance of auxiliary_module.Auxiliary')42logger.info('calling auxiliary_module.Auxiliary.do_something')43a.do_something()44logger.info('finished auxiliary_module.Auxiliary.do_something')45logger.info('calling auxiliary_module.some_function()')46auxiliary_module.some_function()47logger.info('done with auxiliary_module.some_function()')48```4950А вот вспомогательный модуль:5152```python53import logging5455# создать логгер56module_logger = logging.getLogger('spam_application.auxiliary')5758class Auxiliary:59    def __init__(self):60        self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')61        self.logger.info('creating an instance of Auxiliary')6263    def do_something(self):64        self.logger.info('doing something')65        a = 1 + 166        self.logger.info('done doing something')6768def some_function():69    module_logger.info('received a call to "some_function"')70```7172Вывод выглядит так:7374```python752005-03-23 23:47:11,663 - spam_application - INFO -76   creating an instance of auxiliary_module.Auxiliary772005-03-23 23:47:11,665 - spam_application.auxiliary.Auxiliary - INFO -78   creating an instance of Auxiliary792005-03-23 23:47:11,665 - spam_application - INFO -80   created an instance of auxiliary_module.Auxiliary812005-03-23 23:47:11,668 - spam_application - INFO -82   calling auxiliary_module.Auxiliary.do_something832005-03-23 23:47:11,668 - spam_application.auxiliary.Auxiliary - INFO -84   doing something852005-03-23 23:47:11,669 - spam_application.auxiliary.Auxiliary - INFO -86   done doing something872005-03-23 23:47:11,670 - spam_application - INFO -88   finished auxiliary_module.Auxiliary.do_something892005-03-23 23:47:11,671 - spam_application - INFO -90   calling auxiliary_module.some_function()912005-03-23 23:47:11,672 - spam_application.auxiliary - INFO -92   received a call to 'some_function'932005-03-23 23:47:11,673 - spam_application - INFO -94   done with auxiliary_module.some_function()95```9697## Журналирование из нескольких потоков9899Журналирование из нескольких потоков не требует особых усилий. В следующем примере показано журналирование из главного (начального) потока и ещё одного потока:100101```python102import logging103import threading104import time105106def worker(arg):107    while not arg['stop']:108        logging.debug('Hi from myfunc')109        time.sleep(0.5)110111def main():112    logging.basicConfig(level=logging.DEBUG, format='%(relativeCreated)6d %(threadName)s %(message)s')113    info = {'stop': False}114    thread = threading.Thread(target=worker, args=(info,))115    thread.start()116    while True:117        try:118            logging.debug('Hello from main')119            time.sleep(0.75)120        except KeyboardInterrupt:121            info['stop'] = True122            break123    thread.join()124125if __name__ == '__main__':126    main()127```128129При запуске скрипт должен вывести что-то вроде следующего:130131```python132   0 Thread-1 Hi from myfunc133   3 MainThread Hello from main134 505 Thread-1 Hi from myfunc135 755 MainThread Hello from main1361007 Thread-1 Hi from myfunc1371507 MainThread Hello from main1381508 Thread-1 Hi from myfunc1392010 Thread-1 Hi from myfunc1402258 MainThread Hello from main1412512 Thread-1 Hi from myfunc1423009 MainThread Hello from main1433013 Thread-1 Hi from myfunc1443515 Thread-1 Hi from myfunc1453761 MainThread Hello from main1464017 Thread-1 Hi from myfunc1474513 MainThread Hello from main1484518 Thread-1 Hi from myfunc149```150151Как и следовало ожидать, вывод журнала перемежается. Разумеется, такой подход работает и для большего количества потоков, чем показано здесь.152153## Несколько обработчиков и форматировщиков154155Логгеры – это обычные объекты Python. У метода [`addHandler()`](https://python-all.ru/3.5/library/logging.html#logging.Logger.addHandler) нет минимального или максимального ограничения на количество добавляемых обработчиков. Иногда приложению полезно записывать все сообщения всех уровней в текстовый файл и одновременно выводить ошибки и сообщения выше в консоль. Чтобы это настроить, достаточно сконфигурировать нужные обработчики. Вызовы журналирования в коде приложения останутся без изменений. Вот небольшая модификация предыдущего простого примера конфигурации на основе модуля:156157```python158import logging159160logger = logging.getLogger('simple_example')161logger.setLevel(logging.DEBUG)162# создать файловый обработчик, записывающий даже отладочные сообщения163fh = logging.FileHandler('spam.log')164fh.setLevel(logging.DEBUG)165# создать консольный обработчик с более высоким уровнем логирования166ch = logging.StreamHandler()167ch.setLevel(logging.ERROR)168# создать форматтер и добавить его к обработчикам169formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')170ch.setFormatter(formatter)171fh.setFormatter(formatter)172# добавить обработчики в логгер173logger.addHandler(ch)174logger.addHandler(fh)175176# код 'приложения'177logger.debug('debug message')178logger.info('info message')179logger.warn('warn message')180logger.error('error message')181logger.critical('critical message')182```183184Обратите внимание, что «прикладной» код не заботится о нескольких обработчиках. Единственное, что изменилось – добавление и настройка нового обработчика с именем *fh*.185186Возможность создавать новые обработчики с фильтрами более высокого или низкого уровня очень полезна при написании и тестировании приложения. Вместо множества операторов `print` для отладки используйте `logger.debug`: в отличие от операторов print, которые позже придётся удалять или закомментировать, вызовы logger.debug могут оставаться в исходном коде и оставаться неактивными, пока они снова не понадобятся. В тот момент единственное, что нужно изменить – уровень журналирования логгера и/или обработчика на DEBUG.187188## Журналирование в несколько мест назначения189190Допустим, вы хотите вести журнал в консоль и файл с разными форматами сообщений и в разных ситуациях. Предположим, вы хотите записывать сообщения уровня DEBUG и выше в файл, а сообщения уровня INFO и выше – в консоль. Также предположим, что файл должен содержать временные метки, а консольные сообщения – нет. Вот как это можно сделать:191192```python193import logging194195# настроить логирование в файл – подробнее см. предыдущий раздел196logging.basicConfig(level=logging.DEBUG,197                    format='%(asctime)s %(name)-12s %(levelname)-8s %(message)s',198                    datefmt='%m-%d %H:%M',199                    filename='/temp/myapp.log',200                    filemode='w')201# Определяет обработчик, который записывает сообщения уровня INFO и выше в sys.stderr.202console = logging.StreamHandler()203console.setLevel(logging.INFO)204# Задает формат, упрощенный для вывода в консоль.205formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')206# Указывает обработчику использовать этот формат.207console.setFormatter(formatter)208# Добавляет обработчик в корневой логгер.209logging.getLogger('').addHandler(console)210211# Теперь можно выполнять запись в корневой логгер или любой другой. Сначала корневой...212logging.info('Jackdaws love my big sphinx of quartz.')213214# Теперь определите несколько других логгеров, которые могут представлять разные части приложения:215# приложение:216217logger1 = logging.getLogger('myapp.area1')218logger2 = logging.getLogger('myapp.area2')219220logger1.debug('Quick zephyrs blow, vexing daft Jim.')221logger1.info('How quickly daft jumping zebras vex.')222logger2.warning('Jail zesty vixen who grabbed pay from quack.')223logger2.error('The five boxing wizards jump quickly.')224```225226При запуске на консоли вы увидите227228```python229root        : INFO     Jackdaws love my big sphinx of quartz.230myapp.area1 : INFO     How quickly daft jumping zebras vex.231myapp.area2 : WARNING  Jail zesty vixen who grabbed pay from quack.232myapp.area2 : ERROR    The five boxing wizards jump quickly.233```234235а в файле увидите примерно такое236237```python23810-22 22:19 root         INFO     Jackdaws love my big sphinx of quartz.23910-22 22:19 myapp.area1  DEBUG    Quick zephyrs blow, vexing daft Jim.24010-22 22:19 myapp.area1  INFO     How quickly daft jumping zebras vex.24110-22 22:19 myapp.area2  WARNING  Jail zesty vixen who grabbed pay from quack.24210-22 22:19 myapp.area2  ERROR    The five boxing wizards jump quickly.243```244245Как видите, сообщение DEBUG отображается только в файле. Остальные сообщения отправляются в оба места назначения.246247В этом примере используются консольный и файловый обработчики, но вы можете использовать любое количество и любое сочетание обработчиков по своему выбору.248249## Пример сервера конфигурации250251Вот пример модуля, использующего сервер конфигурации журналирования:252253```python254import logging255import logging.config256import time257import os258259# Прочитать начальный конфигурационный файл.260logging.config.fileConfig('logging.conf')261262# Создать и запустить слушатель на порту 9999.263t = logging.config.listen(9999)264t.start()265266logger = logging.getLogger('simpleExample')267268try:269    # Прокрутить вызовы логирования, чтобы увидеть разницу.270    # Создавать новые конфигурации до нажатия Ctrl+C.271    while True:272        logger.debug('debug message')273        logger.info('info message')274        logger.warn('warn message')275        logger.error('error message')276        logger.critical('critical message')277        time.sleep(5)278except KeyboardInterrupt:279    # очистка280    logging.config.stopListening()281    t.join()282```283284А вот скрипт, который принимает имя файла и отправляет этот файл на сервер, предварив его двоично-закодированной длиной, в качестве новой конфигурации журналирования:285286```python287#!/usr/bin/env python288import socket, sys, struct289290with open(sys.argv[1], 'rb') as f:291    data_to_send = f.read()292293HOST = 'localhost'294PORT = 9999295s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)296print('connecting...')297s.connect((HOST, PORT))298print('sending config...')299s.send(struct.pack('>L', len(data_to_send)))300s.send(data_to_send)301s.close()302print('complete')303```304305## Работа с блокирующими обработчиками306307Иногда требуется, чтобы обработчики логирования выполняли свою работу, не блокируя поток, из которого ведется логирование. Это часто встречается в веб-приложениях, хотя, конечно, бывает и в других сценариях.308309Типичный виновник медленной работы – [`SMTPHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.SMTPHandler): отправка электронной почты может занимать много времени по ряду причин, не зависящих от разработчика (например, из-за плохой работы почтовой или сетевой инфраструктуры). Но почти любой сетевой обработчик может блокировать: даже операция [`SocketHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.SocketHandler) может выполнять DNS-запрос «под капотом», который оказывается слишком медленным (и этот запрос может быть глубоко в коде библиотеки сокетов, ниже уровня Python и вне вашего контроля).310311Одно из решений – использовать двухчастный подход. На первом этапе к логгерам, к которым обращаются из критичных по производительности потоков, следует подключать только [`QueueHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.QueueHandler). Они просто пишут в свою очередь, которую можно настроить на достаточно большую ёмкость или инициализировать без верхнего ограничения размера. Запись в очередь обычно выполняется быстро, хотя в коде желательно перехватывать исключение [`queue.Full`](https://python-all.ru/3.5/library/queue.html#queue.Full) на всякий случай. Если вы – разработчик библиотеки, в коде которой есть критичные по производительности потоки, обязательно задокументируйте это (вместе с рекомендацией подключать к вашим логгерам только `QueueHandlers`) для пользы других разработчиков, которые будут использовать ваш код.312313Вторая часть решения – [`QueueListener`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.QueueListener), который был разработан как аналог [`QueueHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.QueueHandler). [`QueueListener`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.QueueListener) устроен очень просто: ему передаётся очередь и несколько обработчиков, и он запускает внутренний поток, который слушает свою очередь на предмет LogRecords, отправленных из `QueueHandlers` (или любого другого источника `LogRecords`). `LogRecords` извлекаются из очереди и передаются обработчикам для обработки.314315Преимущество отдельного класса [`QueueListener`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.QueueListener) в том, что один его экземпляр может обслуживать несколько `QueueHandlers`. Это более экономит ресурсы, чем, скажем, многопоточные версии существующих классов обработчиков, которые расходовали бы по одному потоку на обработчик без особой пользы.316317Ниже приведён пример использования этих двух классов (импорты опущены):318319```python320que = queue.Queue(-1)  # Без ограничения размера.321queue_handler = QueueHandler(que)322handler = logging.StreamHandler()323listener = QueueListener(que, handler)324root = logging.getLogger()325root.addHandler(queue_handler)326formatter = logging.Formatter('%(threadName)s: %(message)s')327handler.setFormatter(formatter)328listener.start()329# Вывод лога будет отображать поток, создавший событие (главный поток), а не внутренний поток,330# отслеживающий внутреннюю очередь.331# Именно это и должно происходить.332# то, что должно произойти.333root.warning('Look out!')334listener.stop()335```336337который при запуске выведет:338339```text340MainThread: Look out!341```342343Изменено в версии 3.5: До Python 3.5 [`QueueListener`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.QueueListener) всегда передавал каждое полученное из очереди сообщение каждому обработчику, с которыми был инициализирован. (Это объяснялось тем, что предполагалось, что фильтрация по уровню полностью выполняется на стороне наполнения очереди.) Начиная с версии 3.5 это поведение можно изменить, передав именованный аргумент `respect_handler_level=True` конструктору слушателя. Когда это сделано, слушатель сравнивает уровень каждого сообщения с уровнем обработчика и передаёт сообщение обработчику, только если это уместно.344345## Отправка и получение событий логирования по сети346347Допустим, вы хотите отправлять события логирования по сети и обрабатывать их на принимающей стороне. Простой способ – подключить экземпляр [`SocketHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.SocketHandler) к корневому логгеру на отправляющей стороне:348349```python350import logging, logging.handlers351352rootLogger = logging.getLogger('')353rootLogger.setLevel(logging.DEBUG)354socketHandler = logging.handlers.SocketHandler('localhost',355                    logging.handlers.DEFAULT_TCP_LOGGING_PORT)356# Не нужно использовать форматтер, так как сокет-обработчик отправляет событие в виде неформатированного пикла.357# неформатированный pickle358rootLogger.addHandler(socketHandler)359360# Теперь можно выполнять запись в корневой логгер или любой другой. Сначала корневой...361logging.info('Jackdaws love my big sphinx of quartz.')362363# Теперь определите несколько других логгеров, которые могут представлять разные части приложения:364# приложение:365366logger1 = logging.getLogger('myapp.area1')367logger2 = logging.getLogger('myapp.area2')368369logger1.debug('Quick zephyrs blow, vexing daft Jim.')370logger1.info('How quickly daft jumping zebras vex.')371logger2.warning('Jail zesty vixen who grabbed pay from quack.')372logger2.error('The five boxing wizards jump quickly.')373```374375На принимающей стороне можно настроить приёмник с помощью модуля [`socketserver`](https://python-all.ru/3.5/library/socketserver.html#module-socketserver). Вот простой работающий пример:376377```python378import pickle379import logging380import logging.handlers381import socketserver382import struct383384class LogRecordStreamHandler(socketserver.StreamRequestHandler):385    """Обработчик для потокового запроса логирования.386387    Это по сути записывает запись, используя ту политику логирования, которая настроена локально.388    настроено локально.389    """390391    def handle(self):392        """393        Обрабатывает несколько запросов – каждый ожидается в формате: 4-байтовая длина, затем запись журнала в формате пикл.394        Записывает запись в соответствии с политикой, настроенной локально.395        согласно локально настроенной политике.396        """397        while True:398            chunk = self.connection.recv(4)399            if len(chunk) < 4:400                break401            slen = struct.unpack('>L', chunk)[0]402            chunk = self.connection.recv(slen)403            while len(chunk) < slen:404                chunk = chunk + self.connection.recv(slen - len(chunk))405            obj = self.unPickle(chunk)406            record = logging.makeLogRecord(obj)407            self.handleLogRecord(record)408409    def unPickle(self, data):410        return pickle.loads(data)411412    def handleLogRecord(self, record):413        # Если указано имя, используется именованный логгер, а не тот, что414        # подразумевается записью.415        if self.server.logname is not None:416            name = self.server.logname417        else:418            name = record.name419        logger = logging.getLogger(name)420        # Примечание: КАЖДАЯ запись попадает в журнал. Это связано с тем, что Logger.handle421        # обычно вызывается ПОСЛЕ фильтрации на уровне регистратора. Если требуется422        # выполнять фильтрацию, делайте это на стороне клиента, чтобы не тратить423        # циклы процессора и сетевую пропускную способность!424        logger.handle(record)425426class LogRecordSocketReceiver(socketserver.ThreadingTCPServer):427    """428    Простой приёмник журнала на основе TCP-сокетов, подходящий для тестирования.429    """430431    allow_reuse_address = True432433    def __init__(self, host='localhost',434                 port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,435                 handler=LogRecordStreamHandler):436        socketserver.ThreadingTCPServer.__init__(self, (host, port), handler)437        self.abort = 0438        self.timeout = 1439        self.logname = None440441    def serve_until_stopped(self):442        import select443        abort = 0444        while not abort:445            rd, wr, ex = select.select([self.socket.fileno()],446                                       [], [],447                                       self.timeout)448            if rd:449                self.handle_request()450            abort = self.abort451452def main():453    logging.basicConfig(454        format='%(relativeCreated)5d %(name)-15s %(levelname)-8s %(message)s')455    tcpserver = LogRecordSocketReceiver()456    print('About to start TCP server...')457    tcpserver.serve_until_stopped()458459if __name__ == '__main__':460    main()461```462463Сначала запустите сервер, затем клиент. На стороне клиента в консоль ничего не выводится; на стороне сервера вы должны увидеть что-то вроде:464465```python466About to start TCP server...467   59 root            INFO     Jackdaws love my big sphinx of quartz.468   59 myapp.area1     DEBUG    Quick zephyrs blow, vexing daft Jim.469   69 myapp.area1     INFO     How quickly daft jumping zebras vex.470   69 myapp.area2     WARNING  Jail zesty vixen who grabbed pay from quack.471   69 myapp.area2     ERROR    The five boxing wizards jump quickly.472```473474Обратите внимание, что в некоторых сценариях существуют проблемы безопасности с pickle. Если они вас затрагивают, вы можете использовать альтернативную схему сериализации, переопределив метод `makePickle()` и реализовав свою альтернативу там, а также адаптировав вышеприведённый скрипт для использования вашей альтернативной сериализации.475476## Добавление контекстной информации в вывод журнала477478Иногда требуется, чтобы вывод журнала содержал контекстную информацию в дополнение к параметрам, переданным в вызове логирования. Например, в сетевом приложении может быть желательно записывать в журнал информацию, специфичную для клиента (например, имя пользователя удалённого клиента или IP-адрес). Хотя для этого можно использовать параметр *extra*, не всегда удобно передавать информацию таким образом. Может возникнуть соблазн создавать экземпляры `Logger` для каждого соединения, но это плохая идея, поскольку такие экземпляры не собираются сборщиком мусора. Хотя на практике это не проблема, когда количество экземпляров `Logger` зависит от уровня детализации, используемого при логировании приложения, управление ими может стать сложным, если количество экземпляров `Logger` станет фактически неограниченным.479480### Использование LoggerAdapter для добавления контекстной информации481482Простой способ передавать контекстную информацию для вывода вместе с информацией о событиях логирования – использовать класс `LoggerAdapter`. Этот класс спроектирован так, чтобы выглядеть как `Logger`, что позволяет вызывать `debug()`, `info()`, `warning()`, `error()`, `exception()`, `critical()` и `log()`. Эти методы имеют те же сигнатуры, что и их аналоги в `Logger`, поэтому экземпляры обоих типов можно использовать взаимозаменяемо.483484При создании экземпляра `LoggerAdapter` вы передаёте ему экземпляр `Logger` и объект, подобный словарю, содержащий вашу контекстную информацию. Когда вы вызываете один из методов логирования на экземпляре `LoggerAdapter`, он делегирует вызов базовому экземпляру `Logger`, переданному в конструктор, и организует передачу контекстной информации в этом делегированном вызове. Вот фрагмент кода `LoggerAdapter`:485486```python487def debug(self, msg, *args, **kwargs):488    """489    Передаёт вызов отладки нижележащему регистратору после добавления490    контекстной информации из данного экземпляра адаптера.491    """492    msg, kwargs = self.process(msg, kwargs)493    self.logger.debug(msg, *args, **kwargs)494```495496Метод `process()` класса `LoggerAdapter` – это то место, где контекстная информация добавляется в вывод журнала. Ему передаются сообщение и именованные аргументы вызова логирования, а он возвращает (потенциально) изменённые версии для использования в вызове базового регистратора. В реализации по умолчанию этот метод оставляет сообщение без изменений, но вставляет ключ 'extra' в именованные аргументы, значением которого является объект, подобный словарю, переданный конструктору. Конечно, если вы передали именованный аргумент 'extra' в вызове адаптера, он будет молча перезаписан.497498Преимущество использования 'extra' в том, что значения из объекта, подобного словарю, сливаются в \_\_dict\_\_ экземпляра `LogRecord`, что позволяет использовать настроенные строки с экземплярами `Formatter`, которые знают о ключах этого объекта. Если вам нужен другой метод, например, добавить контекстную информацию в начало или конец строки сообщения, достаточно создать подкласс `LoggerAdapter` и переопределить `process()` для нужного поведения. Вот простой пример:499500```python501class CustomAdapter(logging.LoggerAdapter):502    """503    Данный пример адаптера ожидает, что переданный объект, подобный словарю, содержит504    ключ 'connid', значение которого в квадратных скобках добавляется к началу сообщения журнала.505    """506    def process(self, msg, kwargs):507        return '[%s] %s' % (self.extra['connid'], msg), kwargs508```509510который можно использовать так:511512```python513logger = logging.getLogger(__name__)514adapter = CustomAdapter(logger, {'connid': some_conn_id})515```516517Тогда все события, регистрируемые через адаптер, будут содержать значение `some_conn_id`, добавленное в начало сообщений журнала.518519#### Использование объектов, отличных от словарей, для передачи контекстной информации520521Необязательно передавать в `LoggerAdapter` именно словарь – можно передать экземпляр класса, реализующего `__getitem__` и `__iter__`, чтобы он выглядел как словарь для системы логирования. Это полезно, если нужно генерировать значения динамически (тогда как значения в словаре были бы постоянными).522523### Использование фильтров для добавления контекстной информации524525Вы также можете добавлять контекстную информацию в вывод журнала с помощью определённого пользователем `Filter`. Экземплярам `Filter` разрешено изменять `LogRecords`, переданный им, включая добавление дополнительных атрибутов, которые затем можно выводить с помощью подходящей форматной строки или, если необходимо, пользовательского `Formatter`.526527Например, в веб-приложении обрабатываемый запрос (или, по крайней мере, его интересные части) можно сохранить в потоковой локальной переменной ([`threading.local`](https://python-all.ru/3.5/library/threading.html#threading.local)), а затем из `Filter` получить к ней доступ, чтобы добавить, скажем, информацию из запроса – например, удалённый IP-адрес и имя пользователя – в `LogRecord`, используя имена атрибутов 'ip' и 'user', как в примере с `LoggerAdapter` выше. В этом случае можно использовать ту же форматную строку для получения вывода, аналогичного показанному выше. Вот пример скрипта:528529```python530import logging531from random import choice532533class ContextFilter(logging.Filter):534    """535    Это фильтр, который внедряет контекстную информацию в журнал.536537    Вместо использования реальной контекстной информации в данном примере используются случайные538    данные.539    """540541    USERS = ['jim', 'fred', 'sheila']542    IPS = ['123.231.231.123', '127.0.0.1', '192.168.0.1']543544    def filter(self, record):545546        record.ip = choice(ContextFilter.IPS)547        record.user = choice(ContextFilter.USERS)548        return True549550if __name__ == '__main__':551    levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)552    logging.basicConfig(level=logging.DEBUG,553                        format='%(asctime)-15s %(name)-5s %(levelname)-8s IP: %(ip)-15s User: %(user)-8s %(message)s')554    a1 = logging.getLogger('a.b.c')555    a2 = logging.getLogger('d.e.f')556557    f = ContextFilter()558    a1.addFilter(f)559    a2.addFilter(f)560    a1.debug('A debug message')561    a1.info('An info message with %s', 'some parameters')562    for x in range(10):563        lvl = choice(levels)564        lvlname = logging.getLevelName(lvl)565        a2.log(lvl, 'A message at %s level with %d %s', lvlname, 2, 'parameters')566```567568который при запуске выдаёт примерно следующее:569570```python5712010-09-06 22:38:15,292 a.b.c DEBUG    IP: 123.231.231.123 User: fred     A debug message5722010-09-06 22:38:15,300 a.b.c INFO     IP: 192.168.0.1     User: sheila   An info message with some parameters5732010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1       User: sheila   A message at CRITICAL level with 2 parameters5742010-09-06 22:38:15,300 d.e.f ERROR    IP: 127.0.0.1       User: jim      A message at ERROR level with 2 parameters5752010-09-06 22:38:15,300 d.e.f DEBUG    IP: 127.0.0.1       User: sheila   A message at DEBUG level with 2 parameters5762010-09-06 22:38:15,300 d.e.f ERROR    IP: 123.231.231.123 User: fred     A message at ERROR level with 2 parameters5772010-09-06 22:38:15,300 d.e.f CRITICAL IP: 192.168.0.1     User: jim      A message at CRITICAL level with 2 parameters5782010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1       User: sheila   A message at CRITICAL level with 2 parameters5792010-09-06 22:38:15,300 d.e.f DEBUG    IP: 192.168.0.1     User: jim      A message at DEBUG level with 2 parameters5802010-09-06 22:38:15,301 d.e.f ERROR    IP: 127.0.0.1       User: sheila   A message at ERROR level with 2 parameters5812010-09-06 22:38:15,301 d.e.f DEBUG    IP: 123.231.231.123 User: fred     A message at DEBUG level with 2 parameters5822010-09-06 22:38:15,301 d.e.f INFO     IP: 123.231.231.123 User: fred     A message at INFO level with 2 parameters583```584585## Ведение журнала в один файл из нескольких процессов586587Хотя модуль logging является потокобезопасным и запись в один файл из нескольких потоков в одном процессе *поддерживается*, запись в один файл из *нескольких процессов* *не* поддерживается, поскольку в Python нет стандартного способа сериализовать доступ к одному файлу из нескольких процессов. Если нужно вести журнал в один файл из нескольких процессов, один из способов – сделать так, чтобы все процессы записывали данные в `SocketHandler`, а отдельный процесс реализовывал сокет-сервер, который читает из сокета и записывает в файл. (Если хотите, можно выделить один поток в одном из существующих процессов для выполнения этой функции.) [В этом разделе](https://python-all.ru/3.5/howto/logging-cookbook.html#network-logging) подробно описывается данный подход и приводится рабочий приёмник сокета, который можно использовать как отправную точку для адаптации в своих приложениях.588589Если используется недавняя версия Python, включающая модуль [`multiprocessing`](https://python-all.ru/3.5/library/multiprocessing.html#module-multiprocessing), можно написать собственный обработчик, который использует класс [`Lock`](https://python-all.ru/3.5/library/multiprocessing.html#multiprocessing.Lock) из этого модуля для сериализации доступа к файлу из процессов. Существующие `FileHandler` и подклассы в настоящее время не используют [`multiprocessing`](https://python-all.ru/3.5/library/multiprocessing.html#module-multiprocessing), хотя в будущем могут. Обратите внимание, что на данный момент модуль [`multiprocessing`](https://python-all.ru/3.5/library/multiprocessing.html#module-multiprocessing) не предоставляет работающую функциональность блокировок на всех платформах (см. [https://bugs.python.org/issue3770](https://python-all.ru/3.5/howto/logging-cookbook.html)).590591В качестве альтернативы можно использовать `Queue` и [`QueueHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.QueueHandler) для отправки всех событий журналирования одному из процессов в вашем многопроцессном приложении. В следующем примере сценария показано, как это сделать; в примере отдельный процесс-слушатель ожидает события, отправленные другими процессами, и регистрирует их в соответствии со своей собственной конфигурацией журналирования. Хотя пример демонстрирует лишь один из способов (например, вместо отдельного процесса-слушателя можно использовать поток-слушатель – реализация будет аналогичной), он позволяет задать полностью разные конфигурации журналирования для слушателя и остальных процессов в вашем приложении и может быть использован как основа для кода, отвечающего вашим конкретным требованиям:592593```python594# Вам понадобятся эти импорты в вашем коде.595import logging596import logging.handlers597import multiprocessing598599# Следующие две строки импорта только для этой демонстрации.600from random import choice, random601import time602603#604# Поскольку нужно задать настройки логирования для слушателя и рабочих процессов, функции605# слушателя и рабочего процесса принимают параметр configurer – вызываемый объект для606# настройки логирования этого процесса. Эти функции также получают очередь, которую607# используют для взаимодействия.608#609# На практике слушателя можно настроить как угодно, но заметьте: в этом простом610# примере слушатель не применяет логику уровней или фильтров к полученным записям.611# На практике эту логику, вероятно, стоит вынести в рабочие процессы, чтобы не612# пересылать между процессами события, которые всё равно будут отфильтрованы.613#614# Размер файлов при ротации намеренно сделан небольшим, чтобы результат был хорошо виден.615def listener_configurer():616    root = logging.getLogger()617    h = logging.handlers.RotatingFileHandler('mptest.log', 'a', 300, 10)618    f = logging.Formatter('%(asctime)s %(processName)-10s %(name)s %(levelname)-8s %(message)s')619    h.setFormatter(f)620    root.addHandler(h)621622# Это главный цикл процесса-слушателя: ждём события логирования623# (LogRecords) в очереди и обрабатываем их; завершаем работу, когда получаем None вместо624# LogRecord.625def listener_process(queue, configurer):626    configurer()627    while True:628        try:629            record = queue.get()630            if record is None:  # Отправляем это как сигнал завершения, чтобы слушатель остановился.631                break632            logger = logging.getLogger(record.name)633            logger.handle(record)  # Никакой логики уровней и фильтров – просто делаем дело!634        except Exception:635            import sys, traceback636            print('Whoops! Problem:', file=sys.stderr)637            traceback.print_exc(file=sys.stderr)638639# Массивы для случайного выбора в этой демонстрации.640641LEVELS = [logging.DEBUG, logging.INFO, logging.WARNING,642          logging.ERROR, logging.CRITICAL]643644LOGGERS = ['a.b.c', 'd.e.f']645646MESSAGES = [647    'Random message #1',648    'Random message #2',649    'Random message #3',650]651652# Настройка рабочего процесса выполняется в начале его работы.653# Обратите внимание: в Windows нельзя полагаться на семантику fork, поэтому каждый процесс654# будет выполнять код настройки логирования при запуске.655def worker_configurer(queue):656    h = logging.handlers.QueueHandler(queue)  # Нужен только один обработчик.657    root = logging.getLogger()658    root.addHandler(h)659    # Отправляем все сообщения для демонстрации; никакой другой логики уровней или фильтров.660    root.setLevel(logging.DEBUG)661662# Это главный цикл рабочего процесса, который просто логирует десять событий с663# случайные задержки перед завершением.664# Сообщения print нужны лишь для того, чтобы было видно, что программа работает.665def worker_process(queue, configurer):666    configurer(queue)667    name = multiprocessing.current_process().name668    print('Worker started: %s' % name)669    for i in range(10):670        time.sleep(random())671        logger = logging.getLogger(choice(LOGGERS))672        level = choice(LEVELS)673        message = choice(MESSAGES)674        logger.log(level, message)675    print('Worker finished: %s' % name)676677# Здесь организуется демонстрация. Создать очередь, создать и запустить678# слушатель, создать десять рабочих процессов и запустить их, дождаться их завершения,679# затем отправить None в очередь, чтобы сообщить слушателю о завершении.680def main():681    queue = multiprocessing.Queue(-1)682    listener = multiprocessing.Process(target=listener_process,683                                       args=(queue, listener_configurer))684    listener.start()685    workers = []686    for i in range(10):687        worker = multiprocessing.Process(target=worker_process,688                                         args=(queue, worker_configurer))689        workers.append(worker)690        worker.start()691    for w in workers:692        w.join()693    queue.put_nowait(None)694    listener.join()695696if __name__ == '__main__':697    main()698```699700Вариант приведённого выше сценария оставляет ведение журнала в главном процессе, в отдельном потоке:701702```python703import logging704import logging.config705import logging.handlers706from multiprocessing import Process, Queue707import random708import threading709import time710711def logger_thread(q):712    while True:713        record = q.get()714        if record is None:715            break716        logger = logging.getLogger(record.name)717        logger.handle(record)718719def worker_process(q):720    qh = logging.handlers.QueueHandler(q)721    root = logging.getLogger()722    root.setLevel(logging.DEBUG)723    root.addHandler(qh)724    levels = [logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,725              logging.CRITICAL]726    loggers = ['foo', 'foo.bar', 'foo.bar.baz',727               'spam', 'spam.ham', 'spam.ham.eggs']728    for i in range(100):729        lvl = random.choice(levels)730        logger = logging.getLogger(random.choice(loggers))731        logger.log(lvl, 'Message no. %d', i)732733if __name__ == '__main__':734    q = Queue()735    d = {736        'version': 1,737        'formatters': {738            'detailed': {739                'class': 'logging.Formatter',740                'format': '%(asctime)s %(name)-15s %(levelname)-8s %(processName)-10s %(message)s'741            }742        },743        'handlers': {744            'console': {745                'class': 'logging.StreamHandler',746                'level': 'INFO',747            },748            'file': {749                'class': 'logging.FileHandler',750                'filename': 'mplog.log',751                'mode': 'w',752                'formatter': 'detailed',753            },754            'foofile': {755                'class': 'logging.FileHandler',756                'filename': 'mplog-foo.log',757                'mode': 'w',758                'formatter': 'detailed',759            },760            'errors': {761                'class': 'logging.FileHandler',762                'filename': 'mplog-errors.log',763                'mode': 'w',764                'level': 'ERROR',765                'formatter': 'detailed',766            },767        },768        'loggers': {769            'foo': {770                'handlers': ['foofile']771            }772        },773        'root': {774            'level': 'DEBUG',775            'handlers': ['console', 'file', 'errors']776        },777    }778    workers = []779    for i in range(5):780        wp = Process(target=worker_process, name='worker %d' % (i + 1), args=(q,))781        workers.append(wp)782        wp.start()783    logging.config.dictConfig(d)784    lp = threading.Thread(target=logger_thread, args=(q,))785    lp.start()786    # На этом этапе главный процесс может заняться своей полезной работой787    # Когда он с этим закончит, он может дождаться завершения рабочих процессов...788    for wp in workers:789        wp.join()790    # А теперь указать потоку журналирования завершиться791    q.put(None)792    lp.join()793```794795Этот вариант показывает, как можно, например, применить конфигурацию для определённых регистраторов – например, регистратор `foo` имеет специальный обработчик, который сохраняет все события подсистемы `foo` в файл `mplog-foo.log`. Это будет использовано механизмом журналирования в главном процессе (даже если события журналирования генерируются в рабочих процессах) для направления сообщений к соответствующим местам назначения.796797## Использование ротации файлов798799Иногда требуется позволить файлу журнала расти до определённого размера, затем открыть новый файл и вести запись в него. Может потребоваться сохранять определённое количество таких файлов, и когда будет создано заданное число файлов, выполнять ротацию, чтобы и количество, и размер файлов оставались в заданных границах. Для такого сценария использования пакет logging предоставляет `RotatingFileHandler`:800801```python802import glob803import logging804import logging.handlers805806LOG_FILENAME = 'logging_rotatingfile_example.out'807808# Настроить конкретный регистратор с нужным уровнем вывода809my_logger = logging.getLogger('MyLogger')810my_logger.setLevel(logging.DEBUG)811812# Добавить обработчик сообщений журнала в регистратор813handler = logging.handlers.RotatingFileHandler(814              LOG_FILENAME, maxBytes=20, backupCount=5)815816my_logger.addHandler(handler)817818# Записать несколько сообщений819for i in range(20):820    my_logger.debug('i = %d' % i)821822# Посмотреть, какие файлы созданы823logfiles = glob.glob('%s*' % LOG_FILENAME)824825for filename in logfiles:826    print(filename)827```828829В результате должно получиться 6 отдельных файлов, каждый из которых содержит часть истории журнала приложения:830831```python832logging_rotatingfile_example.out833logging_rotatingfile_example.out.1834logging_rotatingfile_example.out.2835logging_rotatingfile_example.out.3836logging_rotatingfile_example.out.4837logging_rotatingfile_example.out.5838```839840Самый свежий файл всегда называется `logging_rotatingfile_example.out`, и каждый раз при достижении ограничения по размеру он переименовывается с суффиксом `.1`. Каждый из существующих резервных файлов переименовывается с увеличением суффикса (`.1` становится `.2` и т.д.), а файл `.6` удаляется.841842Разумеется, в этом примере размер файла журнала установлен слишком маленьким для наглядности. В реальности нужно установить *maxBytes* в подходящее значение.843844## Использование альтернативных стилей форматирования845846Когда журналирование было добавлено в стандартную библиотеку Python, единственным способом форматирования сообщений с переменным содержимым было использование %-форматирования. С тех пор в Python появились два новых подхода к форматированию: [`string.Template`](https://python-all.ru/3.5/library/string.html#string.Template) (добавлен в Python 2.4) и [`str.format()`](https://python-all.ru/3.5/library/stdtypes.html#str.format) (добавлен в Python 2.6).847848Начиная с версии 3.2, модуль logging предоставляет улучшенную поддержку этих двух дополнительных стилей форматирования. Класс `Formatter` был расширен: добавлен дополнительный необязательный именованный параметр `style`. По умолчанию он равен `'%'`, но возможны также значения `'{'` и `'$'`, соответствующие двум другим стилям форматирования. Обратная совместимость сохраняется по умолчанию (как и следовало ожидать), но при явном указании параметра style появляется возможность задавать строки формата, работающие с [`str.format()`](https://python-all.ru/3.5/library/stdtypes.html#str.format) или [`string.Template`](https://python-all.ru/3.5/library/string.html#string.Template). Вот пример сеанса работы в консоли, демонстрирующий возможности:849850```pycon851>>> import logging852>>> root = logging.getLogger()853>>> root.setLevel(logging.DEBUG)854>>> handler = logging.StreamHandler()855>>> bf = logging.Formatter('{asctime} {name} {levelname:8s} {message}',856...                        style='{')857>>> handler.setFormatter(bf)858>>> root.addHandler(handler)859>>> logger = logging.getLogger('foo.bar')860>>> logger.debug('This is a DEBUG message')8612010-10-28 15:11:55,341 foo.bar DEBUG    This is a DEBUG message862>>> logger.critical('This is a CRITICAL message')8632010-10-28 15:12:11,526 foo.bar CRITICAL This is a CRITICAL message864>>> df = logging.Formatter('$asctime $name ${levelname} $message',865...                        style='$')866>>> handler.setFormatter(df)867>>> logger.debug('This is a DEBUG message')8682010-10-28 15:13:06,924 foo.bar DEBUG This is a DEBUG message869>>> logger.critical('This is a CRITICAL message')8702010-10-28 15:13:11,494 foo.bar CRITICAL This is a CRITICAL message871>>>872```873874Обратите внимание: форматирование сообщений журнала для конечного вывода в файлы совершенно не зависит от того, как конструируется отдельное сообщение. Оно по-прежнему может использовать %-форматирование, как показано ниже:875876```python877>>> logger.error('This is an%s %s %s', 'other,', 'ERROR,', 'message')8782010-10-28 15:19:29,833 foo.bar ERROR This is another, ERROR, message879>>>880```881882Вызовы логирования (`logger.debug()`, `logger.info()` и т.д.) принимают только позиционные параметры для самого сообщения, а ключевые параметры используются только для определения опций обработки вызова (например, ключевой параметр `exc_info` для указания, что нужно логировать трассировку, или ключевой параметр `extra` для добавления дополнительной контекстной информации). Поэтому напрямую использовать синтаксис [`str.format()`](https://python-all.ru/3.5/library/stdtypes.html#str.format) или [`string.Template`](https://python-all.ru/3.5/library/string.html#string.Template) в вызовах логирования нельзя, так как внутри пакет logging использует %-форматирование для объединения строки формата и переменных аргументов. Изменить это без потери обратной совместимости невозможно, поскольку все существующие вызовы логирования в коде используют строки с %-форматом.883884Однако существует способ использовать {}- и $-форматирование для построения отдельных сообщений журнала. Напомним, что в качестве строки формата сообщения можно использовать произвольный объект, и пакет logging вызовет у этого объекта `str()` для получения фактической строки формата. Рассмотрим следующие два класса:885886```python887class BraceMessage:888    def __init__(self, fmt, *args, **kwargs):889        self.fmt = fmt890        self.args = args891        self.kwargs = kwargs892893    def __str__(self):894        return self.fmt.format(*self.args, **self.kwargs)895896class DollarMessage:897    def __init__(self, fmt, **kwargs):898        self.fmt = fmt899        self.kwargs = kwargs900901    def __str__(self):902        from string import Template903        return Template(self.fmt).substitute(**self.kwargs)904```905906Любой из этих классов можно использовать вместо строки формата, чтобы разрешить применение {}- или $-форматирования для построения фактической части «message», которая появляется в отформатированном выводе журнала вместо «%(message)s», «{message}» или «$message». Это немного громоздко – использовать имена классов каждый раз при журналировании, но вполне приемлемо, если применить псевдоним, например \_\_ (двойное подчеркивание – не путать с \_, одинарным подчеркиванием, используемым как синоним/псевдоним для [`gettext.gettext()`](https://python-all.ru/3.5/library/gettext.html#gettext.gettext) или его аналогов).907908Вышеуказанные классы не входят в состав Python, но их легко скопировать и вставить в свой код. Их можно использовать следующим образом (предполагая, что они объявлены в модуле с именем `wherever`):909910```pycon911>>> from wherever import BraceMessage as __912>>> print(__('Message with {0} {name}', 2, name='placeholders'))913Message with 2 placeholders914>>> class Point: pass915...916>>> p = Point()917>>> p.x = 0.5918>>> p.y = 0.5919>>> print(__('Message with coordinates: ({point.x:.2f}, {point.y:.2f})',920...       point=p))921Message with coordinates: (0.50, 0.50)922>>> from wherever import DollarMessage as __923>>> print(__('Message with $num $what', num=2, what='placeholders'))924Message with 2 placeholders925>>>926```927928Хотя в приведённых выше примерах используется `print()` для демонстрации работы форматирования, в реальности для ведения журнала с помощью этого подхода следует использовать `logger.debug()` или аналогичную функцию.929930Следует отметить, что этот подход не даёт значительного снижения производительности с этим подходом: фактическое форматирование происходит не тогда, когда вы делаете вызов регистрации, а когда (и если) регистрируемое сообщение действительно должно быть выведено в журнал с помощью обработчика. Поэтому единственное, что может сбить с толку, – это то, что скобки ставятся вокруг строки формата и аргументов, а не только вокруг строки формата. Это потому, что нотация \_\_ – это просто синтаксический сахар для вызова конструктора одного из классов XXXMessage.931932Если хотите, можно использовать `LoggerAdapter` для достижения аналогичного эффекта, как в следующем примере:933934```python935import logging936937class Message(object):938    def __init__(self, fmt, args):939        self.fmt = fmt940        self.args = args941942    def __str__(self):943        return self.fmt.format(*self.args)944945class StyleAdapter(logging.LoggerAdapter):946    def __init__(self, logger, extra=None):947        super(StyleAdapter, self).__init__(logger, extra or {})948949    def log(self, level, msg, *args, **kwargs):950        if self.isEnabledFor(level):951            msg, kwargs = self.process(msg, kwargs)952            self.logger._log(level, Message(msg, args), (), **kwargs)953954logger = StyleAdapter(logging.getLogger(__name__))955956def main():957    logger.debug('Hello, {}', 'world!')958959if __name__ == '__main__':960    logging.basicConfig(level=logging.DEBUG)961    main()962```963964При запуске с Python 3.2 или новее указанный выше скрипт должен записать сообщение `Hello, world!`.965966## Настройка `LogRecord`967968Каждое событие журналирования представлено экземпляром [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord). Когда событие регистрируется и не отфильтровывается по уровню регистратора, создаётся [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord), заполняется информацией о событии и затем передаётся обработчикам для этого регистратора (и его предков, вплоть до регистратора, в котором дальнейшее распространение по иерархии отключено). До Python 3.2 было только два места, где выполнялось это создание:969970- [`Logger.makeRecord()`](https://python-all.ru/3.5/library/logging.html#logging.Logger.makeRecord), который вызывается в обычном процессе регистрации события. Он напрямую вызывал [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord) для создания экземпляра.971- [`makeLogRecord()`](https://python-all.ru/3.5/library/logging.html#logging.makeLogRecord), которая вызывается со словарем, содержащим атрибуты для добавления в LogRecord. Обычно она вызывается, когда подходящий словарь был получен по сети (например, в виде pickle через [`SocketHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.SocketHandler) или в формате JSON через [`HTTPHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.HTTPHandler)).972973Обычно это означало, что если требуется выполнить какие-либо специальные действия с [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord), приходилось делать одно из следующего.974975- Создать собственный подкласс [`Logger`](https://python-all.ru/3.5/library/logging.html#logging.Logger), который переопределяет [`Logger.makeRecord()`](https://python-all.ru/3.5/library/logging.html#logging.Logger.makeRecord), и установить его с помощью [`setLoggerClass()`](https://python-all.ru/3.5/library/logging.html#logging.setLoggerClass) до того, как будут созданы какие-либо логгеры, которые вас интересуют.976- Добавить [`Filter`](https://python-all.ru/3.5/library/logging.html#logging.Filter) к логгеру или обработчику, который выполняет необходимые специальные манипуляции при вызове его метода [`filter()`](https://python-all.ru/3.5/library/logging.html#logging.Filter.filter).977978Первый подход был бы несколько громоздким в сценарии, где (скажем) несколько разных библиотек хотели бы делать разные вещи. Каждая попыталась бы установить свой собственный подкласс [`Logger`](https://python-all.ru/3.5/library/logging.html#logging.Logger), и та, которая сделала это последней, победила бы.979980Второй подход достаточно хорошо работает во многих случаях, но не позволяет, например, использовать специализированный подкласс [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord). Разработчики библиотек могут установить подходящий фильтр на своих логгерах, но им приходилось бы помнить об этом каждый раз, когда они добавляют новый логгер (что они делают, просто добавляя новые пакеты или модули и выполняя981982```python983logger = logging.getLogger(__name__)984```985986на уровне модуля). Вероятно, это одна из тех вещей, о которых нужно помнить. Разработчики также могли бы добавить фильтр к [`NullHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.NullHandler), прикрепленному к их корневому логгеру, но он не будет вызываться, если разработчик приложения прикрепит обработчик к логгеру библиотеки нижнего уровня – так что вывод от этого обработчика не будет отражать намерений разработчика библиотеки.987988В Python 3.2 и новее создание [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord) осуществляется через фабрику, которую можно указать. Фабрика – это просто вызываемый объект, который можно установить с помощью [`setLogRecordFactory()`](https://python-all.ru/3.5/library/logging.html#logging.setLogRecordFactory) и запросить с помощью [`getLogRecordFactory()`](https://python-all.ru/3.5/library/logging.html#logging.getLogRecordFactory). Фабрика вызывается с той же сигнатурой, что и конструктор [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord), поскольку [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord) является значением по умолчанию для фабрики.989990Этот подход позволяет пользовательской фабрике контролировать все аспекты создания LogRecord. Например, можно вернуть подкласс или просто добавить несколько дополнительных атрибутов к записи после ее создания, используя шаблон, подобный следующему:991992```python993old_factory = logging.getLogRecordFactory()994995def record_factory(*args, **kwargs):996    record = old_factory(*args, **kwargs)997    record.custom_attribute = 0xdecafbad998    return record9991000logging.setLogRecordFactory(record_factory)1001```10021003Этот шаблон позволяет разным библиотекам объединять фабрики в цепочку, и пока они не перезаписывают атрибуты друг друга или случайно не перезаписывают стандартные атрибуты, никаких сюрпризов быть не должно. Однако следует иметь в виду, что каждое звено цепочки добавляет накладные расходы во время выполнения ко всем операциям логирования, и эту технику следует использовать только тогда, когда использование [`Filter`](https://python-all.ru/3.5/library/logging.html#logging.Filter) не дает желаемого результата.10041005## Создание подкласса QueueHandler – пример с ZeroMQ10061007Можно использовать подкласс `QueueHandler` для отправки сообщений в очереди других типов, например, в сокет ZeroMQ «publish». В приведенном ниже примере сокет создается отдельно и передается обработчику (в качестве его «очереди»):10081009```python1010import zmq   # с использованием pyzmq, привязки Python к ZeroMQ1011import json  # для переносимой сериализации записей10121013ctx = zmq.Context()1014sock = zmq.Socket(ctx, zmq.PUB)  # или zmq.PUSH, или другое подходящее значение1015sock.bind('tcp://*:5556')        # или где угодно10161017class ZeroMQSocketHandler(QueueHandler):1018    def enqueue(self, record):1019        data = json.dumps(record.__dict__)1020        self.queue.send(data)10211022handler = ZeroMQSocketHandler(sock)1023```10241025Конечно, есть и другие способы организации этого, например, передача данных, необходимых обработчику для создания сокета:10261027```python1028class ZeroMQSocketHandler(QueueHandler):1029    def __init__(self, uri, socktype=zmq.PUB, ctx=None):1030        self.ctx = ctx or zmq.Context()1031        socket = zmq.Socket(self.ctx, socktype)1032        socket.bind(uri)1033        QueueHandler.__init__(self, socket)10341035    def enqueue(self, record):1036        data = json.dumps(record.__dict__)1037        self.queue.send(data)10381039    def close(self):1040        self.queue.close()1041```10421043## Создание подкласса QueueListener – пример с ZeroMQ10441045Можно также создать подкласс `QueueListener` для получения сообщений из очередей других типов, например, из сокета ZeroMQ «subscribe». Вот пример:10461047```python1048class ZeroMQSocketListener(QueueListener):1049    def __init__(self, uri, *handlers, **kwargs):1050        self.ctx = kwargs.get('ctx') or zmq.Context()1051        socket = zmq.Socket(self.ctx, zmq.SUB)1052        socket.setsockopt(zmq.SUBSCRIBE, '')  # подписаться на всё1053        socket.connect(uri)10541055    def dequeue(self):1056        msg = self.queue.recv()1057        return logging.makeLogRecord(json.loads(msg))1058```10591060> **См. также**1061>1062> **Модуль [`logging`](https://python-all.ru/3.5/library/logging.html#module-logging)**1063>1064> Справочник API для модуля logging.1065>1066> **Модуль [`logging.config`](https://python-all.ru/3.5/library/logging.config.html#module-logging.config)**1067>1068> API конфигурации для модуля logging.1069>1070> **Модуль [`logging.handlers`](https://python-all.ru/3.5/library/logging.handlers.html#module-logging.handlers)**1071>1072> Полезные обработчики, входящие в состав модуля logging.1073>1074> [Базовое руководство по логированию](https://python-all.ru/3.5/howto/logging.html#logging-basic-tutorial)1075>1076> [Более продвинутое руководство по логированию](https://python-all.ru/3.5/howto/logging.html#logging-advanced-tutorial)10771078## Пример конфигурации на основе словаря10791080Ниже приведен пример словаря конфигурации логирования – он взят из [документации проекта Django](https://python-all.ru/3.5/howto/logging-cookbook.html). Этот словарь передается в [`dictConfig()`](https://python-all.ru/3.5/library/logging.config.html#logging.config.dictConfig) для применения конфигурации:10811082```python1083LOGGING = {1084    'version': 1,1085    'disable_existing_loggers': True,1086    'formatters': {1087        'verbose': {1088            'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s'1089        },1090        'simple': {1091            'format': '%(levelname)s %(message)s'1092        },1093    },1094    'filters': {1095        'special': {1096            '()': 'project.logging.SpecialFilter',1097            'foo': 'bar',1098        }1099    },1100    'handlers': {1101        'null': {1102            'level':'DEBUG',1103            'class':'django.utils.log.NullHandler',1104        },1105        'console':{1106            'level':'DEBUG',1107            'class':'logging.StreamHandler',1108            'formatter': 'simple'1109        },1110        'mail_admins': {1111            'level': 'ERROR',1112            'class': 'django.utils.log.AdminEmailHandler',1113            'filters': ['special']1114        }1115    },1116    'loggers': {1117        'django': {1118            'handlers':['null'],1119            'propagate': True,1120            'level':'INFO',1121        },1122        'django.request': {1123            'handlers': ['mail_admins'],1124            'level': 'ERROR',1125            'propagate': False,1126        },1127        'myproject.custom': {1128            'handlers': ['console', 'mail_admins'],1129            'level': 'INFO',1130            'filters': ['special']1131        }1132    }1133}1134```11351136Для получения дополнительной информации об этой конфигурации можно обратиться к [соответствующему разделу](https://python-all.ru/3.5/howto/logging-cookbook.html) документации Django.11371138## Использование ротатора и средства именования для настройки обработки ротации журналов11391140Пример того, как можно определить namer и rotator, приведен в следующем фрагменте кода, который демонстрирует сжатие журнала с использованием zlib:11411142```python1143def namer(name):1144    return name + ".gz"11451146def rotator(source, dest):1147    with open(source, "rb") as sf:1148        data = sf.read()1149        compressed = zlib.compress(data, 9)1150        with open(dest, "wb") as df:1151            df.write(compressed)1152    os.remove(source)11531154rh = logging.handlers.RotatingFileHandler(...)1155rh.rotator = rotator1156rh.namer = namer1157```11581159Это не «настоящие» .gz-файлы, поскольку они представляют собой просто сжатые данные без «контейнера», который присутствует в обычном gzip-файле. Данный фрагмент приведен только для иллюстрации.11601161## Более сложный пример с многопроцессностью11621163Следующий рабочий пример показывает, как можно использовать логирование с многопроцессностью с помощью файлов конфигурации. Конфигурации довольно просты, но служат иллюстрацией того, как можно реализовать более сложные в реальном сценарии многопроцессной обработки.11641165В примере главный процесс порождает процесс-слушатель и несколько рабочих процессов. Каждый из главного процесса, слушателя и рабочих имеет три отдельные конфигурации (все рабочие используют одну и ту же конфигурацию). Видно ведение журнала в главном процессе, как рабочие пишут в QueueHandler, а слушатель реализует QueueListener и более сложную конфигурацию ведения журнала, и организует отправку событий, полученных через очередь, обработчикам, указанным в конфигурации. Обратите внимание, что эти конфигурации чисто иллюстративные, но этот пример можно адаптировать под свой сценарий.11661167Вот скрипт – строки документации и комментарии, надеюсь, поясняют, как он работает:11681169```python1170import logging1171import logging.config1172import logging.handlers1173from multiprocessing import Process, Queue, Event, current_process1174import os1175import random1176import time11771178class MyHandler:1179    """1180    Простой обработчик для событий логирования. Он выполняется в процессе-слушателе и1181    распределяет события по логгерам на основе имени в полученной записи,1182    которые затем передаются системой логирования обработчикам,1183    настроенным для этих логгеров.1184    """1185    def handle(self, record):1186        logger = logging.getLogger(record.name)1187        # Имя процесса преобразуется только для того, чтобы показать, что это слушатель1188        # выполняет логирование в файлы и консоль.1189        record.processName = '%s (for %s)' % (current_process().name, record.processName)1190        logger.handle(record)11911192def listener_process(q, stop_event, config):1193    """1194    Это можно было бы сделать в главном процессе, но сделано в отдельном1195    процессе для наглядности.11961197    Это инициализирует логирование согласно указанной конфигурации1198    запускает слушатель и ожидает сигнала от главного процесса о завершении1199    через событие. Затем слушатель останавливается, и процесс завершается.1200    """1201    logging.config.dictConfig(config)1202    listener = logging.handlers.QueueListener(q, MyHandler())1203    listener.start()1204    if os.name == 'posix':1205        # В POSIX логгер setup уже был настроен в1206        # родительском процессе, но должен был быть отключён после вызова1207        # dictConfig.1208        # В Windows, поскольку fork не используется, логгер setup не будет1209        # существовать в дочернем процессе, поэтому он будет создан, и сообщение1210        # появится – отсюда и конструкция "if posix".1211        logger = logging.getLogger('setup')1212        logger.critical('Should not appear, because of disabled logger ...')1213    stop_event.wait()1214    listener.stop()12151216def worker_process(config):1217    """1218    Некоторое количество таких процессов порождается для иллюстрации. На1219    практике это могла бы быть разнородная группа процессов, а не1220    идентичные друг другу.12211222    Это инициализирует логирование согласно указанной конфигурации1223    и записывает сотню сообщений со случайными уровнями в случайно выбранные1224    логгеры.12251226    Добавлена небольшая задержка, чтобы дать другим процессам шанс выполниться. Это1227    не является строго необходимым, но позволяет немного перемешать вывод от разных1228    процессов больше, чем если бы её не было.1229    """1230    logging.config.dictConfig(config)1231    levels = [logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,1232              logging.CRITICAL]1233    loggers = ['foo', 'foo.bar', 'foo.bar.baz',1234               'spam', 'spam.ham', 'spam.ham.eggs']1235    if os.name == 'posix':1236        # В POSIX логгер setup уже был настроен в1237        # родительском процессе, но должен был быть отключён после вызова1238        # dictConfig.1239        # В Windows, поскольку fork не используется, логгер setup не будет1240        # существовать в дочернем процессе, поэтому он будет создан, и сообщение1241        # появится – отсюда и конструкция "if posix".1242        logger = logging.getLogger('setup')1243        logger.critical('Should not appear, because of disabled logger ...')1244    for i in range(100):1245        lvl = random.choice(levels)1246        logger = logging.getLogger(random.choice(loggers))1247        logger.log(lvl, 'Message no. %d', i)1248        time.sleep(0.01)12491250def main():1251    q = Queue()1252    # Главный процесс получает простую конфигурацию, которая выводит информацию в консоль.1253    config_initial = {1254        'version': 1,1255        'formatters': {1256            'detailed': {1257                'class': 'logging.Formatter',1258                'format': '%(asctime)s %(name)-15s %(levelname)-8s %(processName)-10s %(message)s'1259            }1260        },1261        'handlers': {1262            'console': {1263                'class': 'logging.StreamHandler',1264                'level': 'INFO',1265            },1266        },1267        'root': {1268            'level': 'DEBUG',1269            'handlers': ['console']1270        },1271    }1272    # Конфигурация рабочего процесса представляет собой QueueHandler, прикреплённый к1273    # корневому логгеру, что позволяет отправлять все сообщения в очередь.1274    # Мы отключаем существующие логгеры, чтобы отключить логгер "setup", используемый в1275    # родительском процессе. Это необходимо в POSIX, потому что логгер будет1276    # присутствовать в дочернем процессе после вызова fork().1277    config_worker = {1278        'version': 1,1279        'disable_existing_loggers': True,1280        'handlers': {1281            'queue': {1282                'class': 'logging.handlers.QueueHandler',1283                'queue': q,1284            },1285        },1286        'root': {1287            'level': 'DEBUG',1288            'handlers': ['queue']1289        },1290    }1291    # Конфигурация процесса-слушателя показывает, что вся гибкость1292    # конфигурации логирования доступна для отправки событий обработчикам так, как1293    # требуется.1294    # Мы отключаем существующие логгеры, чтобы отключить логгер "setup", используемый в1295    # родительском процессе. Это необходимо в POSIX, потому что логгер будет1296    # присутствовать в дочернем процессе после вызова fork().1297    config_listener = {1298        'version': 1,1299        'disable_existing_loggers': True,1300        'formatters': {1301            'detailed': {1302                'class': 'logging.Formatter',1303                'format': '%(asctime)s %(name)-15s %(levelname)-8s %(processName)-10s %(message)s'1304            },1305            'simple': {1306                'class': 'logging.Formatter',1307                'format': '%(name)-15s %(levelname)-8s %(processName)-10s %(message)s'1308            }1309        },1310        'handlers': {1311            'console': {1312                'class': 'logging.StreamHandler',1313                'level': 'INFO',1314                'formatter': 'simple',1315            },1316            'file': {1317                'class': 'logging.FileHandler',1318                'filename': 'mplog.log',1319                'mode': 'w',1320                'formatter': 'detailed',1321            },1322            'foofile': {1323                'class': 'logging.FileHandler',1324                'filename': 'mplog-foo.log',1325                'mode': 'w',1326                'formatter': 'detailed',1327            },1328            'errors': {1329                'class': 'logging.FileHandler',1330                'filename': 'mplog-errors.log',1331                'mode': 'w',1332                'level': 'ERROR',1333                'formatter': 'detailed',1334            },1335        },1336        'loggers': {1337            'foo': {1338                'handlers': ['foofile']1339            }1340        },1341        'root': {1342            'level': 'DEBUG',1343            'handlers': ['console', 'file', 'errors']1344        },1345    }1346    # Записываем несколько начальных событий, просто чтобы показать, что логирование в родительском процессе работает1347    # нормально.1348    logging.config.dictConfig(config_initial)1349    logger = logging.getLogger('setup')1350    logger.info('About to create workers ...')1351    workers = []1352    for i in range(5):1353        wp = Process(target=worker_process, name='worker %d' % (i + 1),1354                     args=(config_worker,))1355        workers.append(wp)1356        wp.start()1357        logger.info('Started worker: %s', wp.name)1358    logger.info('About to create listener ...')1359    stop_event = Event()1360    lp = Process(target=listener_process, name='listener',1361                 args=(q, stop_event, config_listener))1362    lp.start()1363    logger.info('Started listener')1364    # Теперь ожидаем завершения работы рабочих процессов.1365    for wp in workers:1366        wp.join()1367    # Все рабочие процессы завершены, теперь можно остановить прослушивание.1368    # Логирование в родительском процессе всё ещё работает нормально.1369    logger.info('Telling listener to stop ...')1370    stop_event.set()1371    lp.join()1372    logger.info('All done.')13731374if __name__ == '__main__':1375    main()1376```13771378## Вставка BOM в сообщения, отправляемые в SysLogHandler13791380[RFC 5424](https://python-all.ru/3.5/howto/logging-cookbook.html) требует, чтобы Unicode-сообщение отправлялось демону syslog в виде набора байтов следующей структуры: необязательный компонент, состоящий только из ASCII, затем метка порядка байтов (BOM) UTF-8, затем Unicode, закодированный в UTF-8. (См. [соответствующий раздел спецификации](https://python-all.ru/3.5/howto/logging-cookbook.html).)13811382В Python 3.1 в [`SysLogHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.SysLogHandler) был добавлен код для вставки BOM в сообщение, но, к сожалению, он был реализован некорректно: BOM появлялся в начале сообщения и, следовательно, не допускал наличия чисто ASCII-компонента перед ним.13831384Поскольку такое поведение некорректно, код, неправильно вставляющий BOM, удаляется из Python 3.2.4 и более поздних версий. Однако он не заменяется, и если требуется создавать сообщения, совместимые с RFC 5424, которые содержат BOM, необязательную последовательность символов только из ASCII перед ним и произвольный Unicode после него, закодированные в UTF-8, то необходимо сделать следующее:138513861. Необходимо присоединить экземпляр [`Formatter`](https://python-all.ru/3.5/library/logging.html#logging.Formatter) к экземпляру [`SysLogHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.SysLogHandler), указав строку формата, например:13871388   ```python1389   'ASCII section\ufeffUnicode section'1390   ```13911392   Кодовая точка Unicode U+FEFF при кодировании в UTF-8 будет представлена как метка порядка байтов UTF-8 – строка байтов `b'\xef\xbb\xbf'`.13932. ASCII-часть следует заменить на любые подходящие заполнители, но необходимо следить, чтобы данные, которые появляются там после подстановки, всегда были в ASCII (таким образом, они останутся без изменений после кодирования UTF-8).13943. Unicode-часть следует заменить на любые заполнители; если данные после подстановки содержат символы за пределами диапазона ASCII, это нормально – они будут закодированы в UTF-8.13951396Форматированное сообщение *будет* закодировано в UTF-8 с помощью `SysLogHandler`. Если следовать приведённым выше правилам, можно создавать сообщения, совместимые с RFC 5424. В противном случае логирование может не выдавать ошибок, но сообщения не будут соответствовать RFC 5424, и демон syslog может выдавать сообщения об ошибках.13971398## Реализация структурированного ведения журнала13991400Хотя большинство сообщений журнала предназначены для чтения человеком и поэтому не предназначены для машинного разбора, могут возникнуть ситуации, когда требуется выводить сообщения в структурированном формате, *который* может быть разобран программой (без необходимости в сложных регулярных выражениях). Это легко достигается с помощью пакета logging. Существует несколько способов, но ниже приведён простой подход, использующий JSON для сериализации события в машиночитаемом виде.14011402```python1403import json1404import logging14051406class StructuredMessage(object):1407    def __init__(self, message, **kwargs):1408        self.message = message1409        self.kwargs = kwargs14101411    def __str__(self):1412        return '%s >>> %s' % (self.message, json.dumps(self.kwargs))14131414_ = StructuredMessage   # необязательно, для улучшения читаемости14151416logging.basicConfig(level=logging.INFO, format='%(message)s')1417logging.info(_('message 1', foo='bar', bar='baz', num=123, fnum=123.456))1418```14191420Если запустить приведённый выше скрипт, он выведет:14211422```python1423message 1 >>> {"fnum": 123.456, "num": 123, "bar": "baz", "foo": "bar"}1424```14251426Обратите внимание, что порядок элементов может отличаться в зависимости от используемой версии Python.14271428Если требуется более специализированная обработка, можно использовать пользовательский кодировщик JSON, как в следующем полном примере:14291430```python1431from __future__ import unicode_literals14321433import json1434import logging14351436# Следующий фрагмент предназначен для того, чтобы скрипт работал без изменений в версиях 2.x и 3.x.1437try:1438    unicode1439except NameError:1440    unicode = str14411442class Encoder(json.JSONEncoder):1443    def default(self, o):1444        if isinstance(o, set):1445            return tuple(o)1446        elif isinstance(o, unicode):1447            return o.encode('unicode_escape').decode('ascii')1448        return super(Encoder, self).default(o)14491450class StructuredMessage(object):1451    def __init__(self, message, **kwargs):1452        self.message = message1453        self.kwargs = kwargs14541455    def __str__(self):1456        s = Encoder().encode(self.kwargs)1457        return '%s >>> %s' % (self.message, s)14581459_ = StructuredMessage   # необязательно, для улучшения читаемости14601461def main():1462    logging.basicConfig(level=logging.INFO, format='%(message)s')1463    logging.info(_('message 1', set_value={1, 2, 3}, snowman='\u2603'))14641465if __name__ == '__main__':1466    main()1467```14681469При запуске приведённого выше скрипта он выведет:14701471```python1472message 1 >>> {"snowman": "\u2603", "set_value": [1, 2, 3]}1473```14741475Обратите внимание, что порядок элементов может отличаться в зависимости от используемой версии Python.14761477## Настройка обработчиков с помощью [`dictConfig()`](https://python-all.ru/3.5/library/logging.config.html#logging.config.dictConfig)14781479Иногда требуется настроить обработчики логирования особым образом, и при использовании [`dictConfig()`](https://python-all.ru/3.5/library/logging.config.html#logging.config.dictConfig) это можно сделать без создания подклассов. Например, может потребоваться установить владельца файла журнала. В POSIX это легко сделать с помощью [`shutil.chown()`](https://python-all.ru/3.5/library/shutil.html#shutil.chown), но файловые обработчики в стандартной библиотеке не предоставляют встроенной поддержки. Можно настроить создание обработчика с помощью обычной функции, такой как:14801481```python1482def owned_file_handler(filename, mode='a', encoding=None, owner=None):1483    if owner:1484        if not os.path.exists(filename):1485            open(filename, 'a').close()1486        shutil.chown(filename, *owner)1487    return logging.FileHandler(filename, mode, encoding)1488```14891490Затем в конфигурации логирования, передаваемой в [`dictConfig()`](https://python-all.ru/3.5/library/logging.config.html#logging.config.dictConfig), можно указать, что обработчик должен быть создан вызовом этой функции:14911492```python1493LOGGING = {1494    'version': 1,1495    'disable_existing_loggers': False,1496    'formatters': {1497        'default': {1498            'format': '%(asctime)s %(levelname)s %(name)s %(message)s'1499        },1500    },1501    'handlers': {1502        'file':{1503            # Значения ниже извлекаются из этого словаря и1504            # используются для создания обработчика, установки его уровня и1505            # его форматтера.1506            '()': owned_file_handler,1507            'level':'DEBUG',1508            'formatter': 'default',1509            # Значения ниже передаются вызываемому объекту-создателю обработчика1510            # в качестве именованных аргументов.1511            'owner': ['pulse', 'pulse'],1512            'filename': 'chowntest.log',1513            'mode': 'w',1514            'encoding': 'utf-8',1515        },1516    },1517    'root': {1518        'handlers': ['file'],1519        'level': 'DEBUG',1520    },1521}1522```15231524В этом примере для иллюстрации права владения устанавливаются с использованием пользователя и группы `pulse`. Собирая всё вместе в рабочий скрипт, `chowntest.py`:15251526```python1527import logging, logging.config, os, shutil15281529def owned_file_handler(filename, mode='a', encoding=None, owner=None):1530    if owner:1531        if not os.path.exists(filename):1532            open(filename, 'a').close()1533        shutil.chown(filename, *owner)1534    return logging.FileHandler(filename, mode, encoding)15351536LOGGING = {1537    'version': 1,1538    'disable_existing_loggers': False,1539    'formatters': {1540        'default': {1541            'format': '%(asctime)s %(levelname)s %(name)s %(message)s'1542        },1543    },1544    'handlers': {1545        'file':{1546            # Значения ниже извлекаются из этого словаря и1547            # используются для создания обработчика, установки его уровня и1548            # его форматтера.1549            '()': owned_file_handler,1550            'level':'DEBUG',1551            'formatter': 'default',1552            # Значения ниже передаются вызываемому объекту-создателю обработчика1553            # в качестве именованных аргументов.1554            'owner': ['pulse', 'pulse'],1555            'filename': 'chowntest.log',1556            'mode': 'w',1557            'encoding': 'utf-8',1558        },1559    },1560    'root': {1561        'handlers': ['file'],1562        'level': 'DEBUG',1563    },1564}15651566logging.config.dictConfig(LOGGING)1567logger = logging.getLogger('mylogger')1568logger.debug('A debug message')1569```15701571Для запуска, вероятно, потребуется выполнить от имени `root`:15721573```console1574$ sudo python3.3 chowntest.py1575$ cat chowntest.log15762013-11-05 09:34:51,128 DEBUG mylogger A debug message1577$ ls -l chowntest.log1578-rw-r--r-- 1 pulse pulse 55 2013-11-05 09:34 chowntest.log1579```15801581Обратите внимание, что в этом примере используется Python 3.3, потому что в нём появился [`shutil.chown()`](https://python-all.ru/3.5/library/shutil.html#shutil.chown). Этот подход должен работать с любой версией Python, поддерживающей [`dictConfig()`](https://python-all.ru/3.5/library/logging.config.html#logging.config.dictConfig) – а именно Python 2.7, 3.2 или новее. В версиях до 3.3 потребовалось бы реализовать фактическую смену владельца, например, с помощью [`os.chown()`](https://python-all.ru/3.5/library/os.html#os.chown).15821583На практике функция создания обработчика может находиться в служебном модуле где-нибудь в вашем проекте. Вместо строки в конфигурации:15841585```python1586'()': owned_file_handler,1587```15881589можно использовать, например:15901591```python1592'()': 'ext://project.util.owned_file_handler',1593```15941595где `project.util` можно заменить на фактическое имя пакета, в котором находится функция. В приведённом рабочем скрипте должно сработать использование `'ext://__main__.owned_file_handler'`. Здесь фактический вызываемый объект разрешается с помощью [`dictConfig()`](https://python-all.ru/3.5/library/logging.config.html#logging.config.dictConfig) из спецификации `ext://`.15961597Этот пример, надеюсь, также показывает, как можно реализовать другие типы изменений файлов – например, установку определённых битов разрешений POSIX – аналогичным образом, с помощью [`os.chmod()`](https://python-all.ru/3.5/library/os.html#os.chmod).15981599Разумеется, этот подход можно распространить и на другие типы обработчиков, помимо [`FileHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.FileHandler) – например, на один из вращающихся файловых обработчиков или на совершенно другой тип обработчика.16001601## Использование определённых стилей форматирования во всём приложении16021603В Python 3.2 у [`Formatter`](https://python-all.ru/3.5/library/logging.html#logging.Formatter) появился именованный параметр `style`, который, хотя по умолчанию для обратной совместимости он равен `%`, позволяет указать `{` или `$` для поддержки подходов к форматированию, поддерживаемых [`str.format()`](https://python-all.ru/3.5/library/stdtypes.html#str.format) и [`string.Template`](https://python-all.ru/3.5/library/string.html#string.Template). Обратите внимание, что это управляет форматированием сообщений журнала для окончательного вывода в журнал и совершенно не зависит от того, как конструируется отдельное сообщение журнала.16041605Вызовы логирования ([`debug()`](https://python-all.ru/3.5/library/logging.html#logging.Logger.debug), [`info()`](https://python-all.ru/3.5/library/logging.html#logging.Logger.info) и т.д.) принимают только позиционные параметры для самого сообщения логирования, а именованные параметры используются только для определения параметров обработки вызова (например, именованный параметр `exc_info` для указания, что информация о трассировке должна быть записана в журнал, или именованный параметр `extra` для указания дополнительной контекстной информации, добавляемой в журнал). Поэтому вы не можете напрямую выполнять вызовы логирования с использованием синтаксиса [`str.format()`](https://python-all.ru/3.5/library/stdtypes.html#str.format) или [`string.Template`](https://python-all.ru/3.5/library/string.html#string.Template), потому что внутренне пакет logging использует %-форматирование для объединения строки формата и переменных аргументов. Это нельзя изменить, сохраняя обратную совместимость, поскольку все существующие вызовы логирования в коде используют %-форматирование строк.16061607Высказывались предложения связывать стили форматирования с конкретными регистраторами, но этот подход также сталкивается с проблемами обратной совместимости, поскольку любой существующий код может использовать данное имя регистратора и %-форматирование.16081609Чтобы логирование работало совместимо между любыми сторонними библиотеками и вашим кодом, решения о форматировании необходимо принимать на уровне отдельного вызова логирования. Это открывает несколько способов, которыми можно реализовать альтернативные стили форматирования.16101611### Использование фабрик LogRecord16121613В Python 3.2, вместе с упомянутыми выше изменениями [`Formatter`](https://python-all.ru/3.5/library/logging.html#logging.Formatter), пакет logging получил возможность позволять пользователям устанавливать свои собственные подклассы [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord) с помощью функции [`setLogRecordFactory()`](https://python-all.ru/3.5/library/logging.html#logging.setLogRecordFactory). Вы можете использовать это, чтобы установить свой собственный подкласс [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord), который делает правильные вещи, переопределяя метод [`getMessage()`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord.getMessage). В реализации базового класса этого метода происходит форматирование `msg % args`, и именно здесь можно подставить альтернативное форматирование; однако следует быть осторожным, чтобы поддерживать все стили форматирования и разрешить %-форматирование по умолчанию для обеспечения совместимости с другим кодом. Также следует позаботиться о вызове `str(self.msg)`, как это делает базовая реализация.16141615Обратитесь к справочной документации по [`setLogRecordFactory()`](https://python-all.ru/3.5/library/logging.html#logging.setLogRecordFactory) и [`LogRecord`](https://python-all.ru/3.5/library/logging.html#logging.LogRecord) для получения дополнительной информации.16161617### Использование пользовательских объектов сообщений16181619Есть еще один, возможно, более простой способ использовать {}- и $-форматирование для построения отдельных сообщений лога. Вы, возможно, помните (из раздела [Использование произвольных объектов в качестве сообщений](https://python-all.ru/3.5/howto/logging.html#arbitrary-object-messages)), что при логировании можно использовать произвольный объект в качестве строки формата сообщения, и пакет logging вызовет [`str()`](https://python-all.ru/3.5/library/stdtypes.html#str) для этого объекта, чтобы получить фактическую строку формата. Рассмотрим следующие два класса:16201621```python1622class BraceMessage(object):1623    def __init__(self, fmt, *args, **kwargs):1624        self.fmt = fmt1625        self.args = args1626        self.kwargs = kwargs16271628    def __str__(self):1629        return self.fmt.format(*self.args, **self.kwargs)16301631class DollarMessage(object):1632    def __init__(self, fmt, **kwargs):1633        self.fmt = fmt1634        self.kwargs = kwargs16351636    def __str__(self):1637        from string import Template1638        return Template(self.fmt).substitute(**self.kwargs)1639```16401641Любой из них можно использовать вместо строки формата, чтобы разрешить {}- или $-форматирование для построения фактической части «message», которая появляется в форматированном выводе лога вместо «%(message)s», «{message}» или «$message». Если вам кажется неудобным использовать имена классов каждый раз при логировании, вы можете сделать это более приятным, используя псевдоним, такой как `M` или `_` для сообщения (или, возможно, `__`, если вы используете `_` для локализации).16421643Примеры этого подхода приведены ниже. Во-первых, форматирование с помощью [`str.format()`](https://python-all.ru/3.5/library/stdtypes.html#str.format):16441645```python1646>>> __ = BraceMessage1647>>> print(__('Message with {0} {1}', 2, 'placeholders'))1648Message with 2 placeholders1649>>> class Point: pass1650...1651>>> p = Point()1652>>> p.x = 0.51653>>> p.y = 0.51654>>> print(__('Message with coordinates: ({point.x:.2f}, {point.y:.2f})', point=p))1655Message with coordinates: (0.50, 0.50)1656```16571658Во-вторых, форматирование с помощью [`string.Template`](https://python-all.ru/3.5/library/string.html#string.Template):16591660```python1661>>> __ = DollarMessage1662>>> print(__('Message with $num $what', num=2, what='placeholders'))1663Message with 2 placeholders1664>>>1665```16661667Стоит отметить, что при таком подходе вы не платите значительных потерь производительности: фактическое форматирование происходит не при вызове логирования, а когда (и если) сообщение лога действительно должно быть выведено в лог обработчиком. Так что единственная необычная вещь, которая может вас сбить с толку, это то, что круглые скобки ставятся вокруг строки формата и аргументов, а не только вокруг строки формата. Это потому, что нотация \_\_ – это просто синтаксический сахар для вызова конструктора одного из классов `XXXMessage`, показанных выше.16681669## Настройка фильтров с помощью [`dictConfig()`](https://python-all.ru/3.5/library/logging.config.html#logging.config.dictConfig)16701671*Можно* настраивать фильтры с помощью [`dictConfig()`](https://python-all.ru/3.5/library/logging.config.html#logging.config.dictConfig), хотя с первого взгляда может быть неочевидно, как это сделать (поэтому и дан этот рецепт). Поскольку [`Filter`](https://python-all.ru/3.5/library/logging.html#logging.Filter) – единственный класс фильтра, включенный в стандартную библиотеку, и вряд ли он удовлетворит многие требования (он присутствует только как базовый класс), вам, как правило, потребуется определить свой собственный подкласс [`Filter`](https://python-all.ru/3.5/library/logging.html#logging.Filter) с переопределенным методом [`filter()`](https://python-all.ru/3.5/library/logging.html#logging.Filter.filter). Для этого укажите ключ `()` в словаре конфигурации для фильтра, указав вызываемый объект, который будет использоваться для создания фильтра (класс – наиболее очевидный вариант, но вы можете предоставить любой вызываемый объект, возвращающий экземпляр [`Filter`](https://python-all.ru/3.5/library/logging.html#logging.Filter)). Вот полный пример:16721673```python1674import logging1675import logging.config1676import sys16771678class MyFilter(logging.Filter):1679    def __init__(self, param=None):1680        self.param = param16811682    def filter(self, record):1683        if self.param is None:1684            allow = True1685        else:1686            allow = self.param not in record.msg1687        if allow:1688            record.msg = 'changed: ' + record.msg1689        return allow16901691LOGGING = {1692    'version': 1,1693    'filters': {1694        'myfilter': {1695            '()': MyFilter,1696            'param': 'noshow',1697        }1698    },1699    'handlers': {1700        'console': {1701            'class': 'logging.StreamHandler',1702            'filters': ['myfilter']1703        }1704    },1705    'root': {1706        'level': 'DEBUG',1707        'handlers': ['console']1708    },1709}17101711if __name__ == '__main__':1712    logging.config.dictConfig(LOGGING)1713    logging.debug('hello')1714    logging.debug('hello - noshow')1715```17161717Этот пример показывает, как можно передавать конфигурационные данные вызываемому объекту, который создает экземпляр, в виде именованных параметров. При запуске приведенный выше скрипт выведет:17181719```python1720changed: hello1721```17221723что показывает, что фильтр работает в соответствии с настройками.17241725Несколько дополнительных моментов, на которые стоит обратить внимание:17261727- Если вы не можете сослаться на вызываемый объект напрямую в конфигурации (например, если он находится в другом модуле, и вы не можете импортировать его напрямую в том месте, где находится словарь конфигурации), вы можете использовать форму `ext://...`, как описано в разделе [Доступ к внешним объектам](https://python-all.ru/3.5/library/logging.config.html#logging-config-dict-externalobj). Например, в приведенном выше примере можно было использовать текст `'ext://__main__.MyFilter'` вместо `MyFilter`.1728- Помимо фильтров, этот метод также можно использовать для настройки пользовательских обработчиков и форматтеров. Смотрите раздел [Пользовательские объекты](https://python-all.ru/3.5/library/logging.config.html#logging-config-dict-userdef) для получения дополнительной информации о том, как logging поддерживает использование пользовательских объектов в своей конфигурации, а также см. другой рецепт из этой книги рецептов [Настройка обработчиков с помощью dictConfig()](https://python-all.ru/3.5/howto/logging-cookbook.html#custom-handlers) выше.17291730## Настраиваемое форматирование исключений17311732Могут возникнуть ситуации, когда вы захотите настроить форматирование исключений – для примера, предположим, вы хотите ровно одну строку на каждое событие лога, даже если присутствует информация об исключении. Вы можете сделать это с помощью пользовательского класса форматтера, как показано в следующем примере:17331734```python1735import logging17361737class OneLineExceptionFormatter(logging.Formatter):1738    def formatException(self, exc_info):1739        """1740        Форматировать исключение так, чтобы оно выводилось одной строкой.1741        """1742        result = super(OneLineExceptionFormatter, self).formatException(exc_info)1743        return repr(result)  # или форматировать одной строкой по своему усмотрению17441745    def format(self, record):1746        s = super(OneLineExceptionFormatter, self).format(record)1747        if record.exc_text:1748            s = s.replace('\n', '') + '|'1749        return s17501751def configure_logging():1752    fh = logging.FileHandler('output.txt', 'w')1753    f = OneLineExceptionFormatter('%(asctime)s|%(levelname)s|%(message)s|',1754                                  '%d/%m/%Y %H:%M:%S')1755    fh.setFormatter(f)1756    root = logging.getLogger()1757    root.setLevel(logging.DEBUG)1758    root.addHandler(fh)17591760def main():1761    configure_logging()1762    logging.info('Sample message')1763    try:1764        x = 1 / 01765    except ZeroDivisionError as e:1766        logging.exception('ZeroDivisionError: %s', e)17671768if __name__ == '__main__':1769    main()1770```17711772При запуске это создает файл ровно с двумя строками:17731774```python177528/01/2015 07:21:23|INFO|Sample message|177628/01/2015 07:21:23|ERROR|ZeroDivisionError: integer division or modulo by zero|'Traceback (most recent call last):\n  File "logtest7.py", line 30, in main\n    x = 1 / 0\nZeroDivisionError: integer division or modulo by zero'|1777```17781779Хотя описанный выше подход упрощен, он показывает путь к тому, как можно форматировать информацию об исключениях по своему вкусу. Модуль [`traceback`](https://python-all.ru/3.5/library/traceback.html#module-traceback) может быть полезен для более специализированных нужд.17801781## Озвучивание сообщений лога17821783Могут быть ситуации, когда желательно выводить сообщения лога в звуковом, а не визуальном формате. Это легко сделать, если в вашей системе доступна функция преобразования текста в речь (TTS), даже если у нее нет привязки к Python. Большинство TTS-систем имеют программу командной строки, которую можно запустить, и ее можно вызвать из обработчика с помощью [`subprocess`](https://python-all.ru/3.5/library/subprocess.html#module-subprocess). Здесь предполагается, что программы командной строки TTS не будут ожидать взаимодействия с пользователем или занимать много времени для завершения, и что частота сообщений лога не будет настолько высокой, чтобы перегружать пользователя сообщениями, и что допустимо проговаривать сообщения по одному, а не одновременно. В приведенном ниже примере реализации ожидается, пока одно сообщение не будет произнесено, прежде чем обрабатывать следующее, и это может заставить другие обработчики ждать. Вот короткий пример, демонстрирующий подход, который предполагает, что доступен TTS-пакет `espeak`:17841785```python1786import logging1787import subprocess1788import sys17891790class TTSHandler(logging.Handler):1791    def emit(self, record):1792        msg = self.format(record)1793        # Говорить медленно женским английским голосом.1794        cmd = ['espeak', '-s150', '-ven+f3', msg]1795        p = subprocess.Popen(cmd, stdout=subprocess.PIPE,1796                             stderr=subprocess.STDOUT)1797        # дождаться завершения программы1798        p.communicate()17991800def configure_logging():1801    h = TTSHandler()1802    root = logging.getLogger()1803    root.addHandler(h)1804    # стандартный форматтер просто возвращает сообщение1805    root.setLevel(logging.DEBUG)18061807def main():1808    logging.info('Hello')1809    logging.debug('Goodbye')18101811if __name__ == '__main__':1812    configure_logging()1813    sys.exit(main())1814```18151816При запуске этот скрипт должен сказать «Hello», а затем «Goodbye» женским голосом.18171818Описанный выше подход, конечно, можно адаптировать для других TTS-систем и даже для других систем, которые могут обрабатывать сообщения через внешние программы, запускаемые из командной строки.18191820## Буферизация сообщений лога и условный вывод18211822Могут возникнуть ситуации, когда вы хотите записывать сообщения во временную область и выводить их только при наступлении определенного условия. Например, вы можете начать запись отладочных событий в функции, и если функция завершится без ошибок, вы не захотите засорять лог собранной отладочной информацией, но если возникнет ошибка, вы захотите вывести всю отладочную информацию вместе с ошибкой.18231824Вот пример, показывающий, как это можно сделать с помощью декоратора для ваших функций, где вы хотите, чтобы логирование вело себя таким образом. Он использует [`logging.handlers.MemoryHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.handlers.MemoryHandler), который позволяет буферизовать зарегистрированные события до наступления некоторого условия, после чего буферизованные события `flushed` – передаются другому обработчику (обработчику `target`) для обработки. По умолчанию `MemoryHandler` сбрасывается, когда его буфер заполняется или встречается событие, уровень которого больше или равен указанному порогу. Вы можете использовать этот рецепт с более специализированным подклассом `MemoryHandler`, если хотите настроить поведение сброса.18251826Пример скрипта содержит простую функцию `foo`, которая просто перебирает все уровни логирования, записывая в `sys.stderr` информацию о том, какой уровень будет использоваться, а затем регистрирует сообщение на этом уровне. Вы можете передать параметр в `foo`, который, если равен true, будет регистрировать на уровнях ERROR и CRITICAL – в противном случае он регистрирует только на уровнях DEBUG, INFO и WARNING.18271828Скрипт просто декорирует `foo` декоратором, который выполняет условное логирование по необходимости. Декоратор принимает логгер в качестве параметра и подключает обработчик с буферизацией в памяти на время вызова декорируемой функции. Декоратор можно дополнительно настроить, указав целевой обработчик, уровень, при котором следует сбрасывать буфер, и ёмкость буфера. По умолчанию используются [`StreamHandler`](https://python-all.ru/3.5/library/logging.handlers.html#logging.StreamHandler), который пишет в `sys.stderr`, `logging.ERROR` и `100` соответственно.18291830Вот скрипт:18311832```python1833import logging1834from logging.handlers import MemoryHandler1835import sys18361837logger = logging.getLogger(__name__)1838logger.addHandler(logging.NullHandler())18391840def log_if_errors(logger, target_handler=None, flush_level=None, capacity=None):1841    if target_handler is None:1842        target_handler = logging.StreamHandler()1843    if flush_level is None:1844        flush_level = logging.ERROR1845    if capacity is None:1846        capacity = 1001847    handler = MemoryHandler(capacity, flushLevel=flush_level, target=target_handler)18481849    def decorator(fn):1850        def wrapper(*args, **kwargs):1851            logger.addHandler(handler)1852            try:1853                return fn(*args, **kwargs)1854            except Exception:1855                logger.exception('call failed')1856                raise1857            finally:1858                super(MemoryHandler, handler).flush()1859                logger.removeHandler(handler)1860        return wrapper18611862    return decorator18631864def write_line(s):1865    sys.stderr.write('%s\n' % s)18661867def foo(fail=False):1868    write_line('about to log at DEBUG ...')1869    logger.debug('Actually logged at DEBUG')1870    write_line('about to log at INFO ...')1871    logger.info('Actually logged at INFO')1872    write_line('about to log at WARNING ...')1873    logger.warning('Actually logged at WARNING')1874    if fail:1875        write_line('about to log at ERROR ...')1876        logger.error('Actually logged at ERROR')1877        write_line('about to log at CRITICAL ...')1878        logger.critical('Actually logged at CRITICAL')1879    return fail18801881decorated_foo = log_if_errors(logger)(foo)18821883if __name__ == '__main__':1884    logger.setLevel(logging.DEBUG)1885    write_line('Calling undecorated foo with False')1886    assert not foo(False)1887    write_line('Calling undecorated foo with True')1888    assert foo(True)1889    write_line('Calling decorated foo with False')1890    assert not decorated_foo(False)1891    write_line('Calling decorated foo with True')1892    assert decorated_foo(True)1893```18941895При запуске этого скрипта отобразится следующий вывод:18961897```python1898Calling undecorated foo with False1899about to log at DEBUG ...1900about to log at INFO ...1901about to log at WARNING ...1902Calling undecorated foo with True1903about to log at DEBUG ...1904about to log at INFO ...1905about to log at WARNING ...1906about to log at ERROR ...1907about to log at CRITICAL ...1908Calling decorated foo with False1909about to log at DEBUG ...1910about to log at INFO ...1911about to log at WARNING ...1912Calling decorated foo with True1913about to log at DEBUG ...1914about to log at INFO ...1915about to log at WARNING ...1916about to log at ERROR ...1917Actually logged at DEBUG1918Actually logged at INFO1919Actually logged at WARNING1920Actually logged at ERROR1921about to log at CRITICAL ...1922Actually logged at CRITICAL1923```19241925Как видно, фактический вывод журнала происходит только при регистрации события, уровень которого ERROR или выше, но в этом случае также регистрируются все предыдущие события с более низкими уровнями.19261927Конечно, можно использовать обычные средства декорирования:19281929```python1930@log_if_errors(logger)1931def foo(fail=False):1932    ...1933```19341935## Форматирование времени с использованием UTC (GMT) через конфигурацию19361937Иногда требуется форматировать время по UTC, что можно сделать с помощью класса такого как *UTCFormatter*, показанного ниже:19381939```python1940import logging1941import time19421943class UTCFormatter(logging.Formatter):1944    converter = time.gmtime1945```19461947и затем можно использовать `UTCFormatter` в своём коде вместо [`Formatter`](https://python-all.ru/3.5/library/logging.html#logging.Formatter). Если требуется сделать это через конфигурацию, можно воспользоваться API [`dictConfig()`](https://python-all.ru/3.5/library/logging.config.html#logging.config.dictConfig), как показано в следующем полном примере:19481949```python1950import logging1951import logging.config1952import time19531954class UTCFormatter(logging.Formatter):1955    converter = time.gmtime19561957LOGGING = {1958    'version': 1,1959    'disable_existing_loggers': False,1960    'formatters': {1961        'utc': {1962            '()': UTCFormatter,1963            'format': '%(asctime)s %(message)s',1964        },1965        'local': {1966            'format': '%(asctime)s %(message)s',1967        }1968    },1969    'handlers': {1970        'console1': {1971            'class': 'logging.StreamHandler',1972            'formatter': 'utc',1973        },1974        'console2': {1975            'class': 'logging.StreamHandler',1976            'formatter': 'local',1977        },1978    },1979    'root': {1980        'handlers': ['console1', 'console2'],1981   }1982}19831984if __name__ == '__main__':1985    logging.config.dictConfig(LOGGING)1986    logging.warning('The local time is %s', time.asctime())1987```19881989При запуске этого скрипта он должен вывести примерно следующее:19901991```python19922015-10-17 12:53:29,501 The local time is Sat Oct 17 13:53:29 201519932015-10-17 13:53:29,501 The local time is Sat Oct 17 13:53:29 20151994```19951996показывая, как время форматируется как в местном времени, так и в UTC, по одному для каждого обработчика.19971998## Использование контекстного менеджера для выборочного журналирования19992000Бывают ситуации, когда полезно временно изменить конфигурацию журналирования, а затем вернуть её обратно после выполнения каких-то действий. Для этого контекстный менеджер – самый очевидный способ сохранить и восстановить контекст журналирования. Вот простой пример такого контекстного менеджера, который позволяет по желанию изменить уровень журналирования и добавить обработчик журнала исключительно в области действия контекстного менеджера:20012002```python2003import logging2004import sys20052006class LoggingContext(object):2007    def __init__(self, logger, level=None, handler=None, close=True):2008        self.logger = logger2009        self.level = level2010        self.handler = handler2011        self.close = close20122013    def __enter__(self):2014        if self.level is not None:2015            self.old_level = self.logger.level2016            self.logger.setLevel(self.level)2017        if self.handler:2018            self.logger.addHandler(self.handler)20192020    def __exit__(self, et, ev, tb):2021        if self.level is not None:2022            self.logger.setLevel(self.old_level)2023        if self.handler:2024            self.logger.removeHandler(self.handler)2025        if self.handler and self.close:2026            self.handler.close()2027        # неявный возврат None => не подавлять исключения2028```20292030Если указать значение уровня, уровень регистратора устанавливается на это значение в области действия блока with, охватываемого контекстным менеджером. Если указать обработчик, он добавляется к регистратору при входе в блок и удаляется при выходе из блока. Также можно попросить менеджер закрыть обработчик при выходе из блока – это можно сделать, если обработчик больше не нужен.20312032Чтобы проиллюстрировать, как это работает, можно добавить следующий блок кода к предыдущему:20332034```python2035if __name__ == '__main__':2036    logger = logging.getLogger('foo')2037    logger.addHandler(logging.StreamHandler())2038    logger.setLevel(logging.INFO)2039    logger.info('1. This should appear just once on stderr.')2040    logger.debug('2. This should not appear.')2041    with LoggingContext(logger, level=logging.DEBUG):2042        logger.debug('3. This should appear once on stderr.')2043    logger.debug('4. This should not appear.')2044    h = logging.StreamHandler(sys.stdout)2045    with LoggingContext(logger, level=logging.DEBUG, handler=h, close=True):2046        logger.debug('5. This should appear twice - once on stderr and once on stdout.')2047    logger.info('6. This should appear just once on stderr.')2048    logger.debug('7. This should not appear.')2049```20502051Изначально устанавливаем уровень регистратора равным `INFO`, поэтому сообщение №1 отображается, а сообщение №2 – нет. Затем временно меняем уровень на `DEBUG` в следующем блоке `with`, и сообщение №3 отображается. После выхода из блока уровень регистратора восстанавливается до `INFO`, поэтому сообщение №4 не отображается. В следующем блоке `with` снова устанавливаем уровень `DEBUG`, но также добавляем обработчик, записывающий в `sys.stdout`. Таким образом, сообщение №5 отображается дважды на консоли (один раз через `stderr` и один раз через `stdout`). После завершения оператора `with` состояние возвращается к исходному, поэтому сообщение №6 отображается (как сообщение №1), а сообщение №7 – нет (как сообщение №2).20522053Если запустить полученный скрипт, результат будет следующим:20542055```console2056$ python logctx.py20571. This should appear just once on stderr.20583. This should appear once on stderr.20595. This should appear twice - once on stderr and once on stdout.20605. This should appear twice - once on stderr and once on stdout.20616. This should appear just once on stderr.2062```20632064Если запустить его снова, но перенаправить `stderr` в `/dev/null`, мы увидим следующее, что является единственным сообщением, записанным в `stdout`:20652066```console2067$ python logctx.py 2>/dev/null20685. This should appear twice - once on stderr and once on stdout.2069```20702071Ещё раз, но перенаправляя `stdout` в `/dev/null`, получаем:20722073```console2074$ python logctx.py >/dev/null20751. This should appear just once on stderr.20763. This should appear once on stderr.20775. This should appear twice - once on stderr and once on stdout.20786. This should appear just once on stderr.2079```20802081В этом случае сообщение №5, выведенное в `stdout`, не отображается, как и ожидалось.20822083Разумеется, описанный подход можно обобщить, например, для временного подключения фильтров журналирования. Обратите внимание, что приведённый выше код работает как в Python 2, так и в Python 3.2084