Python-сообщество

Есть достаточно большой проект. много модулей, коммандлайн скрипты, демоны, django UI. Хочется сделать гибкое логирование всего и вся с возможностью конфигурирования не лазая в код. Может у кого-нибудь уже это решено и этот кто-нибудь поделится правильным концептом?

Пока общее направление мыслей такое: использовать logging с иерархией логгеров/хэндлеров/форматтеров, описаных в конфиге, загружаемом приложениями с помощью fileConfig(). Но хотелось бы реальный пример такого подхода для (желательно) аналогичного проекта.

примерно так и делали.
Единственно замечание - имена логеров.
Похоже, порядок есть только при одной схеме: имена должны совпадать с полным путем к классу объекта.
Т.е. если есть класс A в модуле pack.subpack.mod, имя модуля должно быть ‘pack.subpack.mod.A’. Это легко автоматизировать написав свой дескриптор.
Можно использовать в качестве имен просто полные пути к модулям, если классов в них немного.
При произвольном именовании начинается форменный бедлам.

Я бы посоветовал пользовать метаклассы для прикрутки логирования к функциям.

class MetaLogging(type):
    def __call__(cls, *args, **kargs):
        for attr in dir(cls):
            value = getattr(cls, attr)
            if isinstance(value, MethodType):
                if attr.startswith('__'):
                    setattr(cls, attr, trace(value))
                elif attr.startswith('_'):
                    setattr(cls, attr, debug(value))
                else:
                    setattr(cls, attr, info(value))
        return super(MetaLogging, cls).__call__(*args, **kargs)

Ээээ. А что ваши trace-debug-info будут делать? Т.е. какая с них польза?

Для автоматической прикрутки декораторов.
простой пример функции:

def debug(func):
    def _logFunctionCall(*args,**kwargs):
        log.debug("%s(%s, %s)" % (func.func_name, args, kwargs))
        return func(*args, **kwargs)
    return _logFunctionCall

Ага. Положим, декораторы я писать умею.
Следующий вопрос: а что мне делать с этой простыней - кто кого вызвал и с какими параметрами?
Вы для чего вообще логи используете?

Мы используем логи для истории. Истории того, как там все было, какой поток чего когда вызывал и все такое. Мне кажется это полезно, вот на каком уровне такое логировать - это вопрос.

Если уж на то пошло: а Вы зачем логи пишите?

Вопрос хороший. И непростой.
Логировать все вызовы подряд не приходилось. Да и зачем? Если уж очень нужно - есть settrace, которая может записать все вызовы.
На тех проектах, где я участвовал - хватало стандартного профайлера, чтобы увидеть кто ест время.
Длинная простыня логов, по моему скромному мнению, в этом не поможет.

В логи нужно писать то, что потом будут читать люди. Скорее, им будет интересно, что код сначала не смог, к примеру, получить данные из тернета по ошибке, которая прилагается - а затем поток успешно помер. Или еще что-нибудь странное.
И эти записи лежат _внутри_ функций-методов, лог пишется тогда, когда это именно нужно.
Даже в режиме дебага не стоит писать все подряд. Есть, наверное, гении - но я не могу внятно прочитать простыню вызовов и найти в ней поломку - когда простыня на несколько мегабайтов (это я еще скромно сказал - видел разные логи).

Итак, простая схема, выработанная практикой.

Источник логов совпадает с полным путем к коду, который пишет в лог.
Сначала - не логируем ничего. Ну кроме самых напрашивающихся кандидатов - типа к БД подключится не получилось, ошибка прилагается.
Дальше - по нужде. Возник вопрос, как себя повела система при крахе или нестандартном поведении - добавляем логи. Разносим их по уровням - debug или таки error.

Кажется, в любом большом проекте так делают. Только, наверное, не описывают процесс - я ни разу не видел, приходилось доходить самому.

Логи - для того чтобы их читали люди. А человеки - не монстры. Поэтому логи должны быть по возможности лаконичными. Баланс вырабатывается для каждого проекта заново. Но логировать все подряд - априорно моветон.

ЗЫ. Обращение на ВЫ - это просто потому, что мы не знакомы. Мне кажется, что так будет вежливей.

У нас пока получилась такая схема:
Был написан простенький project.logging.getLogger(name), который при вызове из __main__ читает конфигурацию из /etc/project/logging.conf, ~/.project/logging.conf и /etc/project/%(name)s-logging.conf при наличии оных. Ну и возвращает логгер для запрашиваемого имени, естественно. Есть также configure_logging, которому конфиг файл можно передать, если нужно.
В каждом модуле пишем LOG = getLogger(__name__) и потом эту глобальную переменную юзаем где нужно. Мне наличие глобальной переменной не очень нравится, но альтернативы, которые я вижу, еще хуже. В классах в __init__ можно делать self.logger = getLogger(self.__module__), либо юзать глобальный LOG, так же, как и в других местах. Была идея нарисовать mixin Loggable для классов и декоратор loggable для функций, которые должны были добавлять logger в namespace объекта или функции соответственно, но подумавши не стал этого делать. explicit is better than implicit.
Что скажете?

PS: Андрей, можно про дескриптор поподробнее?

Отредактировано (Ноя. 10, 2010 20:47:02)

про дескриптор была древняя статья http://www.developers.org.ua/archives/asvetlov/2007/09/22/python-logging/

Глобальные логеры - это нормально. Они такие по определению - потому что все равно регистрируются в глобальной структуре внутри logging.

Использующий логирование код не должен этот логер настраивать. Получил и пиши в него - и все.

Настройка - отдельное дело. Осуществляется на старте приложения, а не на импорте библиотеки. Так правильно - и заодно избавляет от неприятных ситуаций.
Например, когда для одного пользователя библиотеки нужна одна конфигурация, а для другого - иная. Это могут быть две разные программы, юниттесты и т.д.
С ненастроенными логерами такой проблемы нет.

Настройка делается по именам логеров, так что импортировать библиотечный код не нужно.