logging-cookbook.md
1> **Источник:** https://python-all.ru/3.3/howto/logging-cookbook.html2>3> «Документация Python на русском» – неофициальный перевод официальной документации Python: версии от 2.6 до 3.16, полнотекстовый поиск, английский оригинал рядом с переводом. Эта Markdown-версия страницы предназначена для работы с LLM: вставьте её в ChatGPT, Claude или Cursor.45---67# Сборник рецептов по логированию89| Автор: | Vinay Sajip \<vinay\_sajip at red-dove dot com\> |10| --- | --- |1112На этой странице представлен ряд рецептов, связанных с логированием, которые оказались полезными на практике.1314## Использование логирования в нескольких модулях1516Многократные вызовы `logging.getLogger('someLogger')` возвращают ссылку на один и тот же объект логгера. Это верно не только в пределах одного модуля, но и между модулями, пока они находятся в одном процессе интерпретатора Python. Это верно для ссылок на один и тот же объект; кроме того, код приложения может определить и настроить родительский логгер в одном модуле и создать (но не настраивать) дочерний логгер в отдельном модуле, и все вызовы логгера к дочернему будут передаваться родительскому. Вот главный модуль:1718```python19import logging20import auxiliary_module2122# создать логгер с именем 'spam_application'23logger = logging.getLogger('spam_application')24logger.setLevel(logging.DEBUG)25# создать файловый обработчик, записывающий даже отладочные сообщения26fh = logging.FileHandler('spam.log')27fh.setLevel(logging.DEBUG)28# создать консольный обработчик с более высоким уровнем логирования29ch = logging.StreamHandler()30ch.setLevel(logging.ERROR)31# создать форматтер и добавить его к обработчикам32formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')33fh.setFormatter(formatter)34ch.setFormatter(formatter)35# добавить обработчики к логгеру36logger.addHandler(fh)37logger.addHandler(ch)3839logger.info('creating an instance of auxiliary_module.Auxiliary')40a = auxiliary_module.Auxiliary()41logger.info('created an instance of auxiliary_module.Auxiliary')42logger.info('calling auxiliary_module.Auxiliary.do_something')43a.do_something()44logger.info('finished auxiliary_module.Auxiliary.do_something')45logger.info('calling auxiliary_module.some_function()')46auxiliary_module.some_function()47logger.info('done with auxiliary_module.some_function()')48```4950А вот вспомогательный модуль:5152```python53import logging5455# создать логгер56module_logger = logging.getLogger('spam_application.auxiliary')5758class Auxiliary:59 def __init__(self):60 self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')61 self.logger.info('creating an instance of Auxiliary')62 def do_something(self):63 self.logger.info('doing something')64 a = 1 + 165 self.logger.info('done doing something')6667def some_function():68 module_logger.info('received a call to "some_function"')69```7071Вывод выглядит так:7273```python742005-03-23 23:47:11,663 - spam_application - INFO -75 creating an instance of auxiliary_module.Auxiliary762005-03-23 23:47:11,665 - spam_application.auxiliary.Auxiliary - INFO -77 creating an instance of Auxiliary782005-03-23 23:47:11,665 - spam_application - INFO -79 created an instance of auxiliary_module.Auxiliary802005-03-23 23:47:11,668 - spam_application - INFO -81 calling auxiliary_module.Auxiliary.do_something822005-03-23 23:47:11,668 - spam_application.auxiliary.Auxiliary - INFO -83 doing something842005-03-23 23:47:11,669 - spam_application.auxiliary.Auxiliary - INFO -85 done doing something862005-03-23 23:47:11,670 - spam_application - INFO -87 finished auxiliary_module.Auxiliary.do_something882005-03-23 23:47:11,671 - spam_application - INFO -89 calling auxiliary_module.some_function()902005-03-23 23:47:11,672 - spam_application.auxiliary - INFO -91 received a call to 'some_function'922005-03-23 23:47:11,673 - spam_application - INFO -93 done with auxiliary_module.some_function()94```9596## Несколько обработчиков и форматировщиков9798Логгеры – это обычные объекты Python. Метод [`addHandler()`](https://python-all.ru/3.3/library/logging.html#logging.Logger.addHandler) не имеет минимального или максимального ограничения на количество добавляемых обработчиков. Иногда приложению бывает полезно записывать все сообщения всех уровней в текстовый файл, одновременно выводя ошибки и выше на консоль. Чтобы настроить это, просто сконфигурируйте соответствующие обработчики. Вызовы логирования в коде приложения останутся без изменений. Вот небольшая модификация предыдущего простого примера конфигурации на основе модуля:99100```python101import logging102103logger = logging.getLogger('simple_example')104logger.setLevel(logging.DEBUG)105# создать файловый обработчик, записывающий даже отладочные сообщения106fh = logging.FileHandler('spam.log')107fh.setLevel(logging.DEBUG)108# создать консольный обработчик с более высоким уровнем логирования109ch = logging.StreamHandler()110ch.setLevel(logging.ERROR)111# создать форматтер и добавить его к обработчикам112formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')113ch.setFormatter(formatter)114fh.setFormatter(formatter)115# добавить обработчики в логгер116logger.addHandler(ch)117logger.addHandler(fh)118119# код 'приложения'120logger.debug('debug message')121logger.info('info message')122logger.warn('warn message')123logger.error('error message')124logger.critical('critical message')125```126127Обратите внимание, что «прикладной» код не заботится о нескольких обработчиках. Единственное, что изменилось – добавление и настройка нового обработчика с именем *fh*.128129Возможность создавать новые обработчики с фильтрами более высокого или низкого уровня серьезности может быть очень полезна при написании и тестировании приложения. Вместо использования множества операторов `print` для отладки используйте `logger.debug`: в отличие от операторов print, которые вам придется удалить или закомментировать позже, операторы logger.debug могут оставаться в исходном коде и оставаться неактивными до тех пор, пока они снова не понадобятся. В этом случае единственное, что нужно сделать, – изменить уровень серьезности логгера и/или обработчика на debug.130131## Журналирование в несколько мест назначения132133Допустим, вы хотите вести журнал в консоль и файл с разными форматами сообщений и в разных ситуациях. Предположим, вы хотите записывать сообщения уровня DEBUG и выше в файл, а сообщения уровня INFO и выше – в консоль. Также предположим, что файл должен содержать временные метки, а консольные сообщения – нет. Вот как это можно сделать:134135```python136import logging137138# настроить логирование в файл – подробнее см. предыдущий раздел139logging.basicConfig(level=logging.DEBUG,140 format='%(asctime)s %(name)-12s %(levelname)-8s %(message)s',141 datefmt='%m-%d %H:%M',142 filename='/temp/myapp.log',143 filemode='w')144# Определяет обработчик, который записывает сообщения уровня INFO и выше в sys.stderr.145console = logging.StreamHandler()146console.setLevel(logging.INFO)147# Задает формат, упрощенный для вывода в консоль.148formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')149# Указывает обработчику использовать этот формат.150console.setFormatter(formatter)151# Добавляет обработчик в корневой логгер.152logging.getLogger('').addHandler(console)153154# Теперь можно выполнять запись в корневой логгер или любой другой. Сначала корневой...155logging.info('Jackdaws love my big sphinx of quartz.')156157# Теперь определите несколько других логгеров, которые могут представлять разные части приложения:158# приложение:159160logger1 = logging.getLogger('myapp.area1')161logger2 = logging.getLogger('myapp.area2')162163logger1.debug('Quick zephyrs blow, vexing daft Jim.')164logger1.info('How quickly daft jumping zebras vex.')165logger2.warning('Jail zesty vixen who grabbed pay from quack.')166logger2.error('The five boxing wizards jump quickly.')167```168169При запуске на консоли вы увидите170171```python172root : INFO Jackdaws love my big sphinx of quartz.173myapp.area1 : INFO How quickly daft jumping zebras vex.174myapp.area2 : WARNING Jail zesty vixen who grabbed pay from quack.175myapp.area2 : ERROR The five boxing wizards jump quickly.176```177178а в файле увидите примерно такое179180```python18110-22 22:19 root INFO Jackdaws love my big sphinx of quartz.18210-22 22:19 myapp.area1 DEBUG Quick zephyrs blow, vexing daft Jim.18310-22 22:19 myapp.area1 INFO How quickly daft jumping zebras vex.18410-22 22:19 myapp.area2 WARNING Jail zesty vixen who grabbed pay from quack.18510-22 22:19 myapp.area2 ERROR The five boxing wizards jump quickly.186```187188Как видите, сообщение DEBUG отображается только в файле. Остальные сообщения отправляются в оба места назначения.189190В этом примере используются консольный и файловый обработчики, но вы можете использовать любое количество и любое сочетание обработчиков по своему выбору.191192## Пример сервера конфигурации193194Вот пример модуля, использующего сервер конфигурации журналирования:195196```python197import logging198import logging.config199import time200import os201202# Прочитать начальный конфигурационный файл.203logging.config.fileConfig('logging.conf')204205# Создать и запустить слушатель на порту 9999.206t = logging.config.listen(9999)207t.start()208209logger = logging.getLogger('simpleExample')210211try:212 # Прокрутить вызовы логирования, чтобы увидеть разницу.213 # Создавать новые конфигурации до нажатия Ctrl+C.214 while True:215 logger.debug('debug message')216 logger.info('info message')217 logger.warn('warn message')218 logger.error('error message')219 logger.critical('critical message')220 time.sleep(5)221except KeyboardInterrupt:222 # очистка223 logging.config.stopListening()224 t.join()225```226227А вот скрипт, который принимает имя файла и отправляет этот файл на сервер, предварив его двоично-закодированной длиной, в качестве новой конфигурации журналирования:228229```python230#!/usr/bin/env python231import socket, sys, struct232233with open(sys.argv[1], 'rb') as f:234 data_to_send = f.read()235236HOST = 'localhost'237PORT = 9999238s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)239print('connecting...')240s.connect((HOST, PORT))241print('sending config...')242s.send(struct.pack('>L', len(data_to_send)))243s.send(data_to_send)244s.close()245print('complete')246```247248## Работа с блокирующими обработчиками249250Иногда требуется, чтобы обработчики логирования выполняли свою работу, не блокируя поток, из которого ведется логирование. Это часто встречается в веб-приложениях, хотя, конечно, бывает и в других сценариях.251252Часто виновником медленной работы является [`SMTPHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.SMTPHandler): отправка писем может занимать много времени по ряду причин, не зависящих от разработчика (например, плохая производительность почтовой или сетевой инфраструктуры). Но почти любой сетевой обработчик может блокироваться: даже операция [`SocketHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.SocketHandler) может выполнять DNS-запрос внутри, который слишком медленный (и этот запрос может находиться глубоко в коде библиотеки сокетов, ниже уровня Python, и вне вашего контроля).253254Одно из решений – использовать двухчастный подход. На первом этапе прикрепите только [`QueueHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.QueueHandler) к тем логгерам, к которым обращаются из критичных по производительности потоков. Они просто пишут в свою очередь, которая может быть настроена на достаточно большую емкость или инициализирована без верхнего ограничения размера. Запись в очередь обычно принимается быстро, хотя вам, вероятно, потребуется перехватывать исключение [`queue.Full`](https://python-all.ru/3.3/library/queue.html#queue.Full) в качестве меры предосторожности в коде. Если вы разработчик библиотеки, и в вашем коде есть критичные по производительности потоки, обязательно задокументируйте это (вместе с рекомендацией прикреплять только `QueueHandlers` к вашим логгерам) на благо других разработчиков, которые будут использовать ваш код.255256Вторая часть решения – [`QueueListener`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.QueueListener), который был разработан как аналог [`QueueHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.QueueHandler). [`QueueListener`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.QueueListener) очень прост: ему передаются очередь и несколько обработчиков, и он запускает внутренний поток, который слушает свою очередь на предмет LogRecords, отправленных от `QueueHandlers` (или любого другого источника `LogRecords`, если на то пошло). `LogRecords` извлекаются из очереди и передаются обработчикам для обработки.257258Преимущество отдельного класса [`QueueListener`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.QueueListener) в том, что можно использовать один и тот же экземпляр для обслуживания нескольких `QueueHandlers`. Это более эффективно по ресурсам, чем, скажем, создание многопоточных версий существующих классов обработчиков, которые потребляют по одному потоку на обработчик без особой пользы.259260Ниже приведён пример использования этих двух классов (импорты опущены):261262```python263que = queue.Queue(-1) # Без ограничения размера.264queue_handler = QueueHandler(que)265handler = logging.StreamHandler()266listener = QueueListener(que, handler)267root = logging.getLogger()268root.addHandler(queue_handler)269formatter = logging.Formatter('%(threadName)s: %(message)s')270handler.setFormatter(formatter)271listener.start()272# Вывод лога будет отображать поток, создавший событие (главный поток), а не внутренний поток,273# отслеживающий внутреннюю очередь.274# Именно это и должно происходить.275# то, что должно произойти.276root.warning('Look out!')277listener.stop()278```279280который при запуске выведет:281282```python283MainThread: Look out!284```285286## Отправка и получение событий логирования по сети287288Допустим, вы хотите отправлять события логирования по сети и обрабатывать их на принимающей стороне. Простой способ сделать это – прикрепить экземпляр [`SocketHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.SocketHandler) к корневому логгеру на отправляющей стороне:289290```python291import logging, logging.handlers292293rootLogger = logging.getLogger('')294rootLogger.setLevel(logging.DEBUG)295socketHandler = logging.handlers.SocketHandler('localhost',296 logging.handlers.DEFAULT_TCP_LOGGING_PORT)297# Не нужно использовать форматтер, так как сокет-обработчик отправляет событие в виде неформатированного пикла.298# неформатированный pickle299rootLogger.addHandler(socketHandler)300301# Теперь можно выполнять запись в корневой логгер или любой другой. Сначала корневой...302logging.info('Jackdaws love my big sphinx of quartz.')303304# Теперь определите несколько других логгеров, которые могут представлять разные части приложения:305# приложение:306307logger1 = logging.getLogger('myapp.area1')308logger2 = logging.getLogger('myapp.area2')309310logger1.debug('Quick zephyrs blow, vexing daft Jim.')311logger1.info('How quickly daft jumping zebras vex.')312logger2.warning('Jail zesty vixen who grabbed pay from quack.')313logger2.error('The five boxing wizards jump quickly.')314```315316На принимающей стороне можно настроить приемник с помощью модуля [`socketserver`](https://python-all.ru/3.3/library/socketserver.html#module-socketserver). Вот базовый рабочий пример:317318```python319import pickle320import logging321import logging.handlers322import socketserver323import struct324325class LogRecordStreamHandler(socketserver.StreamRequestHandler):326 """Обработчик для потокового запроса логирования.327328 Это по сути записывает запись, используя ту политику логирования, которая настроена локально.329 настроено локально.330 """331332 def handle(self):333 """334 Обрабатывает несколько запросов – каждый ожидается в формате: 4-байтовая длина, затем запись журнала в формате пикл.335 Записывает запись в соответствии с политикой, настроенной локально.336 согласно локально настроенной политике.337 """338 while True:339 chunk = self.connection.recv(4)340 if len(chunk) < 4:341 break342 slen = struct.unpack('>L', chunk)[0]343 chunk = self.connection.recv(slen)344 while len(chunk) < slen:345 chunk = chunk + self.connection.recv(slen - len(chunk))346 obj = self.unPickle(chunk)347 record = logging.makeLogRecord(obj)348 self.handleLogRecord(record)349350 def unPickle(self, data):351 return pickle.loads(data)352353 def handleLogRecord(self, record):354 # Если указано имя, используется именованный логгер, а не тот, что355 # подразумевается записью.356 if self.server.logname is not None:357 name = self.server.logname358 else:359 name = record.name360 logger = logging.getLogger(name)361 # Примечание: КАЖДАЯ запись попадает в журнал. Это связано с тем, что Logger.handle362 # обычно вызывается ПОСЛЕ фильтрации на уровне регистратора. Если требуется363 # выполнять фильтрацию, делайте это на стороне клиента, чтобы не тратить364 # циклы процессора и сетевую пропускную способность!365 logger.handle(record)366367class LogRecordSocketReceiver(socketserver.ThreadingTCPServer):368 """369 Простой приёмник журнала на основе TCP-сокетов, подходящий для тестирования.370 """371372 allow_reuse_address = 1373374 def __init__(self, host='localhost',375 port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,376 handler=LogRecordStreamHandler):377 socketserver.ThreadingTCPServer.__init__(self, (host, port), handler)378 self.abort = 0379 self.timeout = 1380 self.logname = None381382 def serve_until_stopped(self):383 import select384 abort = 0385 while not abort:386 rd, wr, ex = select.select([self.socket.fileno()],387 [], [],388 self.timeout)389 if rd:390 self.handle_request()391 abort = self.abort392393def main():394 logging.basicConfig(395 format='%(relativeCreated)5d %(name)-15s %(levelname)-8s %(message)s')396 tcpserver = LogRecordSocketReceiver()397 print('About to start TCP server...')398 tcpserver.serve_until_stopped()399400if __name__ == '__main__':401 main()402```403404Сначала запустите сервер, затем клиент. На стороне клиента в консоль ничего не выводится; на стороне сервера вы должны увидеть что-то вроде:405406```python407About to start TCP server...408 59 root INFO Jackdaws love my big sphinx of quartz.409 59 myapp.area1 DEBUG Quick zephyrs blow, vexing daft Jim.410 69 myapp.area1 INFO How quickly daft jumping zebras vex.411 69 myapp.area2 WARNING Jail zesty vixen who grabbed pay from quack.412 69 myapp.area2 ERROR The five boxing wizards jump quickly.413```414415Обратите внимание, что в некоторых сценариях существуют проблемы безопасности с pickle. Если они вас затрагивают, вы можете использовать альтернативную схему сериализации, переопределив метод `makePickle()` и реализовав свою альтернативу там, а также адаптировав приведенный выше скрипт для использования вашей альтернативной сериализации.416417## Добавление контекстной информации в вывод журнала418419Иногда требуется, чтобы вывод логирования содержал контекстную информацию в дополнение к параметрам, переданным в вызов логирования. Например, в сетевом приложении может быть желательно регистрировать специфичную для клиента информацию в журнале (например, имя пользователя удаленного клиента или IP-адрес). Хотя вы можете использовать параметр *extra* для этого, не всегда удобно передавать информацию таким образом. Хотя может возникнуть соблазн создавать экземпляры `Logger` для каждого соединения, это не очень хорошая идея, потому что эти экземпляры не собираются сборщиком мусора. Хотя на практике это не проблема, когда количество экземпляров `Logger` зависит от уровня детализации, которую вы хотите использовать при логировании приложения, это может быть трудно управляемым, если количество экземпляров `Logger` становится фактически неограниченным.420421### Использование LoggerAdapter для добавления контекстной информации422423Простой способ передавать контекстную информацию для вывода вместе с информацией о событии логирования – использовать класс `LoggerAdapter`. Этот класс разработан так, чтобы выглядеть как `Logger`, так что вы можете вызывать `debug()`, `info()`, `warning()`, `error()`, `exception()`, `critical()` и `log()`. Эти методы имеют те же сигнатуры, что и их аналоги в `Logger`, поэтому вы можете использовать экземпляры обоих типов взаимозаменяемо.424425Когда вы создаете экземпляр `LoggerAdapter`, вы передаете ему экземпляр `Logger` и объект, подобный словарю, который содержит вашу контекстную информацию. Когда вы вызываете один из методов логирования на экземпляре `LoggerAdapter`, он делегирует вызов базовому экземпляру `Logger`, переданному его конструктору, и обеспечивает передачу контекстной информации в делегированном вызове. Вот фрагмент из кода `LoggerAdapter`:426427```python428def debug(self, msg, *args, **kwargs):429 """430 Передаёт вызов отладки нижележащему регистратору после добавления431 контекстной информации из данного экземпляра адаптера.432 """433 msg, kwargs = self.process(msg, kwargs)434 self.logger.debug(msg, *args, **kwargs)435```436437Метод `process()` класса `LoggerAdapter` – это то место, где контекстная информация добавляется к выводу логирования. Ему передаются сообщение и именованные аргументы вызова логирования, и он возвращает (потенциально) измененные версии этих данных для использования в вызове базового логгера. Реализация по умолчанию этого метода оставляет сообщение без изменений, но вставляет ключ 'extra' в именованные аргументы, значением которого является объект, подобный словарю, переданный конструктору. Конечно, если вы передали аргумент 'extra' в вызове адаптера, он будет молча перезаписан.438439Преимущество использования 'extra' в том, что значения из dict-подобного объекта сливаются в \_\_dict\_\_ экземпляра `LogRecord`, что позволяет использовать настраиваемые строки с экземплярами `Formatter`, которые знают о ключах dict-подобного объекта. Если вам нужен другой метод, например, если вы хотите добавить контекстную информацию в начало или конец строки сообщения, вам просто нужно создать подкласс `LoggerAdapter` и переопределить `process()` для выполнения нужных действий. Вот простой пример:440441```python442class CustomAdapter(logging.LoggerAdapter):443 """444 Данный пример адаптера ожидает, что переданный объект, подобный словарю, содержит445 ключ 'connid', значение которого в квадратных скобках добавляется к началу сообщения журнала.446 """447 def process(self, msg, kwargs):448 return '[%s] %s' % (self.extra['connid'], msg), kwargs449```450451который можно использовать так:452453```python454logger = logging.getLogger(__name__)455adapter = CustomAdapter(logger, {'connid': some_conn_id})456```457458Тогда любые события, которые вы регистрируете через адаптер, будут иметь значение `some_conn_id`, добавленное в начало сообщений журнала.459460#### Использование объектов, отличных от словарей, для передачи контекстной информации461462Вам не нужно передавать фактический словарь в `LoggerAdapter` – вы можете передать экземпляр класса, который реализует `__getitem__` и `__iter__`, так чтобы он выглядел как словарь для логирования. Это может быть полезно, если вы хотите генерировать значения динамически (тогда как значения в словаре были бы постоянными).463464### Использование фильтров для добавления контекстной информации465466Вы также можете добавить контекстную информацию в вывод журнала с помощью пользовательского `Filter`. Экземпляры `Filter` могут изменять переданные им `LogRecords`, включая добавление дополнительных атрибутов, которые затем можно выводить с помощью подходящей строки формата или, при необходимости, пользовательского `Formatter`.467468Например, в веб-приложении обрабатываемый запрос (или, по крайней мере, его интересные части) может храниться в переменной threadlocal ([`threading.local`](https://python-all.ru/3.3/library/threading.html#threading.local)), а затем извлекаться из `Filter` для добавления, скажем, информации из запроса – например, удаленного IP-адреса и имени пользователя – в `LogRecord`, используя имена атрибутов 'ip' и 'user', как в примере с `LoggerAdapter` выше. В этом случае можно использовать ту же строку формата для получения аналогичного вывода, показанного выше. Вот пример скрипта:469470```python471import logging472from random import choice473474class ContextFilter(logging.Filter):475 """476 Это фильтр, который внедряет контекстную информацию в журнал.477478 Вместо использования реальной контекстной информации в данном примере используются случайные479 данные.480 """481482 USERS = ['jim', 'fred', 'sheila']483 IPS = ['123.231.231.123', '127.0.0.1', '192.168.0.1']484485 def filter(self, record):486487 record.ip = choice(ContextFilter.IPS)488 record.user = choice(ContextFilter.USERS)489 return True490491if __name__ == '__main__':492 levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)493 logging.basicConfig(level=logging.DEBUG,494 format='%(asctime)-15s %(name)-5s %(levelname)-8s IP: %(ip)-15s User: %(user)-8s %(message)s')495 a1 = logging.getLogger('a.b.c')496 a2 = logging.getLogger('d.e.f')497498 f = ContextFilter()499 a1.addFilter(f)500 a2.addFilter(f)501 a1.debug('A debug message')502 a1.info('An info message with %s', 'some parameters')503 for x in range(10):504 lvl = choice(levels)505 lvlname = logging.getLevelName(lvl)506 a2.log(lvl, 'A message at %s level with %d %s', lvlname, 2, 'parameters')507```508509который при запуске выдаёт примерно следующее:510511```python5122010-09-06 22:38:15,292 a.b.c DEBUG IP: 123.231.231.123 User: fred A debug message5132010-09-06 22:38:15,300 a.b.c INFO IP: 192.168.0.1 User: sheila An info message with some parameters5142010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1 User: sheila A message at CRITICAL level with 2 parameters5152010-09-06 22:38:15,300 d.e.f ERROR IP: 127.0.0.1 User: jim A message at ERROR level with 2 parameters5162010-09-06 22:38:15,300 d.e.f DEBUG IP: 127.0.0.1 User: sheila A message at DEBUG level with 2 parameters5172010-09-06 22:38:15,300 d.e.f ERROR IP: 123.231.231.123 User: fred A message at ERROR level with 2 parameters5182010-09-06 22:38:15,300 d.e.f CRITICAL IP: 192.168.0.1 User: jim A message at CRITICAL level with 2 parameters5192010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1 User: sheila A message at CRITICAL level with 2 parameters5202010-09-06 22:38:15,300 d.e.f DEBUG IP: 192.168.0.1 User: jim A message at DEBUG level with 2 parameters5212010-09-06 22:38:15,301 d.e.f ERROR IP: 127.0.0.1 User: sheila A message at ERROR level with 2 parameters5222010-09-06 22:38:15,301 d.e.f DEBUG IP: 123.231.231.123 User: fred A message at DEBUG level with 2 parameters5232010-09-06 22:38:15,301 d.e.f INFO IP: 123.231.231.123 User: fred A message at INFO level with 2 parameters524```525526## Ведение журнала в один файл из нескольких процессов527528Хотя логирование потокобезопасно и запись в один файл из нескольких потоков в одном процессе *поддерживается*, запись в один файл из *нескольких процессов* *не* поддерживается, потому что в Python нет стандартного способа сериализовать доступ к одному файлу из нескольких процессов. Если вам нужно вести журнал в один файл из нескольких процессов, один из способов – заставить все процессы записывать в `SocketHandler`, а отдельный процесс будет реализовывать сокет-сервер, который читает из сокета и пишет в файл. (Если хотите, можно выделить один поток в одном из существующих процессов для выполнения этой функции.) [*В этом разделе*](https://python-all.ru/3.3/howto/logging-cookbook.html#network-logging) этот подход документирован более подробно и включает рабочий приемник сокетов, который можно использовать как отправную точку для адаптации в ваших собственных приложениях.529530Если вы используете недавнюю версию Python, которая включает модуль [`multiprocessing`](https://python-all.ru/3.3/library/multiprocessing.html#module-multiprocessing), вы можете написать собственный обработчик, использующий класс [`Lock`](https://python-all.ru/3.3/library/multiprocessing.html#multiprocessing.Lock) из этого модуля для сериализации доступа к файлу из ваших процессов. Существующие `FileHandler` и подклассы не используют [`multiprocessing`](https://python-all.ru/3.3/library/multiprocessing.html#module-multiprocessing) в настоящее время, хотя, возможно, будут в будущем. Обратите внимание, что в настоящее время модуль [`multiprocessing`](https://python-all.ru/3.3/library/multiprocessing.html#module-multiprocessing) не предоставляет работоспособную функциональность блокировки на всех платформах (см. [http://bugs.python.org/issue3770](https://python-all.ru/3.3/howto/logging-cookbook.html)).531532В качестве альтернативы вы можете использовать `Queue` и [`QueueHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.QueueHandler) для отправки всех событий логирования одному из процессов вашего многопроцессного приложения. Следующий пример скрипта демонстрирует, как это можно сделать; в примере отдельный процесс-слушатель прослушивает события, отправленные другими процессами, и регистрирует их в соответствии со своей собственной конфигурацией логирования. Хотя пример демонстрирует только один способ (например, вы можете захотеть использовать поток-слушатель вместо отдельного процесса-слушателя – реализация была бы аналогичной), он допускает полностью различные конфигурации логирования для слушателя и других процессов вашего приложения и может использоваться как основа для кода, удовлетворяющего вашим конкретным требованиям:533534```python535# Вам понадобятся эти импорты в вашем коде.536import logging537import logging.handlers538import multiprocessing539540# Следующие две строки импорта только для этой демонстрации.541from random import choice, random542import time543544#545# Поскольку нужно задать настройки логирования для слушателя и рабочих процессов, функции546# слушателя и рабочего процесса принимают параметр configurer – вызываемый объект для547# настройки логирования этого процесса. Эти функции также получают очередь, которую548# используют для взаимодействия.549#550# На практике слушателя можно настроить как угодно, но заметьте: в этом простом551# примере слушатель не применяет логику уровней или фильтров к полученным записям.552# На практике эту логику, вероятно, стоит вынести в рабочие процессы, чтобы не553# пересылать между процессами события, которые всё равно будут отфильтрованы.554#555# Размер файлов при ротации намеренно сделан небольшим, чтобы результат был хорошо виден.556def listener_configurer():557 root = logging.getLogger()558 h = logging.handlers.RotatingFileHandler('mptest.log', 'a', 300, 10)559 f = logging.Formatter('%(asctime)s %(processName)-10s %(name)s %(levelname)-8s %(message)s')560 h.setFormatter(f)561 root.addHandler(h)562563# Это главный цикл процесса-слушателя: ждём события логирования564# (LogRecords) в очереди и обрабатываем их; завершаем работу, когда получаем None вместо565# LogRecord.566def listener_process(queue, configurer):567 configurer()568 while True:569 try:570 record = queue.get()571 if record is None: # Отправляем это как сигнал завершения, чтобы слушатель остановился.572 break573 logger = logging.getLogger(record.name)574 logger.handle(record) # Никакой логики уровней и фильтров – просто делаем дело!575 except (KeyboardInterrupt, SystemExit):576 raise577 except:578 import sys, traceback579 print('Whoops! Problem:', file=sys.stderr)580 traceback.print_exc(file=sys.stderr)581582# Массивы для случайного выбора в этой демонстрации.583584LEVELS = [logging.DEBUG, logging.INFO, logging.WARNING,585 logging.ERROR, logging.CRITICAL]586587LOGGERS = ['a.b.c', 'd.e.f']588589MESSAGES = [590 'Random message #1',591 'Random message #2',592 'Random message #3',593]594595# Настройка рабочего процесса выполняется в начале его работы.596# Обратите внимание: в Windows нельзя полагаться на семантику fork, поэтому каждый процесс597# будет выполнять код настройки логирования при запуске.598def worker_configurer(queue):599 h = logging.handlers.QueueHandler(queue) # Нужен только один обработчик.600 root = logging.getLogger()601 root.addHandler(h)602 root.setLevel(logging.DEBUG) # Отправляем все сообщения для демонстрации; никакой другой логики уровней или фильтров.603604# Это главный цикл рабочего процесса, который просто логирует десять событий с605# случайные задержки перед завершением.606# Сообщения print нужны лишь для того, чтобы было видно, что программа работает.607def worker_process(queue, configurer):608 configurer(queue)609 name = multiprocessing.current_process().name610 print('Worker started: %s' % name)611 for i in range(10):612 time.sleep(random())613 logger = logging.getLogger(choice(LOGGERS))614 level = choice(LEVELS)615 message = choice(MESSAGES)616 logger.log(level, message)617 print('Worker finished: %s' % name)618619# Здесь организуется демонстрация. Создать очередь, создать и запустить620# слушатель, создать десять рабочих процессов и запустить их, дождаться их завершения,621# затем отправить None в очередь, чтобы сообщить слушателю о завершении.622def main():623 queue = multiprocessing.Queue(-1)624 listener = multiprocessing.Process(target=listener_process,625 args=(queue, listener_configurer))626 listener.start()627 workers = []628 for i in range(10):629 worker = multiprocessing.Process(target=worker_process,630 args=(queue, worker_configurer))631 workers.append(worker)632 worker.start()633 for w in workers:634 w.join()635 queue.put_nowait(None)636 listener.join()637638if __name__ == '__main__':639 main()640```641642Вариант приведённого выше сценария оставляет ведение журнала в главном процессе, в отдельном потоке:643644```python645import logging646import logging.config647import logging.handlers648from multiprocessing import Process, Queue649import random650import threading651import time652653def logger_thread(q):654 while True:655 record = q.get()656 if record is None:657 break658 logger = logging.getLogger(record.name)659 logger.handle(record)660661def worker_process(q):662 qh = logging.handlers.QueueHandler(q)663 root = logging.getLogger()664 root.setLevel(logging.DEBUG)665 root.addHandler(qh)666 levels = [logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,667 logging.CRITICAL]668 loggers = ['foo', 'foo.bar', 'foo.bar.baz',669 'spam', 'spam.ham', 'spam.ham.eggs']670 for i in range(100):671 lvl = random.choice(levels)672 logger = logging.getLogger(random.choice(loggers))673 logger.log(lvl, 'Message no. %d', i)674675if __name__ == '__main__':676 q = Queue()677 d = {678 'version': 1,679 'formatters': {680 'detailed': {681 'class': 'logging.Formatter',682 'format': '%(asctime)s %(name)-15s %(levelname)-8s %(processName)-10s %(message)s'683 }684 },685 'handlers': {686 'console': {687 'class': 'logging.StreamHandler',688 'level': 'INFO',689 },690 'file': {691 'class': 'logging.FileHandler',692 'filename': 'mplog.log',693 'mode': 'w',694 'formatter': 'detailed',695 },696 'foofile': {697 'class': 'logging.FileHandler',698 'filename': 'mplog-foo.log',699 'mode': 'w',700 'formatter': 'detailed',701 },702 'errors': {703 'class': 'logging.FileHandler',704 'filename': 'mplog-errors.log',705 'mode': 'w',706 'level': 'ERROR',707 'formatter': 'detailed',708 },709 },710 'loggers': {711 'foo': {712 'handlers': ['foofile']713 }714 },715 'root': {716 'level': 'DEBUG',717 'handlers': ['console', 'file', 'errors']718 },719 }720 workers = []721 for i in range(5):722 wp = Process(target=worker_process, name='worker %d' % (i + 1), args=(q,))723 workers.append(wp)724 wp.start()725 logging.config.dictConfig(d)726 lp = threading.Thread(target=logger_thread, args=(q,))727 lp.start()728 # На этом этапе главный процесс может заняться своей полезной работой729 # Когда он с этим закончит, он может дождаться завершения рабочих процессов...730 for wp in workers:731 wp.join()732 # А теперь указать потоку журналирования завершиться733 q.put(None)734 lp.join()735```736737Этот вариант показывает, как можно, например, применить конфигурацию для конкретных логгеров – например, логгер `foo` имеет специальный обработчик, который сохраняет все события подсистемы `foo` в файл `mplog-foo.log`. Это будет использоваться механизмом логирования в главном процессе (даже если события логирования генерируются в рабочих процессах) для направления сообщений в соответствующие места назначения.738739## Использование ротации файлов740741Иногда требуется, чтобы файл журнала увеличивался до определенного размера, затем открывался новый файл и запись велась в него. Возможно, вы захотите сохранять определенное количество таких файлов, и когда будет создано это количество файлов, выполнять ротацию файлов, чтобы количество файлов и их размер оставались ограниченными. Для этого сценария использования в пакете logging предусмотрен `RotatingFileHandler`:742743```python744import glob745import logging746import logging.handlers747748LOG_FILENAME = 'logging_rotatingfile_example.out'749750# Настроить конкретный регистратор с нужным уровнем вывода751my_logger = logging.getLogger('MyLogger')752my_logger.setLevel(logging.DEBUG)753754# Добавить обработчик сообщений журнала в регистратор755handler = logging.handlers.RotatingFileHandler(756 LOG_FILENAME, maxBytes=20, backupCount=5)757758my_logger.addHandler(handler)759760# Записать несколько сообщений761for i in range(20):762 my_logger.debug('i = %d' % i)763764# Посмотреть, какие файлы созданы765logfiles = glob.glob('%s*' % LOG_FILENAME)766767for filename in logfiles:768 print(filename)769```770771В результате должно получиться 6 отдельных файлов, каждый из которых содержит часть истории журнала приложения:772773```python774logging_rotatingfile_example.out775logging_rotatingfile_example.out.1776logging_rotatingfile_example.out.2777logging_rotatingfile_example.out.3778logging_rotatingfile_example.out.4779logging_rotatingfile_example.out.5780```781782Самый текущий файл всегда называется `logging_rotatingfile_example.out`, и каждый раз, когда он достигает предельного размера, он переименовывается с суффиксом `.1`. Каждый из существующих резервных файлов переименовывается для увеличения суффикса (`.1` становится `.2` и т.д.), а файл `.6` удаляется.783784Разумеется, в этом примере размер файла журнала установлен слишком маленьким для наглядности. В реальности нужно установить *maxBytes* в подходящее значение.785786## Использование альтернативных стилей форматирования787788Когда логирование было добавлено в стандартную библиотеку Python, единственным способом форматирования сообщений с переменным содержимым был метод %-форматирования. С тех пор в Python появились два новых подхода к форматированию: [`string.Template`](https://python-all.ru/3.3/library/string.html#string.Template) (добавлено в Python 2.4) и [`str.format()`](https://python-all.ru/3.3/library/stdtypes.html#str.format) (добавлено в Python 2.6).789790Логирование (начиная с версии 3.2) обеспечивает улучшенную поддержку этих двух дополнительных стилей форматирования. Класс `Formatter` был расширен, чтобы принимать дополнительный необязательный именованный параметр с именем `style`. По умолчанию он равен `'%'`, но другими возможными значениями являются `'{'` и `'$'`, которые соответствуют двум другим стилям форматирования. Обратная совместимость поддерживается по умолчанию (как и ожидается), но при явном указании параметра style вы получаете возможность задавать строки формата, которые работают с [`str.format()`](https://python-all.ru/3.3/library/stdtypes.html#str.format) или [`string.Template`](https://python-all.ru/3.3/library/string.html#string.Template). Вот пример сеанса консоли, показывающий возможности:791792```pycon793>>> import logging794>>> root = logging.getLogger()795>>> root.setLevel(logging.DEBUG)796>>> handler = logging.StreamHandler()797>>> bf = logging.Formatter('{asctime} {name} {levelname:8s} {message}',798... style='{')799>>> handler.setFormatter(bf)800>>> root.addHandler(handler)801>>> logger = logging.getLogger('foo.bar')802>>> logger.debug('This is a DEBUG message')8032010-10-28 15:11:55,341 foo.bar DEBUG This is a DEBUG message804>>> logger.critical('This is a CRITICAL message')8052010-10-28 15:12:11,526 foo.bar CRITICAL This is a CRITICAL message806>>> df = logging.Formatter('$asctime $name ${levelname} $message',807... style='$')808>>> handler.setFormatter(df)809>>> logger.debug('This is a DEBUG message')8102010-10-28 15:13:06,924 foo.bar DEBUG This is a DEBUG message811>>> logger.critical('This is a CRITICAL message')8122010-10-28 15:13:11,494 foo.bar CRITICAL This is a CRITICAL message813>>>814```815816Обратите внимание: форматирование сообщений журнала для конечного вывода в файлы совершенно не зависит от того, как конструируется отдельное сообщение. Оно по-прежнему может использовать %-форматирование, как показано ниже:817818```python819>>> logger.error('This is an%s %s %s', 'other,', 'ERROR,', 'message')8202010-10-28 15:19:29,833 foo.bar ERROR This is another, ERROR, message821>>>822```823824Вызовы логирования (`logger.debug()`, `logger.info()` и т.д.) принимают только позиционные параметры для самого сообщения логирования, а именованные параметры используются только для определения параметров обработки самого вызова логирования (например, именованный параметр `exc_info` для указания, что следует регистрировать трассировку стека, или именованный параметр `extra` для указания дополнительной контекстной информации, добавляемой в журнал). Поэтому вы не можете напрямую делать вызовы логирования, используя синтаксис [`str.format()`](https://python-all.ru/3.3/library/stdtypes.html#str.format) или [`string.Template`](https://python-all.ru/3.3/library/string.html#string.Template), потому что внутри пакет logging использует %-форматирование для объединения строки формата и переменных аргументов. Это невозможно изменить, сохраняя обратную совместимость, поскольку все существующие вызовы логирования в существующем коде будут использовать %-строки формата.825826Однако есть способ использовать форматирование {}- и $- для построения отдельных сообщений журнала. Напомним, что в качестве строки формата сообщения можно использовать произвольный объект, и пакет logging вызовет `str()` для этого объекта, чтобы получить фактическую строку формата. Рассмотрим следующие два класса:827828```python829class BraceMessage:830 def __init__(self, fmt, *args, **kwargs):831 self.fmt = fmt832 self.args = args833 self.kwargs = kwargs834835 def __str__(self):836 return self.fmt.format(*self.args, **self.kwargs)837838class DollarMessage:839 def __init__(self, fmt, **kwargs):840 self.fmt = fmt841 self.kwargs = kwargs842843 def __str__(self):844 from string import Template845 return Template(self.fmt).substitute(**self.kwargs)846```847848Любой из них можно использовать вместо строки формата, чтобы разрешить {}- или $-форматирование для построения фактической части «message», которая появляется в форматированном выводе журнала вместо «%(message)s» или «{message}» или «$message». Использовать имена классов всякий раз, когда нужно что-то записать, немного неудобно, но вполне приемлемо, если использовать псевдоним, например \_\_ (двойное подчеркивание – не путать с \_, одиночным подчеркиванием, используемым как синоним/псевдоним для [`gettext.gettext()`](https://python-all.ru/3.3/library/gettext.html#gettext.gettext) или его собратьев).849850Вышеуказанные классы не входят в состав Python, но их достаточно легко скопировать и вставить в свой код. Использовать их можно следующим образом (при условии, что они объявлены в модуле с именем `wherever`):851852```pycon853>>> from wherever import BraceMessage as __854>>> print(__('Message with {0} {name}', 2, name='placeholders'))855Message with 2 placeholders856>>> class Point: pass857...858>>> p = Point()859>>> p.x = 0.5860>>> p.y = 0.5861>>> print(__('Message with coordinates: ({point.x:.2f}, {point.y:.2f})',862... point=p))863Message with coordinates: (0.50, 0.50)864>>> from wherever import DollarMessage as __865>>> print(__('Message with $num $what', num=2, what='placeholders'))866Message with 2 placeholders867>>>868```869870Хотя в приведённых выше примерах используется `print()` для демонстрации работы форматирования, в реальном логировании, конечно, применяется `logger.debug()` или аналогичный метод.871872Следует отметить, что этот подход не даёт значительного снижения производительности с этим подходом: фактическое форматирование происходит не тогда, когда вы делаете вызов регистрации, а когда (и если) регистрируемое сообщение действительно должно быть выведено в журнал с помощью обработчика. Поэтому единственное, что может сбить с толку, – это то, что скобки ставятся вокруг строки формата и аргументов, а не только вокруг строки формата. Это потому, что нотация \_\_ – это просто синтаксический сахар для вызова конструктора одного из классов XXXMessage.873874При желании можно использовать `LoggerAdapter` для достижения похожего эффекта, как в следующем примере:875876```python877import logging878879class Message(object):880 def __init__(self, fmt, args):881 self.fmt = fmt882 self.args = args883884 def __str__(self):885 return self.fmt.format(*self.args)886887class StyleAdapter(logging.LoggerAdapter):888 def __init__(self, logger, extra=None):889 super(StyleAdapter, self).__init__(logger, extra or {})890891 def log(self, level, msg, *args, **kwargs):892 if self.isEnabledFor(level):893 msg, kwargs = self.process(msg, kwargs)894 self.logger._log(level, Message(msg, args), (), **kwargs)895896logger = StyleAdapter(logging.getLogger(__name__))897898def main():899 logger.debug('Hello, {}', 'world!')900901if __name__ == '__main__':902 logging.basicConfig(level=logging.DEBUG)903 main()904```905906При запуске на Python 3.2 или новее указанный скрипт должен записать в лог сообщение `Hello, world!`.907908## Настройка `LogRecord`909910Каждое событие логирования представлено экземпляром [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord). Когда событие логируется и не отфильтровывается по уровню регистратора, создаётся [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord), заполняется информацией о событии и передаётся обработчикам этого регистратора (и его предкам, вплоть до регистратора, у которого дальнейшее распространение вверх по иерархии отключено). До Python 3.2 создание выполнялось только в двух местах:911912- [`Logger.makeRecord()`](https://python-all.ru/3.3/library/logging.html#logging.Logger.makeRecord) – вызывается в обычном процессе записи события. Он напрямую обращался к [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord) для создания экземпляра.913- [`makeLogRecord()`](https://python-all.ru/3.3/library/logging.html#logging.makeLogRecord), which is called with a dictionary containing attributes to be added to the LogRecord. This is typically invoked when a suitable dictionary has been received over the network (e.g. in pickle form via a [`SocketHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.SocketHandler), or in JSON form via an [`HTTPHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.HTTPHandler)).914915Обычно это означало, что если требуется что-то особенное с [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord), приходилось делать одно из следующего.916917- Создать собственный подкласс [`Logger`](https://python-all.ru/3.3/library/logging.html#logging.Logger), переопределяющий [`Logger.makeRecord()`](https://python-all.ru/3.3/library/logging.html#logging.Logger.makeRecord), и установить его с помощью [`setLoggerClass()`](https://python-all.ru/3.3/library/logging.html#logging.setLoggerClass) до того, как будут созданы какие-либо нужные регистраторы.918- Добавить [`Filter`](https://python-all.ru/3.3/library/logging.html#logging.Filter) в регистратор или обработчик, который выполняет необходимые специальные манипуляции при вызове его метода [`filter()`](https://python-all.ru/3.3/library/logging.html#logging.Filter.filter).919920Первый подход был бы несколько громоздким, если, скажем, несколько разных библиотек хотели делать разные вещи. Каждая пыталась бы установить собственный подкласс [`Logger`](https://python-all.ru/3.3/library/logging.html#logging.Logger), и победила бы та, которая сделала это последней.921922Второй подход во многих случаях работает достаточно хорошо, но не позволяет, например, использовать специализированный подкласс [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord). Разработчики библиотек могут установить подходящий фильтр для своих регистраторов, но им придётся помнить об этом каждый раз, когда они создают новый регистратор (что они делают, просто добавляя новые пакеты или модули и выполняя923924```python925logger = logging.getLogger(__name__)926```927928на уровне модуля). Вероятно, это лишняя забота. Разработчики могли бы также добавить фильтр в [`NullHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.NullHandler), прикреплённый к их корневому регистратору, но он не будет вызываться, если разработчик приложения присоединит обработчик к нижележащему библиотечному регистратору – тогда вывод этого обработчика не отразит намерений разработчика библиотеки.929930В Python 3.2 и новее создание [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord) осуществляется через фабрику, которую можно указать. Фабрика – это просто вызываемый объект, который можно установить с помощью [`setLogRecordFactory()`](https://python-all.ru/3.3/library/logging.html#logging.setLogRecordFactory) и запросить через [`getLogRecordFactory()`](https://python-all.ru/3.3/library/logging.html#logging.getLogRecordFactory). Фабрика вызывается с той же сигнатурой, что и конструктор [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord), поскольку [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord) является настройкой по умолчанию для фабрики.931932Этот подход позволяет пользовательской фабрике контролировать все аспекты создания LogRecord. Например, можно вернуть подкласс или просто добавить несколько дополнительных атрибутов к записи после ее создания, используя шаблон, подобный следующему:933934```python935old_factory = logging.getLogRecordFactory()936937def record_factory(*args, **kwargs):938 record = old_factory(*args, **kwargs)939 record.custom_attribute = 0xdecafbad940 return record941942logging.setLogRecordFactory(record_factory)943```944945Такой подход позволяет разным библиотекам объединять фабрики в цепочку, и пока они не перезаписывают атрибуты друг друга или случайно не переопределяют стандартные атрибуты, неожиданностей быть не должно. Однако следует помнить, что каждое звено в цепочке добавляет дополнительные накладные расходы во время выполнения всех операций логирования, и этот метод следует использовать только тогда, когда применение [`Filter`](https://python-all.ru/3.3/library/logging.html#logging.Filter) не даёт желаемого результата.946947## Создание подкласса QueueHandler – пример с ZeroMQ948949Можно использовать подкласс `QueueHandler` для отправки сообщений в очереди других типов, например, в сокет «публикации» ZeroMQ. В примере ниже сокет создаётся отдельно и передаётся обработчику (в качестве его «очереди»):950951```python952import zmq # с использованием pyzmq, привязки Python к ZeroMQ953import json # для переносимой сериализации записей954955ctx = zmq.Context()956sock = zmq.Socket(ctx, zmq.PUB) # или zmq.PUSH, или другое подходящее значение957sock.bind('tcp://*:5556') # или где угодно958959class ZeroMQSocketHandler(QueueHandler):960 def enqueue(self, record):961 data = json.dumps(record.__dict__)962 self.queue.send(data)963964handler = ZeroMQSocketHandler(sock)965```966967Конечно, есть и другие способы организации этого, например, передача данных, необходимых обработчику для создания сокета:968969```python970class ZeroMQSocketHandler(QueueHandler):971 def __init__(self, uri, socktype=zmq.PUB, ctx=None):972 self.ctx = ctx or zmq.Context()973 socket = zmq.Socket(self.ctx, socktype)974 socket.bind(uri)975 QueueHandler.__init__(self, socket)976977 def enqueue(self, record):978 data = json.dumps(record.__dict__)979 self.queue.send(data)980981 def close(self):982 self.queue.close()983```984985## Создание подкласса QueueListener – пример с ZeroMQ986987Также можно создать подкласс `QueueListener` для получения сообщений из очередей других типов, например, из сокета «подписки» ZeroMQ. Вот пример:988989```python990class ZeroMQSocketListener(QueueListener):991 def __init__(self, uri, *handlers, **kwargs):992 self.ctx = kwargs.get('ctx') or zmq.Context()993 socket = zmq.Socket(self.ctx, zmq.SUB)994 socket.setsockopt(zmq.SUBSCRIBE, '') # подписаться на всё995 socket.connect(uri)996997 def dequeue(self):998 msg = self.queue.recv()999 return logging.makeLogRecord(json.loads(msg))1000```10011002> **См. также**1003>1004> **Модуль [`logging`](https://python-all.ru/3.3/library/logging.html#module-logging)**1005>1006> Справочник API для модуля logging.1007>1008> **Модуль [`logging.config`](https://python-all.ru/3.3/library/logging.config.html#module-logging.config)**1009>1010> API конфигурации для модуля logging.1011>1012> **Модуль [`logging.handlers`](https://python-all.ru/3.3/library/logging.handlers.html#module-logging.handlers)**1013>1014> Полезные обработчики, входящие в состав модуля logging.1015>1016> [*Базовое руководство по логированию*](https://python-all.ru/3.3/howto/logging.html#logging-basic-tutorial)1017>1018> [*Более продвинутое руководство по логированию*](https://python-all.ru/3.3/howto/logging.html#logging-advanced-tutorial)10191020## Пример конфигурации на основе словаря10211022Ниже приведён пример словаря конфигурации логирования – он взят из [документации проекта Django](https://python-all.ru/3.3/howto/logging-cookbook.html). Этот словарь передаётся в [`dictConfig()`](https://python-all.ru/3.3/library/logging.config.html#logging.config.dictConfig) для применения конфигурации:10231024```python1025LOGGING = {1026 'version': 1,1027 'disable_existing_loggers': True,1028 'formatters': {1029 'verbose': {1030 'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s'1031 },1032 'simple': {1033 'format': '%(levelname)s %(message)s'1034 },1035 },1036 'filters': {1037 'special': {1038 '()': 'project.logging.SpecialFilter',1039 'foo': 'bar',1040 }1041 },1042 'handlers': {1043 'null': {1044 'level':'DEBUG',1045 'class':'django.utils.log.NullHandler',1046 },1047 'console':{1048 'level':'DEBUG',1049 'class':'logging.StreamHandler',1050 'formatter': 'simple'1051 },1052 'mail_admins': {1053 'level': 'ERROR',1054 'class': 'django.utils.log.AdminEmailHandler',1055 'filters': ['special']1056 }1057 },1058 'loggers': {1059 'django': {1060 'handlers':['null'],1061 'propagate': True,1062 'level':'INFO',1063 },1064 'django.request': {1065 'handlers': ['mail_admins'],1066 'level': 'ERROR',1067 'propagate': False,1068 },1069 'myproject.custom': {1070 'handlers': ['console', 'mail_admins'],1071 'level': 'INFO',1072 'filters': ['special']1073 }1074 }1075}1076```10771078Для получения дополнительной информации об этой конфигурации можно обратиться к [соответствующему разделу](https://python-all.ru/3.3/howto/logging-cookbook.html) документации Django.10791080## Использование ротатора и средства именования для настройки обработки ротации журналов10811082Пример того, как можно определить namer и rotator, приведен в следующем фрагменте кода, который демонстрирует сжатие журнала с использованием zlib:10831084```python1085def namer(name):1086 return name + ".gz"10871088def rotator(source, dest):1089 with open(source, "rb") as sf:1090 data = sf.read()1091 compressed = zlib.compress(data, 9)1092 with open(dest, "wb") as df:1093 df.write(compressed)1094 os.remove(source)10951096rh = logging.handlers.RotatingFileHandler(...)1097rh.rotator = rotator1098rh.namer = namer1099```11001101Это не «настоящие» .gz-файлы, поскольку они представляют собой просто сжатые данные без «контейнера», который присутствует в обычном gzip-файле. Данный фрагмент приведен только для иллюстрации.11021103## Более сложный пример с многопроцессностью11041105Следующий рабочий пример показывает, как можно использовать логирование с многопроцессностью с помощью файлов конфигурации. Конфигурации довольно просты, но служат иллюстрацией того, как можно реализовать более сложные в реальном сценарии многопроцессной обработки.11061107В примере главный процесс порождает процесс-слушатель и несколько рабочих процессов. Каждый из главного процесса, слушателя и рабочих имеет три отдельные конфигурации (все рабочие используют одну и ту же конфигурацию). Видно ведение журнала в главном процессе, как рабочие пишут в QueueHandler, а слушатель реализует QueueListener и более сложную конфигурацию ведения журнала, и организует отправку событий, полученных через очередь, обработчикам, указанным в конфигурации. Обратите внимание, что эти конфигурации чисто иллюстративные, но этот пример можно адаптировать под свой сценарий.11081109Вот скрипт – строки документации и комментарии, надеюсь, поясняют, как он работает:11101111```python1112import logging1113import logging.config1114import logging.handlers1115from multiprocessing import Process, Queue, Event, current_process1116import os1117import random1118import time11191120class MyHandler:1121 """1122 Простой обработчик для событий логирования. Он выполняется в процессе-слушателе и1123 распределяет события по логгерам на основе имени в полученной записи,1124 которые затем передаются системой логирования обработчикам,1125 настроенным для этих логгеров.1126 """1127 def handle(self, record):1128 logger = logging.getLogger(record.name)1129 # Имя процесса преобразуется только для того, чтобы показать, что это слушатель1130 # выполняет логирование в файлы и консоль.1131 record.processName = '%s (for %s)' % (current_process().name, record.processName)1132 logger.handle(record)11331134def listener_process(q, stop_event, config):1135 """1136 Это можно было бы сделать в главном процессе, но сделано в отдельном1137 процессе для наглядности.11381139 Это инициализирует логирование согласно указанной конфигурации1140 запускает слушатель и ожидает сигнала от главного процесса о завершении1141 через событие. Затем слушатель останавливается, и процесс завершается.1142 """1143 logging.config.dictConfig(config)1144 listener = logging.handlers.QueueListener(q, MyHandler())1145 listener.start()1146 if os.name == 'posix':1147 # В POSIX логгер setup уже был настроен в1148 # родительском процессе, но должен был быть отключён после вызова1149 # dictConfig.1150 # В Windows, поскольку fork не используется, логгер setup не будет1151 # существовать в дочернем процессе, поэтому он будет создан, и сообщение1152 # появится – отсюда и конструкция "if posix".1153 logger = logging.getLogger('setup')1154 logger.critical('Should not appear, because of disabled logger ...')1155 stop_event.wait()1156 listener.stop()11571158def worker_process(config):1159 """1160 Некоторое количество таких процессов порождается для иллюстрации. На1161 на практике это может быть разнородная группа процессов, а не1162 идентичные друг другу.11631164 Это инициализирует логирование согласно указанной конфигурации1165 и записывает сотню сообщений со случайными уровнями в случайно выбранные1166 логгеры.11671168 Добавлена небольшая задержка, чтобы дать другим процессам шанс выполниться. Это1169 не является строго необходимым, но позволяет немного перемешать вывод от разных1170 процессов больше, чем если бы её не было.1171 """1172 logging.config.dictConfig(config)1173 levels = [logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR,1174 logging.CRITICAL]1175 loggers = ['foo', 'foo.bar', 'foo.bar.baz',1176 'spam', 'spam.ham', 'spam.ham.eggs']1177 if os.name == 'posix':1178 # В POSIX логгер setup уже был настроен в1179 # родительском процессе, но должен был быть отключён после вызова1180 # dictConfig.1181 # В Windows, поскольку fork не используется, логгер setup не будет1182 # существовать в дочернем процессе, поэтому он будет создан, и сообщение1183 # появится – отсюда и конструкция "if posix".1184 logger = logging.getLogger('setup')1185 logger.critical('Should not appear, because of disabled logger ...')1186 for i in range(100):1187 lvl = random.choice(levels)1188 logger = logging.getLogger(random.choice(loggers))1189 logger.log(lvl, 'Message no. %d', i)1190 time.sleep(0.01)11911192def main():1193 q = Queue()1194 # Главный процесс получает простую конфигурацию, которая выводит информацию в консоль.1195 config_initial = {1196 'version': 1,1197 'formatters': {1198 'detailed': {1199 'class': 'logging.Formatter',1200 'format': '%(asctime)s %(name)-15s %(levelname)-8s %(processName)-10s %(message)s'1201 }1202 },1203 'handlers': {1204 'console': {1205 'class': 'logging.StreamHandler',1206 'level': 'INFO',1207 },1208 },1209 'root': {1210 'level': 'DEBUG',1211 'handlers': ['console']1212 },1213 }1214 # Конфигурация рабочего процесса представляет собой QueueHandler, прикреплённый к1215 # корневому логгеру, что позволяет отправлять все сообщения в очередь.1216 # Мы отключаем существующие логгеры, чтобы отключить логгер "setup", используемый в1217 # родительском процессе. Это необходимо в POSIX, потому что логгер будет1218 # присутствовать в дочернем процессе после вызова fork().1219 config_worker = {1220 'version': 1,1221 'disable_existing_loggers': True,1222 'handlers': {1223 'queue': {1224 'class': 'logging.handlers.QueueHandler',1225 'queue': q,1226 },1227 },1228 'root': {1229 'level': 'DEBUG',1230 'handlers': ['queue']1231 },1232 }1233 # Конфигурация процесса-слушателя показывает, что вся гибкость1234 # конфигурации логирования доступна для отправки событий обработчикам так, как1235 # требуется.1236 # Мы отключаем существующие логгеры, чтобы отключить логгер "setup", используемый в1237 # родительском процессе. Это необходимо в POSIX, потому что логгер будет1238 # присутствовать в дочернем процессе после вызова fork().1239 config_listener = {1240 'version': 1,1241 'disable_existing_loggers': True,1242 'formatters': {1243 'detailed': {1244 'class': 'logging.Formatter',1245 'format': '%(asctime)s %(name)-15s %(levelname)-8s %(processName)-10s %(message)s'1246 },1247 'simple': {1248 'class': 'logging.Formatter',1249 'format': '%(name)-15s %(levelname)-8s %(processName)-10s %(message)s'1250 }1251 },1252 'handlers': {1253 'console': {1254 'class': 'logging.StreamHandler',1255 'level': 'INFO',1256 'formatter': 'simple',1257 },1258 'file': {1259 'class': 'logging.FileHandler',1260 'filename': 'mplog.log',1261 'mode': 'w',1262 'formatter': 'detailed',1263 },1264 'foofile': {1265 'class': 'logging.FileHandler',1266 'filename': 'mplog-foo.log',1267 'mode': 'w',1268 'formatter': 'detailed',1269 },1270 'errors': {1271 'class': 'logging.FileHandler',1272 'filename': 'mplog-errors.log',1273 'mode': 'w',1274 'level': 'ERROR',1275 'formatter': 'detailed',1276 },1277 },1278 'loggers': {1279 'foo': {1280 'handlers': ['foofile']1281 }1282 },1283 'root': {1284 'level': 'DEBUG',1285 'handlers': ['console', 'file', 'errors']1286 },1287 }1288 # Записываем несколько начальных событий, просто чтобы показать, что логирование в родительском процессе работает1289 # нормально.1290 logging.config.dictConfig(config_initial)1291 logger = logging.getLogger('setup')1292 logger.info('About to create workers ...')1293 workers = []1294 for i in range(5):1295 wp = Process(target=worker_process, name='worker %d' % (i + 1),1296 args=(config_worker,))1297 workers.append(wp)1298 wp.start()1299 logger.info('Started worker: %s', wp.name)1300 logger.info('About to create listener ...')1301 stop_event = Event()1302 lp = Process(target=listener_process, name='listener',1303 args=(q, stop_event, config_listener))1304 lp.start()1305 logger.info('Started listener')1306 # Теперь ожидаем завершения работы рабочих процессов.1307 for wp in workers:1308 wp.join()1309 # Все рабочие процессы завершены, теперь можно остановить прослушивание.1310 # Логирование в родительском процессе всё ещё работает нормально.1311 logger.info('Telling listener to stop ...')1312 stop_event.set()1313 lp.join()1314 logger.info('All done.')13151316if __name__ == '__main__':1317 main()1318```13191320## Вставка BOM в сообщения, отправляемые в SysLogHandler13211322[RFC 5424](https://python-all.ru/3.3/howto/logging-cookbook.html) требует, чтобы Unicode-сообщение отправлялось демону syslog в виде набора байтов следующей структуры: необязательный компонент, состоящий только из ASCII, затем метка порядка байтов (BOM) UTF-8, затем Unicode, закодированный в UTF-8. (См. [соответствующий раздел спецификации](https://python-all.ru/3.3/howto/logging-cookbook.html).)13231324В Python 3.1 в [`SysLogHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.SysLogHandler) был добавлен код для вставки метки BOM в сообщение, но, к сожалению, он был реализован неправильно: BOM появлялся в начале сообщения, не позволяя никакому чисто ASCII-компоненту находиться перед ним.13251326Поскольку такое поведение некорректно, код, неправильно вставляющий BOM, удаляется из Python 3.2.4 и более поздних версий. Однако он не заменяется, и если требуется создавать сообщения, совместимые с RFC 5424, которые содержат BOM, необязательную последовательность символов только из ASCII перед ним и произвольный Unicode после него, закодированные в UTF-8, то необходимо сделать следующее:132713281. Прикрепите экземпляр [`Formatter`](https://python-all.ru/3.3/library/logging.html#logging.Formatter) к своему экземпляру [`SysLogHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.handlers.SysLogHandler) со строкой формата, например:13291330 ```python1331 'ASCII section\ufeffUnicode section'1332 ```13331334 Кодовая точка Unicode U+FEFF при кодировании UTF-8 будет закодирована как метка BOM UTF-8 – строка байтов `b'\xef\xbb\xbf'`.13352. ASCII-часть следует заменить на любые подходящие заполнители, но необходимо следить, чтобы данные, которые появляются там после подстановки, всегда были в ASCII (таким образом, они останутся без изменений после кодирования UTF-8).13363. Unicode-часть следует заменить на любые заполнители; если данные после подстановки содержат символы за пределами диапазона ASCII, это нормально – они будут закодированы в UTF-8.13371338Отформатированное сообщение *будет* закодировано `SysLogHandler` в кодировке UTF-8. Если соблюдать приведённые выше правила, можно создавать сообщения, совместимые с RFC 5424. В противном случае логирование может не жаловаться, но сообщения не будут соответствовать RFC 5424, и ваш демон syslog может начать жаловаться.13391340## Реализация структурированного ведения журнала13411342Хотя большинство сообщений лога предназначены для чтения человеком и поэтому нелегко разбираются машиной, могут возникнуть ситуации, когда нужно выводить сообщения в структурированном формате, *который* может быть проанализирован программой (без необходимости сложных регулярных выражений для разбора сообщения лога). Это легко достигается с помощью пакета logging. Есть несколько способов это сделать, но ниже приведён простой подход, использующий JSON для сериализации события в машиночитаемом виде:13431344```python1345import json1346import logging13471348class StructuredMessage(object):1349 def __init__(self, message, **kwargs):1350 self.message = message1351 self.kwargs = kwargs13521353 def __str__(self):1354 return '%s >>> %s' % (self.message, json.dumps(self.kwargs))13551356_ = StructuredMessage # необязательно, для улучшения читаемости13571358logging.basicConfig(level=logging.INFO, format='%(message)s')1359logging.info(_('message 1', foo='bar', bar='baz', num=123, fnum=123.456))1360```13611362Если запустить приведённый выше скрипт, он выведет:13631364```python1365message 1 >>> {"fnum": 123.456, "num": 123, "bar": "baz", "foo": "bar"}1366```13671368Обратите внимание, что порядок элементов может отличаться в зависимости от используемой версии Python.13691370Если требуется более специализированная обработка, можно использовать пользовательский кодировщик JSON, как в следующем полном примере:13711372```python1373from __future__ import unicode_literals13741375import json1376import logging13771378# Следующий фрагмент предназначен для того, чтобы скрипт работал без изменений в версиях 2.x и 3.x.1379try:1380 unicode1381except NameError:1382 unicode = str13831384class Encoder(json.JSONEncoder):1385 def default(self, o):1386 if isinstance(o, set):1387 return tuple(o)1388 elif isinstance(o, unicode):1389 return o.encode('unicode_escape').decode('ascii')1390 return super(Encoder, self).default(o)13911392class StructuredMessage(object):1393 def __init__(self, message, **kwargs):1394 self.message = message1395 self.kwargs = kwargs13961397 def __str__(self):1398 s = Encoder().encode(self.kwargs)1399 return '%s >>> %s' % (self.message, s)14001401_ = StructuredMessage # необязательно, для улучшения читаемости14021403def main():1404 logging.basicConfig(level=logging.INFO, format='%(message)s')1405 logging.info(_('message 1', set_value=set([1, 2, 3]), snowman='\u2603'))14061407if __name__ == '__main__':1408 main()1409```14101411При запуске приведённого выше скрипта он выведет:14121413```python1414message 1 >>> {"snowman": "\u2603", "set_value": [1, 2, 3]}1415```14161417Обратите внимание, что порядок элементов может отличаться в зависимости от используемой версии Python.14181419## Настройка обработчиков с помощью [`dictConfig()`](https://python-all.ru/3.3/library/logging.config.html#logging.config.dictConfig)14201421Иногда требуется настроить обработчики логирования особым образом, и при использовании [`dictConfig()`](https://python-all.ru/3.3/library/logging.config.html#logging.config.dictConfig) это можно сделать без создания подклассов. Например, можно задать владельца файла журнала. В POSIX это легко делается с помощью [`shutil.chown()`](https://python-all.ru/3.3/library/shutil.html#shutil.chown), но файловые обработчики в стандартной библиотеке не имеют встроенной поддержки. Создание обработчика можно настроить с помощью обычной функции, например:14221423```python1424def owned_file_handler(filename, mode='a', encoding=None, owner=None):1425 if owner:1426 if not os.path.exists(filename):1427 open(filename, 'a').close()1428 shutil.chown(filename, *owner)1429 return logging.FileHandler(filename, mode, encoding)1430```14311432Затем в конфигурации логирования, передаваемой в [`dictConfig()`](https://python-all.ru/3.3/library/logging.config.html#logging.config.dictConfig), можно указать, что обработчик должен быть создан вызовом этой функции:14331434```python1435LOGGING = {1436 'version': 1,1437 'disable_existing_loggers': False,1438 'formatters': {1439 'default': {1440 'format': '%(asctime)s %(levelname)s %(name)s %(message)s'1441 },1442 },1443 'handlers': {1444 'file':{1445 # Значения ниже извлекаются из этого словаря и1446 # используются для создания обработчика, установки его уровня и1447 # его форматтера.1448 '()': owned_file_handler,1449 'level':'DEBUG',1450 'formatter': 'default',1451 # Значения ниже передаются вызываемому объекту-создателю обработчика1452 # в качестве именованных аргументов.1453 'owner': ['pulse', 'pulse'],1454 'filename': 'chowntest.log',1455 'mode': 'w',1456 'encoding': 'utf-8',1457 },1458 },1459 'root': {1460 'handlers': ['file'],1461 'level': 'DEBUG',1462 },1463}1464```14651466В этом примере я устанавливаю владельца через пользователя и группу `pulse` – только для иллюстрации. Собирая всё вместе в рабочий скрипт `chowntest.py`:14671468```python1469import logging, logging.config, os, shutil14701471def owned_file_handler(filename, mode='a', encoding=None, owner=None):1472 if owner:1473 if not os.path.exists(filename):1474 open(filename, 'a').close()1475 shutil.chown(filename, *owner)1476 return logging.FileHandler(filename, mode, encoding)14771478LOGGING = {1479 'version': 1,1480 'disable_existing_loggers': False,1481 'formatters': {1482 'default': {1483 'format': '%(asctime)s %(levelname)s %(name)s %(message)s'1484 },1485 },1486 'handlers': {1487 'file':{1488 # Значения ниже извлекаются из этого словаря и1489 # используются для создания обработчика, установки его уровня и1490 # его форматтера.1491 '()': owned_file_handler,1492 'level':'DEBUG',1493 'formatter': 'default',1494 # Значения ниже передаются вызываемому объекту-создателю обработчика1495 # в качестве именованных аргументов.1496 'owner': ['pulse', 'pulse'],1497 'filename': 'chowntest.log',1498 'mode': 'w',1499 'encoding': 'utf-8',1500 },1501 },1502 'root': {1503 'handlers': ['file'],1504 'level': 'DEBUG',1505 },1506}15071508logging.config.dictConfig(LOGGING)1509logger = logging.getLogger('mylogger')1510logger.debug('A debug message')1511```15121513Чтобы запустить это, возможно, потребуется выполнить от имени `root`:15141515```python1516$ sudo python3.3 chowntest.py1517$ cat chowntest.log15182013-11-05 09:34:51,128 DEBUG mylogger A debug message1519$ ls -l chowntest.log1520-rw-r--r-- 1 pulse pulse 55 2013-11-05 09:34 chowntest.log1521```15221523Обратите внимание, что в этом примере используется Python 3.3, так как именно в нём появилась функция [`shutil.chown()`](https://python-all.ru/3.3/library/shutil.html#shutil.chown). Этот подход должен работать с любой версией Python, которая поддерживает [`dictConfig()`](https://python-all.ru/3.3/library/logging.config.html#logging.config.dictConfig) – а именно Python 2.7, 3.2 и выше. В версиях до 3.3 вам потребуется реализовать смену владельца, например, с помощью [`os.chown()`](https://python-all.ru/3.3/library/os.html#os.chown).15241525На практике функция создания обработчика может находиться в служебном модуле где-нибудь в вашем проекте. Вместо строки в конфигурации:15261527```python1528'()': owned_file_handler,1529```15301531можно использовать, например:15321533```python1534'()': 'ext://project.util.owned_file_handler',1535```15361537где `project.util` можно заменить на фактическое имя пакета, в котором находится функция. В приведённом выше рабочем скрипте должно сработать использование `'ext://__main__.owned_file_handler'`. Здесь фактическая вызываемая сущность разрешается функцией [`dictConfig()`](https://python-all.ru/3.3/library/logging.config.html#logging.config.dictConfig) из спецификации `ext://`.15381539Надеемся, этот пример также показывает, как можно реализовать другие типы изменений файлов (например, установку определённых битов разрешений POSIX) тем же способом, с помощью [`os.chmod()`](https://python-all.ru/3.3/library/os.html#os.chmod).15401541Конечно, этот подход можно расширить и на другие типы обработчиков, отличные от [`FileHandler`](https://python-all.ru/3.3/library/logging.handlers.html#logging.FileHandler) – например, на один из ротационных файловых обработчиков или на совершенно другой тип обработчика.15421543## Использование определённых стилей форматирования во всём приложении15441545В Python 3.2 у [`Formatter`](https://python-all.ru/3.3/library/logging.html#logging.Formatter) появился именованный параметр `style`, который по умолчанию равен `%` для обратной совместимости, но позволяет указать `{` или `$` для поддержки подходов форматирования, используемых в [`str.format()`](https://python-all.ru/3.3/library/stdtypes.html#str.format) и [`string.Template`](https://python-all.ru/3.3/library/string.html#string.Template). Обратите внимание, что это управляет форматированием сообщений журнала для финального вывода в журнал и совершенно независимо от того, как конструируется отдельное сообщение для записи.15461547Вызовы журналирования ([`debug()`](https://python-all.ru/3.3/library/logging.html#logging.Logger.debug), [`info()`](https://python-all.ru/3.3/library/logging.html#logging.Logger.info) и т.д.) принимают только позиционные параметры для самого сообщения журнала; именованные параметры используются только для определения параметров обработки вызова (например, именованный параметр `exc_info` указывает, что нужно записывать информацию о трассировке, или `extra` для добавления дополнительной контекстной информации в журнал). Поэтому нельзя напрямую использовать синтаксис [`str.format()`](https://python-all.ru/3.3/library/stdtypes.html#str.format) или [`string.Template`](https://python-all.ru/3.3/library/string.html#string.Template) в вызовах журналирования, потому что внутри пакет logging использует %-форматирование для объединения строки формата и переменных аргументов. Изменить это, сохранив обратную совместимость, невозможно, так как все существующие вызовы в коде используют %-формат.15481549Высказывались предложения связывать стили форматирования с конкретными регистраторами, но этот подход также сталкивается с проблемами обратной совместимости, поскольку любой существующий код может использовать данное имя регистратора и %-форматирование.15501551Чтобы логирование работало совместимо между любыми сторонними библиотеками и вашим кодом, решения о форматировании необходимо принимать на уровне отдельного вызова логирования. Это открывает несколько способов, которыми можно реализовать альтернативные стили форматирования.15521553### Использование фабрик LogRecord15541555В Python 3.2, вместе с изменениями [`Formatter`](https://python-all.ru/3.3/library/logging.html#logging.Formatter), упомянутыми выше, пакет logging получил возможность позволять пользователям задавать собственные подклассы [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord) с помощью функции [`setLogRecordFactory()`](https://python-all.ru/3.3/library/logging.html#logging.setLogRecordFactory). Это можно использовать для установки собственного подкласса [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord), который делает правильные вещи, переопределяя метод [`getMessage()`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord.getMessage). В реализации базового класса этого метода происходит форматирование `msg % args`, и здесь можно подставить своё альтернативное форматирование; однако нужно быть осторожным, чтобы поддерживать все стили форматирования и оставить %-форматирование по умолчанию, чтобы обеспечить совместимость с другим кодом. Также следует не забыть вызвать `str(self.msg)`, как это делает базовая реализация.15561557Обратитесь к справочной документации по [`setLogRecordFactory()`](https://python-all.ru/3.3/library/logging.html#logging.setLogRecordFactory) и [`LogRecord`](https://python-all.ru/3.3/library/logging.html#logging.LogRecord) для получения дополнительной информации.15581559### Использование пользовательских объектов сообщений15601561Существует ещё один, возможно, более простой способ использовать {}- и $-форматирование для построения отдельных сообщений журнала. Возможно, вы помните (из раздела [*Использование произвольных объектов в качестве сообщений*](https://python-all.ru/3.3/howto/logging.html#arbitrary-object-messages)), что при журналировании можно использовать произвольный объект в качестве строки формата сообщения, и пакет logging вызовет [`str()`](https://python-all.ru/3.3/library/stdtypes.html#str) для этого объекта, чтобы получить фактическую строку формата. Рассмотрим следующие два класса:15621563```python1564class BraceMessage(object):1565 def __init__(self, fmt, *args, **kwargs):1566 self.fmt = fmt1567 self.args = args1568 self.kwargs = kwargs15691570 def __str__(self):1571 return self.fmt.format(*self.args, **self.kwargs)15721573class DollarMessage(object):1574 def __init__(self, fmt, **kwargs):1575 self.fmt = fmt1576 self.kwargs = kwargs15771578 def __str__(self):1579 from string import Template1580 return Template(self.fmt).substitute(**self.kwargs)1581```15821583Любой из них можно использовать вместо строки формата, чтобы с помощью {}- или $-форматирования строить фактическую часть «message», которая появляется в отформатированном выводе журнала вместо «%(message)s», «{message}» или «$message». Если использовать имена классов каждый раз, когда нужно что-то записать, кажется громоздким, можно сделать это более удобным, используя псевдоним, например `M` или `_` для сообщения (или, возможно, `__`, если вы используете `_` для локализации).15841585Примеры этого подхода приведены ниже. Сначала форматирование с помощью [`str.format()`](https://python-all.ru/3.3/library/stdtypes.html#str.format):15861587```python1588>>> __ = BraceMessage1589>>> print(__('Message with {0} {1}', 2, 'placeholders'))1590Message with 2 placeholders1591>>> class Point: pass1592...1593>>> p = Point()1594>>> p.x = 0.51595>>> p.y = 0.51596>>> print(__('Message with coordinates: ({point.x:.2f}, {point.y:.2f})', point=p))1597Message with coordinates: (0.50, 0.50)1598```15991600Затем форматирование с помощью [`string.Template`](https://python-all.ru/3.3/library/string.html#string.Template):16011602```python1603>>> __ = DollarMessage1604>>> print(__('Message with $num $what', num=2, what='placeholders'))1605Message with 2 placeholders1606>>>1607```16081609Стоит отметить, что при таком подходе нет значительного снижения производительности: фактическое форматирование происходит не в момент вызова журналирования, а когда (и если) сообщение должно быть выведено в журнал обработчиком. Единственная необычная деталь, которая может сбить с толку, – скобки окружают строку формата и аргументы, а не только строку формата. Это связано с тем, что нотация \_\_ – это просто синтаксический сахар для вызова конструктора одного из классов `XXXMessage`, показанных выше.16101611## Настройка фильтров с помощью [`dictConfig()`](https://python-all.ru/3.3/library/logging.config.html#logging.config.dictConfig)16121613Фильтры *можно* настраивать с помощью [`dictConfig()`](https://python-all.ru/3.3/library/logging.config.html#logging.config.dictConfig), хотя с первого взгляда может быть неочевидно, как это сделать (поэтому и приведён этот рецепт). Поскольку [`Filter`](https://python-all.ru/3.3/library/logging.html#logging.Filter) – единственный класс фильтра, входящий в стандартную библиотеку, и вряд ли он удовлетворит все потребности (он существует только как базовый класс), обычно потребуется определить собственный подкласс [`Filter`](https://python-all.ru/3.3/library/logging.html#logging.Filter) с переопределённым методом [`filter()`](https://python-all.ru/3.3/library/logging.html#logging.Filter.filter). Для этого укажите ключ `()` в словаре конфигурации для фильтра, задав вызываемый объект, который будет использоваться для создания фильтра (класс – самый очевидный вариант, но можно указать любой вызываемый объект, возвращающий экземпляр [`Filter`](https://python-all.ru/3.3/library/logging.html#logging.Filter)). Вот полный пример:16141615```python1616import logging1617import logging.config1618import sys16191620class MyFilter(logging.Filter):1621 def __init__(self, param=None):1622 self.param = param16231624 def filter(self, record):1625 if self.param is None:1626 allow = True1627 else:1628 allow = self.param not in record.msg1629 if allow:1630 record.msg = 'changed: ' + record.msg1631 return allow16321633LOGGING = {1634 'version': 1,1635 'filters': {1636 'myfilter': {1637 '()': MyFilter,1638 'param': 'noshow',1639 }1640 },1641 'handlers': {1642 'console': {1643 'class': 'logging.StreamHandler',1644 'filters': ['myfilter']1645 }1646 },1647 'root': {1648 'level': 'DEBUG',1649 'handlers': ['console']1650 },1651}16521653if __name__ == '__main__':1654 logging.config.dictConfig(LOGGING)1655 logging.debug('hello')1656 logging.debug('hello - noshow')1657```16581659Этот пример показывает, как можно передавать конфигурационные данные вызываемому объекту, который создает экземпляр, в виде именованных параметров. При запуске приведенный выше скрипт выведет:16601661```python1662changed: hello1663```16641665что показывает, что фильтр работает в соответствии с настройками.16661667Несколько дополнительных моментов, на которые стоит обратить внимание:16681669- Если нет возможности сослаться на вызываемый объект непосредственно в конфигурации (например, он находится в другом модуле и его нельзя импортировать напрямую в месте, где находится словарь конфигурации), можно использовать форму `ext://...`, как описано в разделе [*Доступ к внешним объектам*](https://python-all.ru/3.3/library/logging.config.html#logging-config-dict-externalobj). Например, в приведённом выше примере можно было использовать текст `'ext://__main__.MyFilter'` вместо `MyFilter`.1670- Помимо фильтров, этот метод также можно использовать для настройки пользовательских обработчиков и форматтеров. Смотрите раздел [*Пользовательские объекты*](https://python-all.ru/3.3/library/logging.config.html#logging-config-dict-userdef) для получения дополнительной информации о том, как logging поддерживает использование пользовательских объектов в своей конфигурации, а также см. другой рецепт из этой книги рецептов [*Настройка обработчиков с помощью dictConfig()*](https://python-all.ru/3.3/howto/logging-cookbook.html#custom-handlers) выше.1671