Запись ошибки в файл python
По мере того, как усложняется структура приложения, ведение логов (журналирование) становится всё полезнее для разработчика. Логи не только пригодятся в процессе отладки, но и помогут обнаружить скрытые проблемы проекта, а также отследить его производительность.
Модуль logging, входящий в состав стандартной библиотеки Python, предоставляет большую часть необходимых для журналирования функций. Если его правильно настроить, записи лога могут предоставить большое количество полезной информации о работе приложения: в каком месте кода была сформирована запись, какие потоки и процессы были запущены, каково состояние памяти.
Данный материал — руководство для начинающих разработчиков.
Обратите внимание, что весь размещённый в статье код подразумевает, что вы уже импортировали модуль:
Using logging in multiple modules¶
Multiple calls to logging.getLogger('someLogger') return a reference to the same logger object. This is true not only within the same module, but also across modules as long as it is in the same Python interpreter process. It is true for references to the same object; additionally, application code can define and configure a parent logger in one module and create (but not configure) a child logger in a separate module, and all logger calls to the child will pass up to the parent. Here is a main module:
Here is the auxiliary module:
The output looks like this:
Логирование событий в файл.
Очень распространенная ситуация, когда необходимо записывать события в файл.
Если необходимо установить уровень ведения журнала из командной строки, а значение параметра для --log= было получено например в переменную loglevel , то можно использовать функцию getattr для получения значения, которое передается logging.basicConfig() в качестве аргумента level :
При условии, что loglevel привязан к строковому значению, полученному из командной строки, можно проверить любой вводимый пользователем уровень логирования, используя псевдокод из следующего примера:
Logging to multiple destinations¶
Let’s say you want to log to console and file with different message formats and in differing circumstances. Say you want to log messages with levels of DEBUG and higher to file, and those messages at level INFO and higher to the console. Let’s also assume that the file should contain timestamps, but the console messages should not. Here’s how you can achieve this:
When you run this, on the console you will see
and in the file you will see something like
As you can see, the DEBUG message only shows up in the file. The other messages are sent to both destinations.
This example uses console and file handlers, but you can use any number and combination of handlers you choose.
Обработчик журналирования
Обработчик журналов — это компонент, который записывает и отображает логи. Например, StreamHandler выводит записи на консоль, FileHandler — в файл, SMTPHandler отправляет на электронную почту.
В каждом обработчике есть два важных поля:
- Форматер, добавляющий в лог контекстную информацию.
- Уровень лога, который отфильтровывает журналы низшего уровня. Обработчик уровня INFO не будет работать с журналами уровня DEBUG.
Стандартная библиотека содержит обработчики, которых в большинстве случаев должно быть достаточно. Самые распространённые — StreamHandler и FileHandler .
Using concurrent.futures.ProcessPoolExecutor¶
If you want to use concurrent.futures.ProcessPoolExecutor to start your worker processes, you need to create the queue slightly differently. Instead of
Обратите внимание, что параметры logging.basicConfig() должны передаваться до первого вызова функций ведения журнала. Если в консоли интерпретатора уже была вызвана хотя бы одна функция, то необходимо перезагрузить пакет logging или выйти и снова зайти в консоль интерпретатора. С версии Python-3.8 для этой цели можно использовать ключевой аргумент force=True
Logging from multiple threads¶
Logging from multiple threads requires no special effort. The following example shows logging from the main (initial) thread and another thread:
When run, the script should print something like the following:
This shows the logging output interspersed as one might expect. This approach works for more threads than shown here, of course.
Ротация логов.
При записи событий регистратора в файл иногда необходимо, чтобы размер файла журнала не рос бесконечно, а увеличился до определенного размера, после чего открывался новый файл для записи логов. Возможно, еще необходимо будет хранение определенного количество таких файлов, а при достижении этого количества возобновлялась запись в лог-файл, который создался первым. Для такого шаблонного поведения пакет logging предоставляет обработчик с именем logging.handlers.RotatingFileHandler() :
Если необходима ротация логов не по объему файла, а по времени накопления событий, например 24 часа, то можно использовать обработчик с именем logging.handlers.TimedRotatingFileHandler() :
Ведение логов из нескольких модулей и использование нескольких обработчиков.
Многократные вызовы logging.getLogger('someLogger') возвращают ссылку на один и тот же объект logger . Это верно не только в пределах одного и того же модуля, но и между модулями, если он находится в одном и том же процессе интерпретатора Python. Так же это поведение распространяется для ссылок на один и тот же объект.
Код приложения может определять и настраивать корневой регистратор в одном модуле и создавать, но не настраивать дочерний регистратор в отдельном модуле, и все вызовы регистратора для дочернего объекта будут передаваться родительскому.
Код основного модуля:
Код импортируемого модуля.
Вывод будет выглядеть так:
Возможность создания новых обработчиков с фильтрами более высокой или более низкой важности может быть очень полезна при написании и тестировании приложения. Вместо использования функций print() для отладки используйте метод logger.debug() : в отличие от операторов print() , которые придется удалить или закомментировать позже, функции logger.debug() могут оставаться нетронутыми в исходном коде и оставаться неактивными, пока они вам не понадобятся снова. Единственное изменение, которое необходимо сделать - это изменить уровень логирования и/или обработчика для отладки.
Sending and receiving logging events across a network¶
Let’s say you want to send logging events across a network, and handle them at the receiving end. A simple way of doing this is attaching a SocketHandler instance to the root logger at the sending end:
At the receiving end, you can set up a receiver using the socketserver module. Here is a basic working example:
First run the server, and then the client. On the client side, nothing is printed on the console; on the server side, you should see something like:
Note that there are some security issues with pickle in some scenarios. If these affect you, you can use an alternative serialization scheme by overriding the makePickle() method and implementing your alternative there, as well as adapting the above script to use your alternative serialization.
Using LoggerAdapters to impart contextual information¶
An easy way in which you can pass contextual information to be output along with logging event information is to use the LoggerAdapter class. This class is designed to look like a Logger , so that you can call debug() , info() , warning() , error() , exception() , critical() and log() . These methods have the same signatures as their counterparts in Logger , so you can use the two types of instances interchangeably.
When you create an instance of LoggerAdapter , you pass it a Logger instance and a dict-like object which contains your contextual information. When you call one of the logging methods on an instance of LoggerAdapter , it delegates the call to the underlying instance of Logger passed to its constructor, and arranges to pass the contextual information in the delegated call. Here’s a snippet from the code of LoggerAdapter :
The process() method of LoggerAdapter is where the contextual information is added to the logging output. It’s passed the message and keyword arguments of the logging call, and it passes back (potentially) modified versions of these to use in the call to the underlying logger. The default implementation of this method leaves the message alone, but inserts an ‘extra’ key in the keyword argument whose value is the dict-like object passed to the constructor. Of course, if you had passed an ‘extra’ keyword argument in the call to the adapter, it will be silently overwritten.
The advantage of using ‘extra’ is that the values in the dict-like object are merged into the LogRecord instance’s __dict__, allowing you to use customized strings with your Formatter instances which know about the keys of the dict-like object. If you need a different method, e.g. if you want to prepend or append the contextual information to the message string, you just need to subclass LoggerAdapter and override process() to do what you need. Here is a simple example:
which you can use like this:
Then any events that you log to the adapter will have the value of some_conn_id prepended to the log messages.
Using objects other than dicts to pass contextual information¶
You don’t need to pass an actual dict to a LoggerAdapter - you could pass an instance of a class which implements __getitem__ and __iter__ so that it looks like a dict to logging. This would be useful if you want to generate values dynamically (whereas the values in a dict would be constant).
Диспетчер журналирования
Вероятно, диспетчер журналирования — то, что используется в коде чаще всего, и в то же время является источником наибольших трудностей. Новый диспетчер журналирования можно создать следующим образом:
В диспетчере три основных поля.
- Распространение. Определяет, должен ли лог обрабатываться родительским диспетчером (по умолчанию эта функция активна).
- Уровень. Как и в обработчике, уровень отфильтровывает менее важные журналы. Отличие заключается в том, что уровень проверяется только в дочерних диспетчерах, при распространении вверх уровень не учитывается.
- Список обработчиков, в которые направляется попавшая в диспетчер запись. Он позволяет гибко настраивать обработку записей. К примеру, можно создать обработчик, записывающий всё с уровнем DEBUG , и обработчик для электронной почты, работающий только с уровнем CRITICAL . Взаимоотношения диспетчера с обработчиками строятся по принципу издатель-потребитель. Запись передаётся всем обработчикам, как только пройдёт проверку уровня в диспетчере.
Имя диспетчера уникально, таким образом, если диспетчер с именем «toto» уже создан, последующие вызовы logging.getLogger("toto") будут возвращать один и тот же объект.
Как можно догадаться, диспетчеры выстраиваются в соответствии с иерархией. На вершине находится корневой диспетчер, получить доступ к которому можно с помощью logging.root() . Он вызывается при использовании методов, подобных logging.debug() . По умолчанию корневому журналу присваивается уровень WARN , поэтому каждый журнал с меньшим уровнем (например logging.info("info") ) игнорируется. Кроме того, обработчик по умолчанию для корневого диспетчера создаётся автоматически, когда добавляется первая запись в журнал уровня выше WARN . Не рекомендуется обращаться к корневому диспетчеру прямо или косвенно с помощью методов, подобных logging.debug() .
При создании нового диспетчера в качестве родительского будет установлен корневой.
Диспетчер использует «запись с точкой», то есть объект с именем «a.b» будет дочерним по отношению к «a». Однако это правило действительно только при существовании «a», иначе родительским всё равно будет корневой диспетчер.
Когда диспетчер определяет, что запись проходит фильтр по уровню (если уровень лога ниже уровня диспетчера, запись игнорируется), применяется не действительный, а эффективный уровень. Эффективный уровень обычно равен уровню диспетчера, однако при этом уровень NOTSET является исключением. В таком случае эффективный уровень будет равен уровню первого диспетчера, расположенного выше в вертикали наследования, уровень которого не равен NOTSET .
По умолчанию уровень нового диспетчера NOTSET , и, поскольку уровень корневого равен WARN , то и эффективный уровень нового будет WARN . Таким образом, если даже к новому диспетчеру прикреплены обработчики, они не вызываются, если уровень лога не превышает WARN.
Уровень диспетчера используется по умолчанию для пропуска записи, которая будет проигнорирована, если её уровень недостаточно высок.
Logging to a single file from multiple processes¶
Although logging is thread-safe, and logging to a single file from multiple threads in a single process is supported, logging to a single file from multiple processes is not supported, because there is no standard way to serialize access to a single file across multiple processes in Python. If you need to log to a single file from multiple processes, one way of doing this is to have all the processes log to a SocketHandler , and have a separate process which implements a socket server which reads from the socket and logs to file. (If you prefer, you can dedicate one thread in one of the existing processes to perform this function.) This section documents this approach in more detail and includes a working socket receiver which can be used as a starting point for you to adapt in your own applications.
Alternatively, you can use a Queue and a QueueHandler to send all logging events to one of the processes in your multi-process application. The following example script demonstrates how you can do this; in the example a separate listener process listens for events sent by other processes and logs them according to its own logging configuration. Although the example only demonstrates one way of doing it (for example, you may want to use a listener thread rather than a separate listener process – the implementation would be analogous) it does allow for completely different logging configurations for the listener and the other processes in your application, and can be used as the basis for code meeting your own specific requirements:
A variant of the above script keeps the logging in the main process, in a separate thread:
This variant shows how you can e.g. apply configuration for particular loggers - e.g. the foo logger has a special handler which stores all events in the foo subsystem in a file mplog-foo.log . This will be used by the logging machinery in the main process (even though the logging events are generated in the worker processes) to direct the messages to the appropriate destinations.
Практические советы
Модуль журналирования весьма полезен, однако некоторые его особенности могут вызвать головную боль даже у опытных разработчиков. Есть несколько практических советов по применению этого модуля.
This page contains a number of recipes related to logging, which have been found useful in the past.
Running a logging socket listener in production¶
To run a logging listener in production, you may need to use a process-management tool such as Supervisor. Here is a Gist which provides the bare-bones files to run the above functionality using Supervisor: you will need to change the /path/to/ parts in the Gist to reflect the actual paths you want to use.
Основные концепции журналирования на Python
В данном разделе рассмотрим уровни журналирования, форматирование журналов, обработчики и диспетчер журналирования.
Логирование событий из нескольких модулей.
Если программа состоит из нескольких модулей, вот пример того, как можно организовать код:
Если запустить файл app.py , то в myapp.log увидим следующее:
Добавление значений переменных в описание события использует форматирование строк в стиле printf . Такое поведение в модуле logging сохранено для обратной совместимости. С версии Python-3.2 класс logging.Formatter() получил ключевой аргумент style='%' , при помощи которого можно установить спецификации форматирования '
Этот запишет в файл example.log следующее:
Для простого использования модуля достаточно использования таких атрибутов как levelname (серьезность), message (описание события, включая данные переменных) и возможно понадобится отображение времени, когда произошло событие.
Чтобы отобразить дату и время события, необходимо поместить атрибут %(asctime)s в строку формата:
Код выше выведет в файл example.log следующее:
Формат отображения даты и времени по умолчанию подобен ISO8601 или RFC 3339. Если нужен больший контроль над форматированием даты и времени, то необходимо использовать аргумент datefmt для класса начальной настройки модуля logging.basicConfig() , как в этом примере:
Теперь в файл example.log можно увидеть запись:
Формат аргумента datefmt такой же, как поддерживается функцией time.strftime() .
Уровни журналирования
Уровни журналирования соотносятся с важностью лога: запись об ошибке должна быть важнее предупреждения, а отладочный журнал должен быть полезен только при отладке приложения.
В Python существует шесть уровней лога. Каждому уровню присвоено целое число, указывающее на важность лога: NOTSET=0, DEBUG=10 , INFO=20 , WARN=30 , ERROR=40 и CRITICAL=50 .
Ведение журнала из нескольких потоков.
Ведение журнала из нескольких потоков не требует особых усилий. В следующем примере показано ведение журнала из основного потока mail и потока Thread-1 :
При запуске скрипт должен напечатать что-то вроде этого:
Вывод логов на консоль показывает, что выходные данные журнала перемещаются, как и следовало ожидать. Этот подход работает для бОльшего количества потоков, чем здесь показано.
Configuration server example¶
Here is an example of a module using the logging configuration server:
And here is a script that takes a filename and sends that file to the server, properly preceded with the binary-encoded length, as the new logging configuration:
Настройка регистратора из файла
Следующий код Python создает регистратор, обработчик и форматер, почти идентичные тем, что в приведенном выше примере, только конфигурацию будет брать из файла logging.conf :
Листинг файла конфигурации logging.conf
Печать или вывод в файл информации об исключениях и записей трассировки стека.
Логирование исключений с трассировкой стека.
Для того, что бы регистрировать перехваченные исключения с полной трассировкой стека, используйте функцию logging.exception() . Она подходит для кода, который может вызвать ряд исключений, которые например нельзя ожидать. И вместо того, чтобы завершить программу, можно записать информацию об ошибке и продолжить ее работу.
По умолчанию функция logging.exception() использует уровень журнала ERROR . Также для этих целей, можно использовать обычное функции регистрации событий, такие как logging.debug() , logging.info() , logging.warn() и т. д., только устанавливать значение аргумента exc_info=True :
Dealing with handlers that block¶
Sometimes you have to get your logging handlers to do their work without blocking the thread you’re logging from. This is common in web applications, though of course it also occurs in other scenarios.
A common culprit which demonstrates sluggish behaviour is the SMTPHandler : sending emails can take a long time, for a number of reasons outside the developer’s control (for example, a poorly performing mail or network infrastructure). But almost any network-based handler can block: Even a SocketHandler operation may do a DNS query under the hood which is too slow (and this query can be deep in the socket library code, below the Python layer, and outside your control).
One solution is to use a two-part approach. For the first part, attach only a QueueHandler to those loggers which are accessed from performance-critical threads. They simply write to their queue, which can be sized to a large enough capacity or initialized with no upper bound to their size. The write to the queue will typically be accepted quickly, though you will probably need to catch the queue.Full exception as a precaution in your code. If you are a library developer who has performance-critical threads in their code, be sure to document this (together with a suggestion to attach only QueueHandlers to your loggers) for the benefit of other developers who will use your code.
The second part of the solution is QueueListener , which has been designed as the counterpart to QueueHandler . A QueueListener is very simple: it’s passed a queue and some handlers, and it fires up an internal thread which listens to its queue for LogRecords sent from QueueHandlers (or any other source of LogRecords , for that matter). The LogRecords are removed from the queue and passed to the handlers for processing.
The advantage of having a separate QueueListener class is that you can use the same instance to service multiple QueueHandlers . This is more resource-friendly than, say, having threaded versions of the existing handler classes, which would eat up one thread per handler for no particular benefit.
An example of using these two classes follows (imports omitted):
which, when run, will produce:
Changed in version 3.5: Prior to Python 3.5, the QueueListener always passed every message received from the queue to every handler it was initialized with. (This was because it was assumed that level filtering was all done on the other side, where the queue is filled.) From 3.5 onwards, this behaviour can be changed by passing a keyword argument respect_handler_level=True to the listener’s constructor. When this is done, the listener compares the level of each message with the handler’s level, and only passes a message to a handler if it’s appropriate to do so.
Multiple handlers and formatters¶
Loggers are plain Python objects. The addHandler() method has no minimum or maximum quota for the number of handlers you may add. Sometimes it will be beneficial for an application to log all messages of all severities to a text file while simultaneously logging errors or above to the console. To set this up, simply configure the appropriate handlers. The logging calls in the application code will remain unchanged. Here is a slight modification to the previous simple module-based configuration example:
Notice that the ‘application’ code does not care about multiple handlers. All that changed was the addition and configuration of a new handler named fh.
The ability to create new handlers with higher- or lower-severity filters can be very helpful when writing and testing an application. Instead of using many print statements for debugging, use logger.debug : Unlike the print statements, which you will have to delete or comment out later, the logger.debug statements can remain intact in the source code and remain dormant until you need them again. At that time, the only change that needs to happen is to modify the severity level of the logger and/or handler to debug.
Содержание:
Форматирование журналов
Например, при форматировании записи «hello world»:
в логе она отобразится таким образом:
Примеры использования вывода на печать исключений и трассировки стека:
Пример наглядно демонстрирует различные способы печати исключения и обратной трассировки:
Пакет logging использует модульный подход и предлагает несколько категорий компонентов: регистраторы, обработчики, фильтры и форматеры.
- Регистраторы Logger предоставляют интерфейс, который непосредственно использует код приложения.
- Обработчики Handler отправляют записи журнала (созданные регистраторами) в соответствующий пункт назначения.
- Фильтры Filter предоставляют более точную возможность определить, какие записи журнала выводить.
- Форматтеры Formatter определяют расположение записей журнала в конечном выводе.
Using Filters to impart contextual information¶
You can also add contextual information to log output using a user-defined Filter . Filter instances are allowed to modify the LogRecords passed to them, including adding additional attributes which can then be output using a suitable format string, or if needed a custom Formatter .
For example in a web application, the request being processed (or at least, the interesting parts of it) can be stored in a threadlocal ( threading.local ) variable, and then accessed from a Filter to add, say, information from the request - say, the remote IP address and remote user’s username - to the LogRecord , using the attribute names ‘ip’ and ‘user’ as in the LoggerAdapter example above. In that case, the same format string can be used to get similar output to that shown above. Here’s an example script:
which, when run, produces something like:
Adding contextual information to your logging output¶
Sometimes you want logging output to contain contextual information in addition to the parameters passed to the logging call. For example, in a networked application, it may be desirable to log client-specific information in the log (e.g. remote client’s username, or IP address). Although you could use the extra parameter to achieve this, it’s not always convenient to pass the information in this way. While it might be tempting to create Logger instances on a per-connection basis, this is not a good idea because these instances are not garbage collected. While this is not a problem in practice, when the number of Logger instances is dependent on the level of granularity you want to use in logging an application, it could be hard to manage if the number of Logger instances becomes effectively unbounded.
Содержание:
- traceback.print_tb() -печать трассировки стека,
- traceback.print_exception() - печать исключения и трассировку стека,
- traceback.print_exc() - сокращение для вызова traceback.print_exception() ,
- traceback.print_last() - еще одно сокращение для вызова print_exception() ,
- traceback.print_stack() - печатает записи трассировки, начиная с точки вызова,
- traceback.format_exc() - похожа на traceback.print_exc(limit) но возвращает строку вместо печати, .
traceback.print_tb(tb, limit=None, file=None) :
Функция traceback.print_tb() если аргумент limit положительный, то печатает записи трассировки стека из объекта трассировки tb , ограничивая количество записей значением limit (начиная с кадра вызывающего абонента). В противном случае выводит последние записи abs(limit) .
- Если аргумент limit опущен или отсутствует, то печатаются все записи.
- Если аргумент файла file опущен или отсутствует, то вывод идет в sys.stderr .
- Если аргумент файла file задан, то для получения вывода он должен быть открытым файлом или файлоподобным объектом.
traceback.print_exception(etype, value, tb, limit=None, file=None, chain=True) :
Функция traceback.print_exception() выводит информацию об исключении и записи трассировки стека из объекта трассировки tb в файл.
- Если tb не равно None , то выводится заголовок Traceback (most recent call last): ,
- Функция печатает etype исключения и значение после трассировки стека,
- Если type(value) - это SyntaxError , а значение имеет соответствующий формат, то функция печатает строку, в которой произошла синтаксическая ошибка с символом вставки, указывающим приблизительное положение ошибки.
Необязательный аргумент limit имеет то же значение, что и в функции traceback.print_tb() .
Если аргумент chain=True (по умолчанию), то связанные исключения (атрибуты исключения __cause__ или __context__ ) также будут выведены, как это делает сам интерпретатор при печати необработанного исключения.
traceback.print_exc(limit=None, file=None, chain=True) :
Функция traceback.print_exc() представляет собой сокращенное название для вызова traceback.print_exception() и вызывается с параметрами:
Обратите внимание, что значение аргументов etype , value и tb функции traceback.print_exception() уже подставлены в виде вызова sys.exc_info() .
traceback.print_last(limit=None, file=None, chain=True) :
Функция traceback.print_last() представляет собой сокращенный для вызова traceback.print_exception() и вызывается с параметрами:
Как правило, функция будет работать только после того, как исключение достигнет интерактивной подсказки (подробнее смотрите описание sys.last_type ).
Обратите внимание, что значение аргументов etype , value и tb функции traceback.print_exception() уже подставлены в виде значений sys.last_type , sys.last_value и sys.last_traceback соответственно.
traceback.print_stack(f=None, limit=None, file=None) :
Функция traceback.print_stack() если limit является положительным, то печатает записи трассировки стека, начиная с точки вызова, ограничивая количество значением limit . В противном случае выводит на печать последние записи abs(limit) .
- Если аргумент limit опущен или отсутствует, то печатаются все записи.
- Необязательный аргумент f можно использовать для указания альтернативного кадра стека для запуска.
- Необязательный аргумент file имеет то же значение, что и для функции traceback.print_tb() .
traceback.format_exc(limit=None, chain=True) :
Функция traceback.format_exc() похожа на traceback.print_exc(limit) но возвращает строку вместо печати или сохранения в файл.
Продвинутая настройка логирования.
Создание регистраторов, обработчиков и форматтеров в явном виде с использованием кода Python, который вызывает методы конфигурации.
Запуск этого кода приведет к созданию файла 'example.log' с записями внутри:
Читайте также: