`logging-cookbook.md`

2084 строк · 141.7 КБ · обычная страница · сырой текст · скачать
1> **Источник:** https://python-all.ru/3.6/howto/logging-cookbook.html2>3> «Документация Python на русском» – неофициальный перевод официальной документации Python: версии от 2.6 до 3.16, полнотекстовый поиск, английский оригинал рядом с переводом. Эта Markdown-версия страницы предназначена для работы с LLM: вставьте её в ChatGPT, Claude или Cursor.45---67# Сборник рецептов по логированию89**Автор**1011Vinay Sajip \<vinay\_sajip at red-dove dot com\>1213На этой странице представлен ряд рецептов, связанных с логированием, которые оказались полезными на практике.1415## Использование логирования в нескольких модулях1617Многократные вызовы `logging.getLogger('someLogger')` возвращают ссылку на один и тот же объект логгера. Это верно не только в пределах одного модуля, но и для разных модулей, если они выполняются в одном процессе интерпретатора Python. Кроме того, код приложения может определить и настроить родительский логгер в одном модуле, а затем создать (но не настраивать) дочерний логгер в другом модуле – все вызовы логгера у дочернего будут передаваться родительскому. Вот главный модуль:1819```python20import logging21import auxiliary_module2223# создать логгер с именем 'spam_application'24logger = logging.getLogger('spam_application')25logger.setLevel(logging.DEBUG)26# создать файловый обработчик, записывающий даже отладочные сообщения27fh = logging.FileHandler('spam.log')28fh.setLevel(logging.DEBUG)29# создать консольный обработчик с более высоким уровнем логирования30ch = logging.StreamHandler()31ch.setLevel(logging.ERROR)32# создать форматтер и добавить его к обработчикам33formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')34fh.setFormatter(formatter)35ch.setFormatter(formatter)36# добавить обработчики к логгеру37logger.addHandler(fh)38logger.addHandler(ch)3940logger.info('creating an instance of auxiliary_module.Auxiliary')41a = auxiliary_module.Auxiliary()42logger.info('created an instance of auxiliary_module.Auxiliary')43logger.info('calling auxiliary_module.Auxiliary.do_something')44a.do_something()45logger.info('finished auxiliary_module.Auxiliary.do_something')46logger.info('calling auxiliary_module.some_function()')47auxiliary_module.some_function()48logger.info('done with auxiliary_module.some_function()')49```5051А вот вспомогательный модуль:5253```python54import logging5556# создать логгер57module_logger = logging.getLogger('spam_application.auxiliary')5859class Auxiliary:60    def __init__(self):61        self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')62        self.logger.info('creating an instance of Auxiliary')6364    def do_something(self):65        self.logger.info('doing something')66        a = 1 + 167        self.logger.info('done doing something')6869def some_function():70    module_logger.info('received a call to "some_function"')71```7273Вывод выглядит так:7475```text762005-03-23 23:47:11,663 - spam_application - INFO -77   creating an instance of auxiliary_module.Auxiliary782005-03-23 23:47:11,665 - spam_application.auxiliary.Auxiliary - INFO -79   creating an instance of Auxiliary802005-03-23 23:47:11,665 - spam_application - INFO -81   created an instance of auxiliary_module.Auxiliary822005-03-23 23:47:11,668 - spam_application - INFO -83   calling auxiliary_module.Auxiliary.do_something842005-03-23 23:47:11,668 - spam_application.auxiliary.Auxiliary - INFO -85   doing something862005-03-23 23:47:11,669 - spam_application.auxiliary.Auxiliary - INFO -87   done doing something882005-03-23 23:47:11,670 - spam_application - INFO -89   finished auxiliary_module.Auxiliary.do_something902005-03-23 23:47:11,671 - spam_application - INFO -91   calling auxiliary_module.some_function()922005-03-23 23:47:11,672 - spam_application.auxiliary - INFO -93   received a call to 'some_function'942005-03-23 23:47:11,673 - spam_application - INFO -95   done with auxiliary_module.some_function()96```9798## Журналирование из нескольких потоков99100Журналирование из нескольких потоков не требует особых усилий. В следующем примере показано журналирование из главного (начального) потока и ещё одного потока:101102```python103import logging104import threading105import time106107def worker(arg):108    while not arg['stop']:109        logging.debug('Hi from myfunc')110        time.sleep(0.5)111112def main():113    logging.basicConfig(level=logging.DEBUG, format='%(relativeCreated)6d %(threadName)s %(message)s')114    info = {'stop': False}115    thread = threading.Thread(target=worker, args=(info,))116    thread.start()117    while True:118        try:119            logging.debug('Hello from main')120            time.sleep(0.75)121        except KeyboardInterrupt:122            info['stop'] = True123            break124    thread.join()125126if __name__ == '__main__':127    main()128```129130При запуске скрипт должен вывести что-то вроде следующего:131132```text133   0 Thread-1 Hi from myfunc134   3 MainThread Hello from main135 505 Thread-1 Hi from myfunc136 755 MainThread Hello from main1371007 Thread-1 Hi from myfunc1381507 MainThread Hello from main1391508 Thread-1 Hi from myfunc1402010 Thread-1 Hi from myfunc1412258 MainThread Hello from main1422512 Thread-1 Hi from myfunc1433009 MainThread Hello from main1443013 Thread-1 Hi from myfunc1453515 Thread-1 Hi from myfunc1463761 MainThread Hello from main1474017 Thread-1 Hi from myfunc1484513 MainThread Hello from main1494518 Thread-1 Hi from myfunc150```151152Как и следовало ожидать, вывод журнала перемежается. Разумеется, такой подход работает и для большего количества потоков, чем показано здесь.153154## Несколько обработчиков и форматировщиков155156Логгеры – это обычные объекты Python. У метода [`addHandler()`](https://python-all.ru/3.6/library/logging.html#logging.Logger.addHandler) нет минимального или максимального ограничения на количество добавляемых обработчиков. Иногда приложению полезно записывать все сообщения всех уровней в текстовый файл и одновременно выводить ошибки и сообщения выше в консоль. Чтобы это настроить, достаточно сконфигурировать нужные обработчики. Вызовы журналирования в коде приложения останутся без изменений. Вот небольшая модификация предыдущего простого примера конфигурации на основе модуля:157158```python159import logging160161logger = logging.getLogger('simple_example')162logger.setLevel(logging.DEBUG)163# создать файловый обработчик, записывающий даже отладочные сообщения164fh = logging.FileHandler('spam.log')165fh.setLevel(logging.DEBUG)166# создать консольный обработчик с более высоким уровнем логирования167ch = logging.StreamHandler()168ch.setLevel(logging.ERROR)169# создать форматтер и добавить его к обработчикам170formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')171ch.setFormatter(formatter)172fh.setFormatter(formatter)173# добавить обработчики в логгер174logger.addHandler(ch)175logger.addHandler(fh)176177# код 'приложения'178logger.debug('debug message')179logger.info('info message')180logger.warn('warn message')181logger.error('error message')182logger.critical('critical message')183```184185Обратите внимание, что «прикладной» код не заботится о нескольких обработчиках. Единственное, что изменилось – добавление и настройка нового обработчика с именем *fh*.186187Возможность создавать новые обработчики с фильтрами более высокого или низкого уровня очень полезна при написании и тестировании приложения. Вместо множества операторов `print` для отладки используйте `logger.debug`: в отличие от операторов print, которые позже придётся удалять или закомментировать, вызовы logger.debug могут оставаться в исходном коде и оставаться неактивными, пока они снова не понадобятся. В тот момент единственное, что нужно изменить – уровень журналирования логгера и/или обработчика на DEBUG.188189## Журналирование в несколько мест назначения190191Допустим, вы хотите вести журнал в консоль и файл с разными форматами сообщений и в разных ситуациях. Предположим, вы хотите записывать сообщения уровня DEBUG и выше в файл, а сообщения уровня INFO и выше – в консоль. Также предположим, что файл должен содержать временные метки, а консольные сообщения – нет. Вот как это можно сделать:192193```python194import logging195196# настроить логирование в файл – подробнее см. предыдущий раздел197logging.basicConfig(level=logging.DEBUG,198                    format='%(asctime)s %(name)-12s %(levelname)-8s %(message)s',199                    datefmt='%m-%d %H:%M',200                    filename='/temp/myapp.log',201                    filemode='w')202# Определяет обработчик, который записывает сообщения уровня INFO и выше в sys.stderr.203console = logging.StreamHandler()204console.setLevel(logging.INFO)205# Задает формат, упрощенный для вывода в консоль.206formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')207# Указывает обработчику использовать этот формат.208console.setFormatter(formatter)209# Добавляет обработчик в корневой логгер.210logging.getLogger('').addHandler(console)211212# Теперь можно выполнять запись в корневой логгер или любой другой. Сначала корневой...213logging.info('Jackdaws love my big sphinx of quartz.')214215# Теперь определите несколько других логгеров, которые могут представлять разные части приложения:216# приложение:217218logger1 = logging.getLogger('myapp.area1')219logger2 = logging.getLogger('myapp.area2')220221logger1.debug('Quick zephyrs blow, vexing daft Jim.')222logger1.info('How quickly daft jumping zebras vex.')223logger2.warning('Jail zesty vixen who grabbed pay from quack.')224logger2.error('The five boxing wizards jump quickly.')225```226227При запуске на консоли вы увидите228229```text230root        : INFO     Jackdaws love my big sphinx of quartz.231myapp.area1 : INFO     How quickly daft jumping zebras vex.232myapp.area2 : WARNING  Jail zesty vixen who grabbed pay from quack.233myapp.area2 : ERROR    The five boxing wizards jump quickly.234```235236а в файле увидите примерно такое237238```text23910-22 22:19 root         INFO     Jackdaws love my big sphinx of quartz.24010-22 22:19 myapp.area1  DEBUG    Quick zephyrs blow, vexing daft Jim.24110-22 22:19 myapp.area1  INFO     How quickly daft jumping zebras vex.24210-22 22:19 myapp.area2  WARNING  Jail zesty vixen who grabbed pay from quack.24310-22 22:19 myapp.area2  ERROR    The five boxing wizards jump quickly.244```245246Как видите, сообщение DEBUG отображается только в файле. Остальные сообщения отправляются в оба места назначения.247248В этом примере используются консольный и файловый обработчики, но вы можете использовать любое количество и любое сочетание обработчиков по своему выбору.249250## Пример сервера конфигурации251252Вот пример модуля, использующего сервер конфигурации журналирования:253254```python255import logging256import logging.config257import time258import os259260# Прочитать начальный конфигурационный файл.261logging.config.fileConfig('logging.conf')262263# Создать и запустить слушатель на порту 9999.264t = logging.config.listen(9999)265t.start()266267logger = logging.getLogger('simpleExample')268269try:270    # Прокрутить вызовы логирования, чтобы увидеть разницу.271    # Создавать новые конфигурации до нажатия Ctrl+C.272    while True:273        logger.debug('debug message')274        logger.info('info message')275        logger.warn('warn message')276        logger.error('error message')277        logger.critical('critical message')278        time.sleep(5)279except KeyboardInterrupt:280    # очистка281    logging.config.stopListening()282    t.join()283```284285А вот скрипт, который принимает имя файла и отправляет этот файл на сервер, предварив его двоично-закодированной длиной, в качестве новой конфигурации журналирования:286287```python288#!/usr/bin/env python289import socket, sys, struct290291with open(sys.argv[1], 'rb') as f:292    data_to_send = f.read()293294HOST = 'localhost'295PORT = 9999296s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)297print('connecting...')298s.connect((HOST, PORT))299print('sending config...')300s.send(struct.pack('>L', len(data_to_send)))301s.send(data_to_send)302s.close()303print('complete')304```305306## Работа с блокирующими обработчиками307308Иногда требуется, чтобы обработчики логирования выполняли свою работу, не блокируя поток, из которого ведется логирование. Это часто встречается в веб-приложениях, хотя, конечно, бывает и в других сценариях.309310Типичный виновник медленной работы – [`SMTPHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.SMTPHandler): отправка электронной почты может занимать много времени по ряду причин, не зависящих от разработчика (например, из-за плохой работы почтовой или сетевой инфраструктуры). Но почти любой сетевой обработчик может блокировать: даже операция [`SocketHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.SocketHandler) может выполнять DNS-запрос «под капотом», который оказывается слишком медленным (и этот запрос может быть глубоко в коде библиотеки сокетов, ниже уровня Python и вне вашего контроля).311312Одно из решений – использовать двухчастный подход. На первом этапе к логгерам, к которым обращаются из критичных по производительности потоков, следует подключать только [`QueueHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.QueueHandler). Они просто пишут в свою очередь, которую можно настроить на достаточно большую ёмкость или инициализировать без верхнего ограничения размера. Запись в очередь обычно выполняется быстро, хотя в коде желательно перехватывать исключение [`queue.Full`](https://python-all.ru/3.6/library/queue.html#queue.Full) на всякий случай. Если вы – разработчик библиотеки, в коде которой есть критичные по производительности потоки, обязательно задокументируйте это (вместе с рекомендацией подключать к вашим логгерам только `QueueHandlers`) для пользы других разработчиков, которые будут использовать ваш код.313314Вторая часть решения – [`QueueListener`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.QueueListener), который был разработан как аналог [`QueueHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.QueueHandler). [`QueueListener`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.QueueListener) устроен очень просто: ему передаётся очередь и несколько обработчиков, и он запускает внутренний поток, который слушает свою очередь на предмет LogRecords, отправленных из `QueueHandlers` (или любого другого источника `LogRecords`). `LogRecords` извлекаются из очереди и передаются обработчикам для обработки.315316Преимущество отдельного класса [`QueueListener`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.QueueListener) в том, что один его экземпляр может обслуживать несколько `QueueHandlers`. Это более экономит ресурсы, чем, скажем, многопоточные версии существующих классов обработчиков, которые расходовали бы по одному потоку на обработчик без особой пользы.317318Ниже приведён пример использования этих двух классов (импорты опущены):319320```python321que = queue.Queue(-1)  # Без ограничения размера.322queue_handler = QueueHandler(que)323handler = logging.StreamHandler()324listener = QueueListener(que, handler)325root = logging.getLogger()326root.addHandler(queue_handler)327formatter = logging.Formatter('%(threadName)s: %(message)s')328handler.setFormatter(formatter)329listener.start()330# Вывод лога будет отображать поток, создавший событие (главный поток), а не внутренний поток,331# отслеживающий внутреннюю очередь.332# Именно это и должно происходить.333# то, что должно произойти.334root.warning('Look out!')335listener.stop()336```337338который при запуске выведет:339340```text341MainThread: Look out!342```343344Изменено в версии 3.5: До Python 3.5 [`QueueListener`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.QueueListener) всегда передавал каждое полученное из очереди сообщение каждому обработчику, с которыми был инициализирован. (Это объяснялось тем, что предполагалось, что фильтрация по уровню полностью выполняется на стороне наполнения очереди.) Начиная с версии 3.5 это поведение можно изменить, передав именованный аргумент `respect_handler_level=True` конструктору слушателя. Когда это сделано, слушатель сравнивает уровень каждого сообщения с уровнем обработчика и передаёт сообщение обработчику, только если это уместно.345346## Отправка и получение событий логирования по сети347348Допустим, вы хотите отправлять события логирования по сети и обрабатывать их на принимающей стороне. Простой способ – подключить экземпляр [`SocketHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.SocketHandler) к корневому логгеру на отправляющей стороне:349350```python351import logging, logging.handlers352353rootLogger = logging.getLogger('')354rootLogger.setLevel(logging.DEBUG)355socketHandler = logging.handlers.SocketHandler('localhost',356                    logging.handlers.DEFAULT_TCP_LOGGING_PORT)357# Не нужно использовать форматтер, так как сокет-обработчик отправляет событие в виде неформатированного пикла.358# неформатированный pickle359rootLogger.addHandler(socketHandler)360361# Теперь можно выполнять запись в корневой логгер или любой другой. Сначала корневой...362logging.info('Jackdaws love my big sphinx of quartz.')363364# Теперь определите несколько других логгеров, которые могут представлять разные части приложения:365# приложение:366367logger1 = logging.getLogger('myapp.area1')368logger2 = logging.getLogger('myapp.area2')369370logger1.debug('Quick zephyrs blow, vexing daft Jim.')371logger1.info('How quickly daft jumping zebras vex.')372logger2.warning('Jail zesty vixen who grabbed pay from quack.')373logger2.error('The five boxing wizards jump quickly.')374```375376На принимающей стороне можно настроить приёмник с помощью модуля [`socketserver`](https://python-all.ru/3.6/library/socketserver.html#module-socketserver). Вот простой работающий пример:377378```python379import pickle380import logging381import logging.handlers382import socketserver383import struct384385class LogRecordStreamHandler(socketserver.StreamRequestHandler):386    """Обработчик для потокового запроса логирования.387388    Это по сути записывает запись, используя ту политику логирования, которая настроена локально.389    настроено локально.390    """391392    def handle(self):393        """394        Обрабатывает несколько запросов – каждый ожидается в формате: 4-байтовая длина, затем запись журнала в формате пикл.395        Записывает запись в соответствии с политикой, настроенной локально.396        согласно локально настроенной политике.397        """398        while True:399            chunk = self.connection.recv(4)400            if len(chunk) < 4:401                break402            slen = struct.unpack('>L', chunk)[0]403            chunk = self.connection.recv(slen)404            while len(chunk) < slen:405                chunk = chunk + self.connection.recv(slen - len(chunk))406            obj = self.unPickle(chunk)407            record = logging.makeLogRecord(obj)408            self.handleLogRecord(record)409410    def unPickle(self, data):411        return pickle.loads(data)412413    def handleLogRecord(self, record):414        # Если указано имя, используется именованный логгер, а не тот, что415        # подразумевается записью.416        if self.server.logname is not None:417            name = self.server.logname418        else:419            name = record.name420        logger = logging.getLogger(name)421        # Примечание: КАЖДАЯ запись попадает в журнал. Это связано с тем, что Logger.handle422        # обычно вызывается ПОСЛЕ фильтрации на уровне регистратора. Если требуется423        # выполнять фильтрацию, делайте это на стороне клиента, чтобы не тратить424        # циклы процессора и сетевую пропускную способность!425        logger.handle(record)426427class LogRecordSocketReceiver(socketserver.ThreadingTCPServer):428    """429    Простой приёмник журнала на основе TCP-сокетов, подходящий для тестирования.430    """431432    allow_reuse_address = True433434    def __init__(self, host='localhost',435                 port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,436                 handler=LogRecordStreamHandler):437        socketserver.ThreadingTCPServer.__init__(self, (host, port), handler)438        self.abort = 0439        self.timeout = 1440        self.logname = None441442    def serve_until_stopped(self):443        import select444        abort = 0445        while not abort:446            rd, wr, ex = select.select([self.socket.fileno()],447                                       [], [],448                                       self.timeout)449            if rd:450                self.handle_request()451            abort = self.abort452453def main():454    logging.basicConfig(455        format='%(relativeCreated)5d %(name)-15s %(levelname)-8s %(message)s')456    tcpserver = LogRecordSocketReceiver()457    print('About to start TCP server...')458    tcpserver.serve_until_stopped()459460if __name__ == '__main__':461    main()462```463464Сначала запустите сервер, затем клиент. На стороне клиента в консоль ничего не выводится; на стороне сервера вы должны увидеть что-то вроде:465466```text467About to start TCP server...468   59 root            INFO     Jackdaws love my big sphinx of quartz.469   59 myapp.area1     DEBUG    Quick zephyrs blow, vexing daft Jim.470   69 myapp.area1     INFO     How quickly daft jumping zebras vex.471   69 myapp.area2     WARNING  Jail zesty vixen who grabbed pay from quack.472   69 myapp.area2     ERROR    The five boxing wizards jump quickly.473```474475Обратите внимание, что в некоторых сценариях существуют проблемы безопасности с pickle. Если они вас затрагивают, вы можете использовать альтернативную схему сериализации, переопределив метод `makePickle()` и реализовав свою альтернативу там, а также адаптировав вышеприведённый скрипт для использования вашей альтернативной сериализации.476477## Добавление контекстной информации в вывод журнала478479Иногда требуется, чтобы вывод журнала содержал контекстную информацию в дополнение к параметрам, переданным в вызове логирования. Например, в сетевом приложении может быть желательно записывать в журнал информацию, специфичную для клиента (например, имя пользователя удалённого клиента или IP-адрес). Хотя для этого можно использовать параметр *extra*, не всегда удобно передавать информацию таким образом. Может возникнуть соблазн создавать экземпляры `Logger` для каждого соединения, но это плохая идея, поскольку такие экземпляры не собираются сборщиком мусора. Хотя на практике это не проблема, когда количество экземпляров `Logger` зависит от уровня детализации, используемого при логировании приложения, управление ими может стать сложным, если количество экземпляров `Logger` станет фактически неограниченным.480481### Использование LoggerAdapter для добавления контекстной информации482483Простой способ передавать контекстную информацию для вывода вместе с информацией о событиях логирования – использовать класс `LoggerAdapter`. Этот класс спроектирован так, чтобы выглядеть как `Logger`, что позволяет вызывать `debug()`, `info()`, `warning()`, `error()`, `exception()`, `critical()` и `log()`. Эти методы имеют те же сигнатуры, что и их аналоги в `Logger`, поэтому экземпляры обоих типов можно использовать взаимозаменяемо.484485При создании экземпляра `LoggerAdapter` вы передаёте ему экземпляр `Logger` и объект, подобный словарю, содержащий вашу контекстную информацию. Когда вы вызываете один из методов логирования на экземпляре `LoggerAdapter`, он делегирует вызов базовому экземпляру `Logger`, переданному в конструктор, и организует передачу контекстной информации в этом делегированном вызове. Вот фрагмент кода `LoggerAdapter`:486487```python488def debug(self, msg, *args, **kwargs):489    """490    Передаёт вызов отладки нижележащему регистратору после добавления491    контекстной информации из данного экземпляра адаптера.492    """493    msg, kwargs = self.process(msg, kwargs)494    self.logger.debug(msg, *args, **kwargs)495```496497Метод `process()` класса `LoggerAdapter` – это то место, где контекстная информация добавляется в вывод журнала. Ему передаются сообщение и именованные аргументы вызова логирования, а он возвращает (потенциально) изменённые версии для использования в вызове базового регистратора. В реализации по умолчанию этот метод оставляет сообщение без изменений, но вставляет ключ 'extra' в именованные аргументы, значением которого является объект, подобный словарю, переданный конструктору. Конечно, если вы передали именованный аргумент 'extra' в вызове адаптера, он будет молча перезаписан.498499Преимущество использования 'extra' в том, что значения из объекта, подобного словарю, сливаются в \_\_dict\_\_ экземпляра `LogRecord`, что позволяет использовать настроенные строки с экземплярами `Formatter`, которые знают о ключах этого объекта. Если вам нужен другой метод, например, добавить контекстную информацию в начало или конец строки сообщения, достаточно создать подкласс `LoggerAdapter` и переопределить `process()` для нужного поведения. Вот простой пример:500501```python502class CustomAdapter(logging.LoggerAdapter):503    """504    Данный пример адаптера ожидает, что переданный объект, подобный словарю, содержит505    ключ 'connid', значение которого в квадратных скобках добавляется к началу сообщения журнала.506    """507    def process(self, msg, kwargs):508        return '[%s] %s' % (self.extra['connid'], msg), kwargs509```510511который можно использовать так:512513```python514logger = logging.getLogger(__name__)515adapter = CustomAdapter(logger, {'connid': some_conn_id})516```517518Тогда все события, регистрируемые через адаптер, будут содержать значение `some_conn_id`, добавленное в начало сообщений журнала.519520#### Использование объектов, отличных от словарей, для передачи контекстной информации521522Необязательно передавать в `LoggerAdapter` именно словарь – можно передать экземпляр класса, реализующего `__getitem__` и `__iter__`, чтобы он выглядел как словарь для системы логирования. Это полезно, если нужно генерировать значения динамически (тогда как значения в словаре были бы постоянными).523524### Использование фильтров для добавления контекстной информации525526Вы также можете добавлять контекстную информацию в вывод журнала с помощью определённого пользователем `Filter`. Экземплярам `Filter` разрешено изменять `LogRecords`, переданный им, включая добавление дополнительных атрибутов, которые затем можно выводить с помощью подходящей форматной строки или, если необходимо, пользовательского `Formatter`.527528Например, в веб-приложении обрабатываемый запрос (или, по крайней мере, его интересные части) можно сохранить в потоковой локальной переменной ([`threading.local`](https://python-all.ru/3.6/library/threading.html#threading.local)), а затем из `Filter` получить к ней доступ, чтобы добавить, скажем, информацию из запроса – например, удалённый IP-адрес и имя пользователя – в `LogRecord`, используя имена атрибутов 'ip' и 'user', как в примере с `LoggerAdapter` выше. В этом случае можно использовать ту же форматную строку для получения вывода, аналогичного показанному выше. Вот пример скрипта:529530```python531import logging532from random import choice533534class ContextFilter(logging.Filter):535    """536    Это фильтр, который внедряет контекстную информацию в журнал.537538    Вместо использования реальной контекстной информации в данном примере используются случайные539    данные.540    """541542    USERS = ['jim', 'fred', 'sheila']543    IPS = ['123.231.231.123', '127.0.0.1', '192.168.0.1']544545    def filter(self, record):546547        record.ip = choice(ContextFilter.IPS)548        record.user = choice(ContextFilter.USERS)549        return True550551if __name__ == '__main__':552    levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)553    logging.basicConfig(level=logging.DEBUG,554                        format='%(asctime)-15s %(name)-5s %(levelname)-8s IP: %(ip)-15s User: %(user)-8s %(message)s')555    a1 = logging.getLogger('a.b.c')556    a2 = logging.getLogger('d.e.f')557558    f = ContextFilter()559    a1.addFilter(f)560    a2.addFilter(f)561    a1.debug('A debug message')562    a1.info('An info message with %s', 'some parameters')563    for x in range(10):564        lvl = choice(levels)565        lvlname = logging.getLevelName(lvl)566        a2.log(lvl, 'A message at %s level with %d %s', lvlname, 2, 'parameters')567```568569который при запуске выдаёт примерно следующее:570571```text5722010-09-06 22:38:15,292 a.b.c DEBUG    IP: 123.231.231.123 User: fred     A debug message5732010-09-06 22:38:15,300 a.b.c INFO     IP: 192.168.0.1     User: sheila   An info message with some parameters5742010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1       User: sheila   A message at CRITICAL level with 2 parameters5752010-09-06 22:38:15,300 d.e.f ERROR    IP: 127.0.0.1       User: jim      A message at ERROR level with 2 parameters5762010-09-06 22:38:15,300 d.e.f DEBUG    IP: 127.0.0.1       User: sheila   A message at DEBUG level with 2 parameters5772010-09-06 22:38:15,300 d.e.f ERROR    IP: 123.231.231.123 User: fred     A message at ERROR level with 2 parameters5782010-09-06 22:38:15,300 d.e.f CRITICAL IP: 192.168.0.1     User: jim      A message at CRITICAL level with 2 parameters5792010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1       User: sheila   A message at CRITICAL level with 2 parameters5802010-09-06 22:38:15,300 d.e.f DEBUG    IP: 192.168.0.1     User: jim      A message at DEBUG level with 2 parameters5812010-09-06 22:38:15,301 d.e.f ERROR    IP: 127.0.0.1       User: sheila   A message at ERROR level with 2 parameters5822010-09-06 22:38:15,301 d.e.f DEBUG    IP: 123.231.231.123 User: fred     A message at DEBUG level with 2 parameters5832010-09-06 22:38:15,301 d.e.f INFO     IP: 123.231.231.123 User: fred     A message at INFO level with 2 parameters584```585586## Ведение журнала в один файл из нескольких процессов587588Хотя модуль logging является потокобезопасным и запись в один файл из нескольких потоков в одном процессе *поддерживается*, запись в один файл из *нескольких процессов* *не* поддерживается, поскольку в Python нет стандартного способа сериализовать доступ к одному файлу из нескольких процессов. Если нужно вести журнал в один файл из нескольких процессов, один из способов – сделать так, чтобы все процессы записывали данные в `SocketHandler`, а отдельный процесс реализовывал сокет-сервер, который читает из сокета и записывает в файл. (Если хотите, можно выделить один поток в одном из существующих процессов для выполнения этой функции.) [В этом разделе](https://python-all.ru/3.6/howto/logging-cookbook.html#network-logging) подробно описывается данный подход и приводится рабочий приёмник сокета, который можно использовать как отправную точку для адаптации в своих приложениях.589590Если используется недавняя версия Python, включающая модуль [`multiprocessing`](https://python-all.ru/3.6/library/multiprocessing.html#module-multiprocessing), можно написать собственный обработчик, который использует класс [`Lock`](https://python-all.ru/3.6/library/multiprocessing.html#multiprocessing.Lock) из этого модуля для сериализации доступа к файлу из процессов. Существующие `FileHandler` и подклассы в настоящее время не используют [`multiprocessing`](https://python-all.ru/3.6/library/multiprocessing.html#module-multiprocessing), хотя в будущем могут. Обратите внимание, что на данный момент модуль [`multiprocessing`](https://python-all.ru/3.6/library/multiprocessing.html#module-multiprocessing) не предоставляет работающую функциональность блокировок на всех платформах (см. [https://bugs.python.org/issue3770](https://python-all.ru/3.6/howto/logging-cookbook.html)).591592В качестве альтернативы можно использовать `Queue` и [`QueueHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.QueueHandler) для отправки всех событий журналирования одному из процессов в вашем многопроцессном приложении. В следующем примере сценария показано, как это сделать; в примере отдельный процесс-слушатель ожидает события, отправленные другими процессами, и регистрирует их в соответствии со своей собственной конфигурацией журналирования. Хотя пример демонстрирует лишь один из способов (например, вместо отдельного процесса-слушателя можно использовать поток-слушатель – реализация будет аналогичной), он позволяет задать полностью разные конфигурации журналирования для слушателя и остальных процессов в вашем приложении и может быть использован как основа для кода, отвечающего вашим конкретным требованиям:593594```python595# Вам понадобятся эти импорты в вашем коде.596import logging597import logging.handlers598import multiprocessing599600# Следующие две строки импорта только для этой демонстрации.601from random import choice, random602import time603604#605# Поскольку нужно задать настройки логирования для слушателя и рабочих процессов, функции606# слушателя и рабочего процесса принимают параметр configurer – вызываемый объект для607# настройки логирования этого процесса. Эти функции также получают очередь, которую608# используют для взаимодействия.609#610# На практике слушателя можно настроить как угодно, но заметьте: в этом простом611# примере слушатель не применяет логику уровней или фильтров к полученным записям.612# На практике эту логику, вероятно, стоит вынести в рабочие процессы, чтобы не613# пересылать между процессами события, которые всё равно будут отфильтрованы.614#615# Размер файлов при ротации намеренно сделан небольшим, чтобы результат был хорошо виден.616def listener_configurer():617    root = logging.getLogger()618    h = logging.handlers.RotatingFileHandler('mptest.log', 'a', 300, 10)619    f = logging.Formatter('%(asctime)s %(processName)-10s %(name)s %(levelname)-8s %(message)s')620    h.setFormatter(f)621    root.addHandler(h)622623# Это главный цикл процесса-слушателя: ждём события логирования624# (LogRecords) в очереди и обрабатываем их; завершаем работу, когда получаем None вместо625# LogRecord.626def listener_process(queue, configurer):627    configurer()628    while True:629        try:630            record = queue.get()631            if record is None:  # Отправляем это как сигнал завершения, чтобы слушатель остановился.632                break633            logger = logging.getLogger(record.name)634            logger.handle(record)  # Никакой логики уровней и фильтров – просто делаем дело!635        except Exception:636            import sys, traceback637            print('Whoops! Problem:', file=sys.stderr)638            traceback.print_exc(file=sys.stderr)639640# Массивы для случайного выбора в этой демонстрации.641642LEVELS = [logging.DEBUG, logging.INFO, logging.WARNING,643          logging.ERROR, logging.CRITICAL]644645LOGGERS = ['a.b.c', 'd.e.f']646647MESSAGES = [648    'Random message #1',649    'Random message #2',650    'Random message #3',651]652653# Настройка рабочего процесса выполняется в начале его работы.654# Обратите внимание: в Windows нельзя полагаться на семантику fork, поэтому каждый процесс655# будет выполнять код настройки логирования при запуске.656def worker_configurer(queue):657    h = logging.handlers.QueueHandler(queue)  # Нужен только один обработчик.658    root = logging.getLogger()659    root.addHandler(h)660    # Отправляем все сообщения для демонстрации; никакой другой логики уровней или фильтров.661    root.setLevel(logging.DEBUG)662663# Это главный цикл рабочего процесса, который просто логирует десять событий с664# случайные задержки перед завершением.665# Сообщения print нужны лишь для того, чтобы было видно, что программа работает.666def worker_process(queue, configurer):667    configurer(queue)668    name = multiprocessing.current_process().name669    print('Worker started: %s' % name)670    for i in range(10):671        time.sleep(random())672        logger = logging.getLogger(choice(LOGGERS))673        level = choice(LEVELS)674        message = choice(MESSAGES)675        logger.log(level, message)676    print('Worker finished: %s' % name)677678# Здесь организуется демонстрация. Создать очередь, создать и запустить679# слушатель, создать десять рабочих процессов и запустить их, дождаться их завершения,680# затем отправить None в очередь, чтобы сообщить слушателю о завершении.681def main():682    queue = multiprocessing.Queue(-1)683    listener = multiprocessing.Process(target=listener_process,684                                       args=(queue, listener_configurer))685    listener.start()686    workers = []687    for i in range(10):688        worker = multiprocessing.Process(target=worker_process,689                                         args=(queue, worker_configurer))690        workers.append(worker)691        worker.start()692    for w in workers:693        w.join()694    queue.put_nowait(None)695    listener.join()696697if __name__ == '__main__':698    main()699```700701Вариант приведённого выше сценария оставляет ведение журнала в главном процессе, в отдельном потоке:702703```python704import logging705import logging.config706import logging.handlers707from multiprocessing import Process, Queue708import random709import threading710import time711712def logger_thread(q):713    while True:714        record = q.get()715        if record is None:716            break717        logger = logging.getLogger(record.name)718        logger.handle(record)719720def worker_process(q):721    qh = logging.handlers.QueueHandler(q)722    root = logging.getLogger()723    root.setLevel(logging.DEBUG)724    root.addHandler(qh)725    levels = [logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,726              logging.CRITICAL]727    loggers = ['foo', 'foo.bar', 'foo.bar.baz',728               'spam', 'spam.ham', 'spam.ham.eggs']729    for i in range(100):730        lvl = random.choice(levels)731        logger = logging.getLogger(random.choice(loggers))732        logger.log(lvl, 'Message no. %d', i)733734if __name__ == '__main__':735    q = Queue()736    d = {737        'version': 1,738        'formatters': {739            'detailed': {740                'class': 'logging.Formatter',741                'format': '%(asctime)s %(name)-15s %(levelname)-8s %(processName)-10s %(message)s'742            }743        },744        'handlers': {745            'console': {746                'class': 'logging.StreamHandler',747                'level': 'INFO',748            },749            'file': {750                'class': 'logging.FileHandler',751                'filename': 'mplog.log',752                'mode': 'w',753                'formatter': 'detailed',754            },755            'foofile': {756                'class': 'logging.FileHandler',757                'filename': 'mplog-foo.log',758                'mode': 'w',759                'formatter': 'detailed',760            },761            'errors': {762                'class': 'logging.FileHandler',763                'filename': 'mplog-errors.log',764                'mode': 'w',765                'level': 'ERROR',766                'formatter': 'detailed',767            },768        },769        'loggers': {770            'foo': {771                'handlers': ['foofile']772            }773        },774        'root': {775            'level': 'DEBUG',776            'handlers': ['console', 'file', 'errors']777        },778    }779    workers = []780    for i in range(5):781        wp = Process(target=worker_process, name='worker %d' % (i + 1), args=(q,))782        workers.append(wp)783        wp.start()784    logging.config.dictConfig(d)785    lp = threading.Thread(target=logger_thread, args=(q,))786    lp.start()787    # На этом этапе главный процесс может заняться своей полезной работой788    # Когда он с этим закончит, он может дождаться завершения рабочих процессов...789    for wp in workers:790        wp.join()791    # А теперь указать потоку журналирования завершиться792    q.put(None)793    lp.join()794```795796Этот вариант показывает, как можно, например, применить конфигурацию для определённых регистраторов – например, регистратор `foo` имеет специальный обработчик, который сохраняет все события подсистемы `foo` в файл `mplog-foo.log`. Это будет использовано механизмом журналирования в главном процессе (даже если события журналирования генерируются в рабочих процессах) для направления сообщений к соответствующим местам назначения.797798## Использование ротации файлов799800Иногда требуется позволить файлу журнала расти до определённого размера, затем открыть новый файл и вести запись в него. Может потребоваться сохранять определённое количество таких файлов, и когда будет создано заданное число файлов, выполнять ротацию, чтобы и количество, и размер файлов оставались в заданных границах. Для такого сценария использования пакет logging предоставляет `RotatingFileHandler`:801802```python803import glob804import logging805import logging.handlers806807LOG_FILENAME = 'logging_rotatingfile_example.out'808809# Настроить конкретный регистратор с нужным уровнем вывода810my_logger = logging.getLogger('MyLogger')811my_logger.setLevel(logging.DEBUG)812813# Добавить обработчик сообщений журнала в регистратор814handler = logging.handlers.RotatingFileHandler(815              LOG_FILENAME, maxBytes=20, backupCount=5)816817my_logger.addHandler(handler)818819# Записать несколько сообщений820for i in range(20):821    my_logger.debug('i = %d' % i)822823# Посмотреть, какие файлы созданы824logfiles = glob.glob('%s*' % LOG_FILENAME)825826for filename in logfiles:827    print(filename)828```829830В результате должно получиться 6 отдельных файлов, каждый из которых содержит часть истории журнала приложения:831832```text833logging_rotatingfile_example.out834logging_rotatingfile_example.out.1835logging_rotatingfile_example.out.2836logging_rotatingfile_example.out.3837logging_rotatingfile_example.out.4838logging_rotatingfile_example.out.5839```840841Самый свежий файл всегда называется `logging_rotatingfile_example.out`, и каждый раз при достижении ограничения по размеру он переименовывается с суффиксом `.1`. Каждый из существующих резервных файлов переименовывается с увеличением суффикса (`.1` становится `.2` и т.д.), а файл `.6` удаляется.842843Разумеется, в этом примере размер файла журнала установлен слишком маленьким для наглядности. В реальности нужно установить *maxBytes* в подходящее значение.844845## Использование альтернативных стилей форматирования846847Когда журналирование было добавлено в стандартную библиотеку Python, единственным способом форматирования сообщений с переменным содержимым было использование %-форматирования. С тех пор в Python появились два новых подхода к форматированию: [`string.Template`](https://python-all.ru/3.6/library/string.html#string.Template) (добавлен в Python 2.4) и [`str.format()`](https://python-all.ru/3.6/library/stdtypes.html#str.format) (добавлен в Python 2.6).848849Начиная с версии 3.2, модуль logging предоставляет улучшенную поддержку этих двух дополнительных стилей форматирования. Класс `Formatter` был расширен: добавлен дополнительный необязательный именованный параметр `style`. По умолчанию он равен `'%'`, но возможны также значения `'{'` и `'$'`, соответствующие двум другим стилям форматирования. Обратная совместимость сохраняется по умолчанию (как и следовало ожидать), но при явном указании параметра style появляется возможность задавать строки формата, работающие с [`str.format()`](https://python-all.ru/3.6/library/stdtypes.html#str.format) или [`string.Template`](https://python-all.ru/3.6/library/string.html#string.Template). Вот пример сеанса работы в консоли, демонстрирующий возможности:850851```pycon852>>> import logging853>>> root = logging.getLogger()854>>> root.setLevel(logging.DEBUG)855>>> handler = logging.StreamHandler()856>>> bf = logging.Formatter('{asctime} {name} {levelname:8s} {message}',857...                        style='{')858>>> handler.setFormatter(bf)859>>> root.addHandler(handler)860>>> logger = logging.getLogger('foo.bar')861>>> logger.debug('This is a DEBUG message')8622010-10-28 15:11:55,341 foo.bar DEBUG    This is a DEBUG message863>>> logger.critical('This is a CRITICAL message')8642010-10-28 15:12:11,526 foo.bar CRITICAL This is a CRITICAL message865>>> df = logging.Formatter('$asctime $name ${levelname} $message',866...                        style='$')867>>> handler.setFormatter(df)868>>> logger.debug('This is a DEBUG message')8692010-10-28 15:13:06,924 foo.bar DEBUG This is a DEBUG message870>>> logger.critical('This is a CRITICAL message')8712010-10-28 15:13:11,494 foo.bar CRITICAL This is a CRITICAL message872>>>873```874875Обратите внимание: форматирование сообщений журнала для конечного вывода в файлы совершенно не зависит от того, как конструируется отдельное сообщение. Оно по-прежнему может использовать %-форматирование, как показано ниже:876877```python878>>> logger.error('This is an%s %s %s', 'other,', 'ERROR,', 'message')8792010-10-28 15:19:29,833 foo.bar ERROR This is another, ERROR, message880>>>881```882883Вызовы логирования (`logger.debug()`, `logger.info()` и т.д.) принимают только позиционные параметры для самого сообщения, а ключевые параметры используются только для определения опций обработки вызова (например, ключевой параметр `exc_info` для указания, что нужно логировать трассировку, или ключевой параметр `extra` для добавления дополнительной контекстной информации). Поэтому напрямую использовать синтаксис [`str.format()`](https://python-all.ru/3.6/library/stdtypes.html#str.format) или [`string.Template`](https://python-all.ru/3.6/library/string.html#string.Template) в вызовах логирования нельзя, так как внутри пакет logging использует %-форматирование для объединения строки формата и переменных аргументов. Изменить это без потери обратной совместимости невозможно, поскольку все существующие вызовы логирования в коде используют строки с %-форматом.884885Однако существует способ использовать {}- и $-форматирование для построения отдельных сообщений журнала. Напомним, что в качестве строки формата сообщения можно использовать произвольный объект, и пакет logging вызовет у этого объекта `str()` для получения фактической строки формата. Рассмотрим следующие два класса:886887```python888class BraceMessage:889    def __init__(self, fmt, *args, **kwargs):890        self.fmt = fmt891        self.args = args892        self.kwargs = kwargs893894    def __str__(self):895        return self.fmt.format(*self.args, **self.kwargs)896897class DollarMessage:898    def __init__(self, fmt, **kwargs):899        self.fmt = fmt900        self.kwargs = kwargs901902    def __str__(self):903        from string import Template904        return Template(self.fmt).substitute(**self.kwargs)905```906907Любой из этих классов можно использовать вместо строки формата, чтобы разрешить применение {}- или $-форматирования для построения фактической части «message», которая появляется в отформатированном выводе журнала вместо «%(message)s», «{message}» или «$message». Это немного громоздко – использовать имена классов каждый раз при журналировании, но вполне приемлемо, если применить псевдоним, например \_\_ (двойное подчеркивание – не путать с \_, одинарным подчеркиванием, используемым как синоним/псевдоним для [`gettext.gettext()`](https://python-all.ru/3.6/library/gettext.html#gettext.gettext) или его аналогов).908909Вышеуказанные классы не входят в состав Python, но их легко скопировать и вставить в свой код. Их можно использовать следующим образом (предполагая, что они объявлены в модуле с именем `wherever`):910911```pycon912>>> from wherever import BraceMessage as __913>>> print(__('Message with {0} {name}', 2, name='placeholders'))914Message with 2 placeholders915>>> class Point: pass916...917>>> p = Point()918>>> p.x = 0.5919>>> p.y = 0.5920>>> print(__('Message with coordinates: ({point.x:.2f}, {point.y:.2f})',921...       point=p))922Message with coordinates: (0.50, 0.50)923>>> from wherever import DollarMessage as __924>>> print(__('Message with $num $what', num=2, what='placeholders'))925Message with 2 placeholders926>>>927```928929Хотя в приведённых выше примерах используется `print()` для демонстрации работы форматирования, в реальности для ведения журнала с помощью этого подхода следует использовать `logger.debug()` или аналогичную функцию.930931Следует отметить, что этот подход не даёт значительного снижения производительности с этим подходом: фактическое форматирование происходит не тогда, когда вы делаете вызов регистрации, а когда (и если) регистрируемое сообщение действительно должно быть выведено в журнал с помощью обработчика. Поэтому единственное, что может сбить с толку, – это то, что скобки ставятся вокруг строки формата и аргументов, а не только вокруг строки формата. Это потому, что нотация \_\_ – это просто синтаксический сахар для вызова конструктора одного из классов XXXMessage.932933Если хотите, можно использовать `LoggerAdapter` для достижения аналогичного эффекта, как в следующем примере:934935```python936import logging937938class Message(object):939    def __init__(self, fmt, args):940        self.fmt = fmt941        self.args = args942943    def __str__(self):944        return self.fmt.format(*self.args)945946class StyleAdapter(logging.LoggerAdapter):947    def __init__(self, logger, extra=None):948        super(StyleAdapter, self).__init__(logger, extra or {})949950    def log(self, level, msg, *args, **kwargs):951        if self.isEnabledFor(level):952            msg, kwargs = self.process(msg, kwargs)953            self.logger._log(level, Message(msg, args), (), **kwargs)954955logger = StyleAdapter(logging.getLogger(__name__))956957def main():958    logger.debug('Hello, {}', 'world!')959960if __name__ == '__main__':961    logging.basicConfig(level=logging.DEBUG)962    main()963```964965При запуске с Python 3.2 или новее указанный выше скрипт должен записать сообщение `Hello, world!`.966967## Настройка `LogRecord`968969Каждое событие журналирования представлено экземпляром [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord). Когда событие регистрируется и не отфильтровывается по уровню регистратора, создаётся [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord), заполняется информацией о событии и затем передаётся обработчикам для этого регистратора (и его предков, вплоть до регистратора, в котором дальнейшее распространение по иерархии отключено). До Python 3.2 было только два места, где выполнялось это создание:970971- [`Logger.makeRecord()`](https://python-all.ru/3.6/library/logging.html#logging.Logger.makeRecord), который вызывается в обычном процессе регистрации события. Он напрямую вызывал [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord) для создания экземпляра.972- [`makeLogRecord()`](https://python-all.ru/3.6/library/logging.html#logging.makeLogRecord), которая вызывается со словарем, содержащим атрибуты для добавления в LogRecord. Обычно она вызывается, когда подходящий словарь был получен по сети (например, в виде pickle через [`SocketHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.SocketHandler) или в формате JSON через [`HTTPHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.HTTPHandler)).973974Обычно это означало, что если требуется выполнить какие-либо специальные действия с [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord), приходилось делать одно из следующего.975976- Создать собственный подкласс [`Logger`](https://python-all.ru/3.6/library/logging.html#logging.Logger), который переопределяет [`Logger.makeRecord()`](https://python-all.ru/3.6/library/logging.html#logging.Logger.makeRecord), и установить его с помощью [`setLoggerClass()`](https://python-all.ru/3.6/library/logging.html#logging.setLoggerClass) до того, как будут созданы какие-либо логгеры, которые вас интересуют.977- Добавить [`Filter`](https://python-all.ru/3.6/library/logging.html#logging.Filter) к логгеру или обработчику, который выполняет необходимые специальные манипуляции при вызове его метода [`filter()`](https://python-all.ru/3.6/library/logging.html#logging.Filter.filter).978979Первый подход был бы несколько громоздким в сценарии, где (скажем) несколько разных библиотек хотели бы делать разные вещи. Каждая попыталась бы установить свой собственный подкласс [`Logger`](https://python-all.ru/3.6/library/logging.html#logging.Logger), и та, которая сделала это последней, победила бы.980981Второй подход достаточно хорошо работает во многих случаях, но не позволяет, например, использовать специализированный подкласс [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord). Разработчики библиотек могут установить подходящий фильтр на своих логгерах, но им приходилось бы помнить об этом каждый раз, когда они добавляют новый логгер (что они делают, просто добавляя новые пакеты или модули и выполняя982983```python984logger = logging.getLogger(__name__)985```986987на уровне модуля). Вероятно, это одна из тех вещей, о которых нужно помнить. Разработчики также могли бы добавить фильтр к [`NullHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.NullHandler), прикрепленному к их корневому логгеру, но он не будет вызываться, если разработчик приложения прикрепит обработчик к логгеру библиотеки нижнего уровня – так что вывод от этого обработчика не будет отражать намерений разработчика библиотеки.988989В Python 3.2 и новее создание [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord) осуществляется через фабрику, которую можно указать. Фабрика – это просто вызываемый объект, который можно установить с помощью [`setLogRecordFactory()`](https://python-all.ru/3.6/library/logging.html#logging.setLogRecordFactory) и запросить с помощью [`getLogRecordFactory()`](https://python-all.ru/3.6/library/logging.html#logging.getLogRecordFactory). Фабрика вызывается с той же сигнатурой, что и конструктор [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord), поскольку [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord) является значением по умолчанию для фабрики.990991Этот подход позволяет пользовательской фабрике контролировать все аспекты создания LogRecord. Например, можно вернуть подкласс или просто добавить несколько дополнительных атрибутов к записи после ее создания, используя шаблон, подобный следующему:992993```python994old_factory = logging.getLogRecordFactory()995996def record_factory(*args, **kwargs):997    record = old_factory(*args, **kwargs)998    record.custom_attribute = 0xdecafbad999    return record10001001logging.setLogRecordFactory(record_factory)1002```10031004Этот шаблон позволяет разным библиотекам объединять фабрики в цепочку, и пока они не перезаписывают атрибуты друг друга или случайно не перезаписывают стандартные атрибуты, никаких сюрпризов быть не должно. Однако следует иметь в виду, что каждое звено цепочки добавляет накладные расходы во время выполнения ко всем операциям логирования, и эту технику следует использовать только тогда, когда использование [`Filter`](https://python-all.ru/3.6/library/logging.html#logging.Filter) не дает желаемого результата.10051006## Создание подкласса QueueHandler – пример с ZeroMQ10071008Можно использовать подкласс `QueueHandler` для отправки сообщений в очереди других типов, например, в сокет ZeroMQ «publish». В приведенном ниже примере сокет создается отдельно и передается обработчику (в качестве его «очереди»):10091010```python1011import zmq   # с использованием pyzmq, привязки Python к ZeroMQ1012import json  # для переносимой сериализации записей10131014ctx = zmq.Context()1015sock = zmq.Socket(ctx, zmq.PUB)  # или zmq.PUSH, или другое подходящее значение1016sock.bind('tcp://*:5556')        # или где угодно10171018class ZeroMQSocketHandler(QueueHandler):1019    def enqueue(self, record):1020        self.queue.send_json(record.__dict__)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        super().__init__(socket)10341035    def enqueue(self, record):1036        self.queue.send_json(record.__dict__)10371038    def close(self):1039        self.queue.close()1040```10411042## Создание подкласса QueueListener – пример с ZeroMQ10431044Можно также создать подкласс `QueueListener` для получения сообщений из очередей других типов, например, из сокета ZeroMQ «subscribe». Вот пример:10451046```python1047class ZeroMQSocketListener(QueueListener):1048    def __init__(self, uri, *handlers, **kwargs):1049        self.ctx = kwargs.get('ctx') or zmq.Context()1050        socket = zmq.Socket(self.ctx, zmq.SUB)1051        socket.setsockopt_string(zmq.SUBSCRIBE, '')  # подписаться на всё1052        socket.connect(uri)1053        super().__init__(socket, *handlers, **kwargs)10541055    def dequeue(self):1056        msg = self.queue.recv_json()1057        return logging.makeLogRecord(msg)1058```10591060> **См. также**1061>1062> **Модуль [`logging`](https://python-all.ru/3.6/library/logging.html#module-logging)**1063>1064> Справочник API для модуля logging.1065>1066> **Модуль [`logging.config`](https://python-all.ru/3.6/library/logging.config.html#module-logging.config)**1067>1068> API конфигурации для модуля logging.1069>1070> **Модуль [`logging.handlers`](https://python-all.ru/3.6/library/logging.handlers.html#module-logging.handlers)**1071>1072> Полезные обработчики, входящие в состав модуля logging.1073>1074> [Базовое руководство по логированию](https://python-all.ru/3.6/howto/logging.html#logging-basic-tutorial)1075>1076> [Более продвинутое руководство по логированию](https://python-all.ru/3.6/howto/logging.html#logging-advanced-tutorial)10771078## Пример конфигурации на основе словаря10791080Ниже приведен пример словаря конфигурации логирования – он взят из [документации проекта Django](https://python-all.ru/3.6/howto/logging-cookbook.html). Этот словарь передается в [`dictConfig()`](https://python-all.ru/3.6/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.6/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.6/howto/logging-cookbook.html) требует, чтобы сообщение Unicode отправлялось демону syslog в виде набора байтов, имеющего следующую структуру: необязательный чисто ASCII-компонент, за которым следует метка порядка байтов UTF-8 (BOM), а затем Unicode, закодированный в UTF-8. (См. [**соответствующий раздел спецификации**](https://python-all.ru/3.6/howto/logging-cookbook.html).)13811382В Python 3.1 в [`SysLogHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.handlers.SysLogHandler) был добавлен код для вставки BOM в сообщение, но, к сожалению, он был реализован некорректно: BOM появлялся в начале сообщения и, следовательно, не допускал наличия чисто ASCII-компонента перед ним.13831384Поскольку такое поведение ошибочно, некорректный код вставки BOM удаляется из Python 3.2.4 и более поздних версий. Однако он не заменяется, и если требуется создавать сообщения, соответствующие [**RFC 5424**](https://python-all.ru/3.6/howto/logging-cookbook.html), которые включают BOM, необязательную чисто ASCII-последовательность перед ним и произвольный Unicode после него, закодированный в UTF-8, то необходимо сделать следующее:138513861. Необходимо присоединить экземпляр [`Formatter`](https://python-all.ru/3.6/library/logging.html#logging.Formatter) к экземпляру [`SysLogHandler`](https://python-all.ru/3.6/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**](https://python-all.ru/3.6/howto/logging-cookbook.html). Если этого не делать, модуль logging может не жаловаться, но сообщения не будут соответствовать 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```text1423message 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```text1472message 1 >>> {"snowman": "\u2603", "set_value": [1, 2, 3]}1473```14741475Обратите внимание, что порядок элементов может отличаться в зависимости от используемой версии Python.14761477## Настройка обработчиков с помощью [`dictConfig()`](https://python-all.ru/3.6/library/logging.config.html#logging.config.dictConfig)14781479Иногда требуется настроить обработчики логирования особым образом, и при использовании [`dictConfig()`](https://python-all.ru/3.6/library/logging.config.html#logging.config.dictConfig) это можно сделать без создания подклассов. Например, может потребоваться установить владельца файла журнала. В POSIX это легко сделать с помощью [`shutil.chown()`](https://python-all.ru/3.6/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.6/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.6/library/shutil.html#shutil.chown). Этот подход должен работать с любой версией Python, поддерживающей [`dictConfig()`](https://python-all.ru/3.6/library/logging.config.html#logging.config.dictConfig) – а именно Python 2.7, 3.2 или новее. В версиях до 3.3 потребовалось бы реализовать фактическую смену владельца, например, с помощью [`os.chown()`](https://python-all.ru/3.6/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.6/library/logging.config.html#logging.config.dictConfig) из спецификации `ext://`.15961597Этот пример, надеюсь, также показывает, как можно реализовать другие типы изменений файлов – например, установку определённых битов разрешений POSIX – аналогичным образом, с помощью [`os.chmod()`](https://python-all.ru/3.6/library/os.html#os.chmod).15981599Разумеется, этот подход можно распространить и на другие типы обработчиков, помимо [`FileHandler`](https://python-all.ru/3.6/library/logging.handlers.html#logging.FileHandler) – например, на один из вращающихся файловых обработчиков или на совершенно другой тип обработчика.16001601## Использование определённых стилей форматирования во всём приложении16021603В Python 3.2 у [`Formatter`](https://python-all.ru/3.6/library/logging.html#logging.Formatter) появился именованный параметр `style`, который, хотя по умолчанию для обратной совместимости он равен `%`, позволяет указать `{` или `$` для поддержки подходов к форматированию, поддерживаемых [`str.format()`](https://python-all.ru/3.6/library/stdtypes.html#str.format) и [`string.Template`](https://python-all.ru/3.6/library/string.html#string.Template). Обратите внимание, что это управляет форматированием сообщений журнала для окончательного вывода в журнал и совершенно не зависит от того, как конструируется отдельное сообщение журнала.16041605Вызовы логирования ([`debug()`](https://python-all.ru/3.6/library/logging.html#logging.Logger.debug), [`info()`](https://python-all.ru/3.6/library/logging.html#logging.Logger.info) и т.д.) принимают только позиционные параметры для самого сообщения логирования, а именованные параметры используются только для определения параметров обработки вызова (например, именованный параметр `exc_info` для указания, что информация о трассировке должна быть записана в журнал, или именованный параметр `extra` для указания дополнительной контекстной информации, добавляемой в журнал). Поэтому вы не можете напрямую выполнять вызовы логирования с использованием синтаксиса [`str.format()`](https://python-all.ru/3.6/library/stdtypes.html#str.format) или [`string.Template`](https://python-all.ru/3.6/library/string.html#string.Template), потому что внутренне пакет logging использует %-форматирование для объединения строки формата и переменных аргументов. Это нельзя изменить, сохраняя обратную совместимость, поскольку все существующие вызовы логирования в коде используют %-форматирование строк.16061607Высказывались предложения связывать стили форматирования с конкретными регистраторами, но этот подход также сталкивается с проблемами обратной совместимости, поскольку любой существующий код может использовать данное имя регистратора и %-форматирование.16081609Чтобы логирование работало совместимо между любыми сторонними библиотеками и вашим кодом, решения о форматировании необходимо принимать на уровне отдельного вызова логирования. Это открывает несколько способов, которыми можно реализовать альтернативные стили форматирования.16101611### Использование фабрик LogRecord16121613В Python 3.2, вместе с упомянутыми выше изменениями [`Formatter`](https://python-all.ru/3.6/library/logging.html#logging.Formatter), пакет logging получил возможность позволять пользователям устанавливать свои собственные подклассы [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord) с помощью функции [`setLogRecordFactory()`](https://python-all.ru/3.6/library/logging.html#logging.setLogRecordFactory). Вы можете использовать это, чтобы установить свой собственный подкласс [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord), который делает правильные вещи, переопределяя метод [`getMessage()`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord.getMessage). В реализации базового класса этого метода происходит форматирование `msg % args`, и именно здесь можно подставить альтернативное форматирование; однако следует быть осторожным, чтобы поддерживать все стили форматирования и разрешить %-форматирование по умолчанию для обеспечения совместимости с другим кодом. Также следует позаботиться о вызове `str(self.msg)`, как это делает базовая реализация.16141615Обратитесь к справочной документации по [`setLogRecordFactory()`](https://python-all.ru/3.6/library/logging.html#logging.setLogRecordFactory) и [`LogRecord`](https://python-all.ru/3.6/library/logging.html#logging.LogRecord) для получения дополнительной информации.16161617### Использование пользовательских объектов сообщений16181619Есть еще один, возможно, более простой способ использовать {}- и $-форматирование для построения отдельных сообщений лога. Вы, возможно, помните (из раздела [Использование произвольных объектов в качестве сообщений](https://python-all.ru/3.6/howto/logging.html#arbitrary-object-messages)), что при логировании можно использовать произвольный объект в качестве строки формата сообщения, и пакет logging вызовет [`str()`](https://python-all.ru/3.6/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.6/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.6/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.6/library/logging.config.html#logging.config.dictConfig)16701671*Можно* настраивать фильтры с помощью [`dictConfig()`](https://python-all.ru/3.6/library/logging.config.html#logging.config.dictConfig), хотя с первого взгляда может быть неочевидно, как это сделать (поэтому и дан этот рецепт). Поскольку [`Filter`](https://python-all.ru/3.6/library/logging.html#logging.Filter) – единственный класс фильтра, включенный в стандартную библиотеку, и вряд ли он удовлетворит многие требования (он присутствует только как базовый класс), вам, как правило, потребуется определить свой собственный подкласс [`Filter`](https://python-all.ru/3.6/library/logging.html#logging.Filter) с переопределенным методом [`filter()`](https://python-all.ru/3.6/library/logging.html#logging.Filter.filter). Для этого укажите ключ `()` в словаре конфигурации для фильтра, указав вызываемый объект, который будет использоваться для создания фильтра (класс – наиболее очевидный вариант, но вы можете предоставить любой вызываемый объект, возвращающий экземпляр [`Filter`](https://python-all.ru/3.6/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```text1720changed: hello1721```17221723что показывает, что фильтр работает в соответствии с настройками.17241725Несколько дополнительных моментов, на которые стоит обратить внимание:17261727- Если вы не можете сослаться на вызываемый объект напрямую в конфигурации (например, если он находится в другом модуле, и вы не можете импортировать его напрямую в том месте, где находится словарь конфигурации), вы можете использовать форму `ext://...`, как описано в разделе [Доступ к внешним объектам](https://python-all.ru/3.6/library/logging.config.html#logging-config-dict-externalobj). Например, в приведенном выше примере можно было использовать текст `'ext://__main__.MyFilter'` вместо `MyFilter`.1728- Помимо фильтров, этот метод также можно использовать для настройки пользовательских обработчиков и форматтеров. Смотрите раздел [Пользовательские объекты](https://python-all.ru/3.6/library/logging.config.html#logging-config-dict-userdef) для получения дополнительной информации о том, как logging поддерживает использование пользовательских объектов в своей конфигурации, а также см. другой рецепт из этой книги рецептов [Настройка обработчиков с помощью dictConfig()](https://python-all.ru/3.6/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```text177528/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.6/library/traceback.html#module-traceback) может быть полезен для более специализированных нужд.17801781## Озвучивание сообщений лога17821783Могут быть ситуации, когда желательно выводить сообщения лога в звуковом, а не визуальном формате. Это легко сделать, если в вашей системе доступна функция преобразования текста в речь (TTS), даже если у нее нет привязки к Python. Большинство TTS-систем имеют программу командной строки, которую можно запустить, и ее можно вызвать из обработчика с помощью [`subprocess`](https://python-all.ru/3.6/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.6/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.6/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```text1898Calling 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.6/library/logging.html#logging.Formatter). Если требуется сделать это через конфигурацию, можно воспользоваться API [`dictConfig()`](https://python-all.ru/3.6/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```text19922015-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