Логирование в Питоне
Логирование является важной частью разработки. То, что правильно построенные логи сильно облегчают отладку и дальнейшее сопровождение проекта — сейчас, кажется, неоспоримая истина и общее место.
В Питоне существуют несколько способов делать это. Простейший — выводить всю необходимую информацию через print. Достоинства очевидны — простота. Недостатки тоже — отсутствие гибкости в настройках.
Поэтому появилось довольно много библиотек для решения этой проблемы. Я не буду даже пытаться их перечислять, остановлюсь на стандартном пакете logging. Он весьма мощен, допускает гибкую настройку, иерархические категории, вывод логов в любой мыслимый источник, указание желаемого форматирования сообщений. И, главное, logging — это стандарт, включенный в любую поставку Питона. Архитектурно он вырос из знаменитого log4j (Apache Group), который имеет множество клонов на других языках программирования.
Я не буду описывать тривиальные шаги по настройке logging системы и выводу простейших логов. Все это можно прочитать в стандартной документации модуля logging и ее части, посвященной простому примеру использования.
Перейду к опыту применения. Первый же вопрос, который возникает — как отличать записи из разных мест. Поясню на примере.
# module sample_mod
import logging
def a():
logging.debug("I'm here")
...
def b():
logging.debug("I'm here")
...
Совершенно непонятно, кто источник сообщения. Конечно, можно настроить формат так, что будет указан полный путь к файлу и номер строки в нем, но это сильно загромождает вывод. Писать с явным указанием источника:# module sample_mod
def a():
logging.debug("sample_mod:a - I'm here")
...
тоже не хочется. К счастью, сразу же на ум приходят иерархически организованные логеры. В нашем случае они создаются через вызов функции getLogger. Поскольку я пишу с интенсивным использованием ООП, дальнейшие примеры будут строиться на классах, а не функциях. Попытаемся создать класс A, в котором заведем для логера: один для класса целиком, второй для отдельной инстанции.# module sample_mod
class A(object):
cls_logger = logging.getLogger('sample_mod.A')
def __init__(self):
self.inst_logger = logging.getLogger('sample_mod.A.0x%008x'%id(self))
...
def f(self):
self.cls_logger.debug("class logger message")
def g(self):
self.inst_logger.debug("instance logger message")
Отлично. Теперь мы можем писать что-то вроде:>>> a = A()
>>> a.f()
DEBUG:sample_mod.A:class logger message
>>> a.g()
DEBUG:sample_mod.A.0x009fb650:class logger message
Вроде бы все хорошо, но есть пара «но». Первое очевидно — нужно явно указывать имя логера, хотя оно собирается из имени модуля, имени класса (и адреса инстанции для второго случая). Все это можно спросить у Питона, но вот незадача — если в конструкторе все уже есть и мы можем просто написатьself.inst_logger = logging.getLogger('%s.%s.0x%008x'%(self.__class__.__module__, self.__class__.__name__,id(self)))
то при создании логера для класса спросить __class__ просто не у кого.
Есть еще одна проблема: поскольку не предусмотрено удаление логеров, то для каждого нового объекта делается новый, а старые продолжают жить. Мало того, что неограниченно растет память, так еще и создание занимает ощутимое количество времени. Я подсмотрел, как это делают в SQLAlchemy:
def _get_instance_name(instance):
return instance.__class__.__module__ + "." + instance.__class__.__name__ + ".0x.." + hex(id(instance))[-2:]
def instance_logger(instance):
return logging.getLogger(_get_instance_name(instance))
def class_logger(cls):
return logging.getLogger(cls.__module__ + "." + cls.__name__)
Что ж, довольно элегантно. Берем последние две цифры адреса. Различать экземпляры объектов вполне можно, а память расти не будет. Вполне подойдет. Пример модифицировался так:class A(object):
def __init__(self):
self.inst_logger = instance_logger(self)
...
A.cls_logger = class_logger(A)
Все почти хорошо. Только мне очень не нравится модифицирование класса после создания при добавлении cls_logger. Не потому, что считаю подобные действия абсолютным злом — наоборот, очень часто пользуюсь. Причина другая — легко не заметить этот код. Да и привык я описывать переменные класса в его начале. Мысль завертелась вокруг инструментирования кода. В который раз посетовав на отсутствие декораторов класса (не ждать же Python 2.6), начал строить все на метаклассах. Но с ними тоже все не хорошо. Во-первых, пришлось бы явно указывать метакласс или навязывать свой базовый. Во-вторых и главных: как только в предках появляется два разных метакласса, Питону становится нехорошо и он впадает в ступор. И, конечно же, в моем проекте это вылезло почти сразу. Я уже начал огорченно менять иерархию наследования, добавляя ненужные костыли, как вспомнил о дескрипторах. Решение оказалось очень простым:class class_logger(object):
'''Class logger descriptor'''
def __init__(self):
self._logger = None
def __get__(self, instance, owner):
if self._logger is None:
self._logger = logging.getLogger(owner.__module__ + "." + owner.__name__)
return self._logger
class instance_logger(object):
'''Instance logger descriptor'''
def __init__(self):
self._logger = None
def __get__(self, instance, owner):
if self._logger is None:
self._logger = logging.getLogger(_get_instance_name(instance))
return self._logger
а пример использования весьма лаконичным:class A(object):
cls_logger = class_logger()
inst_logger = instance_logger()
def __init__(self):
...
Преимущества очевидны: логер (как для класса, так и для объекта) описывается одной строкой, никаких дополнительных трюков не требуется, конструктор класса не содержит никакого дополнительного кода. К тому же все прекрасно видно, а параметрами для class_logger и instance_logger можно передавать какие-нибудь настроечные параметры. На этом стоит поставить точку и привести получившийся код целиком (он до смешного короток):# module logutils
import sys
import new
import logging
#copy public content of logging package
for name in dir(logging):
if not name.startswith('_'):
globals()[name] = getattr(logging, name)
def _get_instance_name(instance):
return instance.__class__.__module__ + "." + instance.__class__.__name__ + ".0x.." + hex(id(instance))[-2:]
class class_logger(object):
'''Class logger descriptor'''
def __init__(self):
self._logger = None
def __get__(self, instance, owner):
if self._logger is None:
self._logger = logging.getLogger(owner.__module__ + "." + owner.__name__)
return self._logger
class instance_logger(object):
'''Instance logger descriptor'''
def __init__(self):
self._logger = None
def __get__(self, instance, owner):
if self._logger is None:
self._logger = logging.getLogger(_get_instance_name(instance))
return self._logger
Все про українське ІТ в телеграмі — підписуйтеся на канал DOU
4 коментарі
Підписатись на коментаріВідписатись від коментарів Коментарі можуть залишати тільки користувачі з підтвердженими акаунтами.