Журналирование ошибок приложения на Flask

Перевод статьи: Logging Application Errors

Новинка версии 0.3.

В приложениях и серверах иногда происходят ошибки. Рано или поздно вы увидите исключение на сервере в эксплуатации. Даже если ваш код на 100% правильный, вы всё равно будете время от времени видеть исключения. Почему? Потому что может сломаться что-то другое. Вот некоторые ситуации, в которых совершенный код может приводить к ошибкам на сервере:

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

И это только небольшой список причин, который можно продолжить. Как же справляться с проблемами такого рода? По умолчанию, если приложение запущено в рабочем режиме, Flask покажет очень простую страницу и занесёт исключение в журнал.

Но для обработки ошибок можно сделать и больше, если задать соответствующие настройки.

Письма об ошибках

Если приложение запущено на сервере в эксплуатации, по умолчанию не желательно показывать сообщения об ошибках. Почему? Flask пытается быть фреймворком, не требующим настройки. Куда он должен складывать сообщения об ошибках, если это не указано в настройках? Автоматически выбранное место может не подойти, потому что у пользователя может не быть прав на создание журналов в этом месте. К тому же, в большинстве никто не станет читать журналы небольших приложений.

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

Flask использует встроенную систему журналирования Python, и действительно может отправлять письма об ошибках, чем вы можете воспользоваться. Вот как можно настроить систему журналирования Flask для отправки писем об исключениях:

ADMINS = ['yourname@example.com']

if not app.debug:
    import logging
    from logging.handlers import SMTPHandler
    mail_handler = SMTPHandler('127.0.0.1',
                               'server-error@example.com',
                               ADMINS, 'Сбой в приложении')
    mail_handler.setLevel(logging.ERROR)
    app.logger.addHandler(mail_handler)

Что это даст? Мы создали новый обработчик SMTPHandler, который отправит письма через почтовый сервер с IP-адресом 127.0.0.1 на все адреса из ADMINS с адреса server-error@example.com и с темой "Сбой в приложении". Если почтовый сервер требует авторизации, можно указать необходимые для неё данные. За информацией о том, как это сделать, обратитесь к документации на SMTPHandler.

Мы также сообщили обработчику, что он должен отправлять письма только об ошибках или более важных сообщениях, потому что нам явно не нужны письма о предупреждениях или других бесполезных записях в журнале, которые могут появиться в процессе обработки запроса.

Перед тем, как применить эти настройки на сервере в эксплуатации, обратитесь к разделу Управление форматом журнала ниже, чтобы в письма помещалась необходимая информация и вы не растерялись, получив письмо.

Журналирование в файл

Даже если вы получили письмо, вам скорее всего захочется посмотреть и на предупреждения в журнале. Хорошо бы сохранить как можно больше информации, полезной для отладки проблемы. Отметим, что ядро Flask само по себе не выдаёт предупреждений, поэтому вам самим нужно позаботиться о том, чтобы генерировать предупреждения в вашем коде, в случае если что-то пошло не так.

Эта пара обработчиков поставляется в комплекте с системой журналирования, но не каждый из них подходит для начального журналирования ошибок. Наиболее интересными могут показаться следующие:

• FileHandler - ведёт журнал ошибок в файле.
• RotatingFileHandler - ведёт журнал ошибок в фале и создаёт новый файл после определённого количества сообщений.
• NTEventLogHandler - использует системный журнал событий Windows. Может пригодиться при развёртывании приложения на Windows-компьютере.
• SysLogHandler - отправляет сообщения в syslog, системный журнал UNIX.

Как только вы подберёте подходящий обработчик журнала, можете настроить обработчик SMTP из примера выше. Просто убедитесь в том, что снизили порог критичности сообщений (я рекомендую WARNING):

if not app.debug:
    import logging
    from themodule import TheHandlerYouWant
    file_handler = TheHandlerYouWant(...)
    file_handler.setLevel(logging.WARNING)
    app.logger.addHandler(file_handler)

Управление форматом журнала

По умолчанию обработчик будет лишь записывать строку с сообщением в файл или отправлять эту строку по почте. Записи журнала содержат больше информации и стоит настроить обработчик так, чтобы он содержал больше полезной информации, по которой можно понять, что случилось и, что более важно, где это произошло.

Средство форматирования можно настроить при помощи строки формата. Отметим, что отчёт о трассировке добавляется к записи в журнале автоматически, для этого не требуется каких-то специальных настроек в строке формата.

Вот примеры настройки:

Журналирование на почту

from logging import Formatter
mail_handler.setFormatter(Formatter('''
Message type: %(levelname)s
Location: %(pathname)s:%(lineno)d
Module: %(module)s
Function: %(funcName)s
Time: %(asctime)s
Message:
%(message)s
'''))

Журналирование в файл

from logging import Formatter
file_handler.setFormatter(Formatter(
'%(asctime)s %(levelname)s: %(message)s '
'[in %(pathname)s:%(lineno)d]'
))

Сложное форматирование журналов

Вот список полезных переменных форматирования для подстановки в строку формата. Отметим, что этот список не полный, полный список можно найти в официальной документации пакета журналирования.

Формат	Описание
%(levelname)s	Уровень серьёзности сообщения ('DEBUG' - отладочное, 'INFO' - информационное, 'WARNING' - предупреждение, 'ERROR' - ошибка, 'CRITICAL' - критичное).
%(pathname)s	Полный путь к файлу с исходным текстом, из которого была вызвана функция журналирования (если доступен).
%(filename)s	Имя файла с исходным текстом.
%(module)s	Модуль (часть имени файла).
%(funcName)s	Имя функции, из который была вызвана функция журналирования.
%(lineno)d	Номер строки в файле исходного текста, в которой произошёл вызов функции журналирования (если доступна).
%(asctime)s	Время создания записи в журнале в человеко-читаемом виде. По умолчанию используется формат "2003-07-08 16:49:45,896" (числа после запятой - это миллисекунды). Можно изменить путём создания класса-наследника от formatter и заменой метода formatTime().
%(message)s	Журнальное сообщение, полученное из выражения msg % args

Если вы хотите выполнить тонкую настройку форматирования, нужно создать класс-наследник от formatter. formatter имеет три полезных метода:

format():

• Занимается собственно форматированием. Принимает объект LogRecord и возвращает отформатированную строку.

formatTime():

• Вызывается для форматирования asctime. Если нужно задать другой формат времени, можно заменить этот метод.

formatException():

• Вызывается для форматирования исключений. Принимает кортеж exc_info и возвращает строку. В большинстве случаев подойдёт метод по умолчанию, поэтому скорее всего вам не потребуется его заменять.

За более подробной информацией обратитесь к официальной документации.

Другие библиотеки

Таким образом мы настроили журналирование событий, порождаемых самим приложением. Другие библиотеки могут вести собственный журнал. Например, SQLAlchemy широко использует журналирование в собственном ядре. Хотя этот способ пригоден для настройки сразу всех средств журналирования в пакете logging, пользоваться им не рекомендуется. Может возникнуть ситуация, когда нужно различать приложения, работающие в пределах одного интерпретатора Python, но будет невозможно сделать для них отдельные настройки журналирования.

Вместо этого рекомендуется выяснить, какие средства журналирования нужны, получить их с помощью функции getLogger() и перебрать все присоединённые к ним обработчики:

from logging import getLogger
loggers = [app.logger, getLogger('sqlalchemy'),
           getLogger('otherlibrary')]

for logger in loggers:
    logger.addHandler(mail_handler)
    logger.addHandler(file_handler)

Отладка ошибок приложения

Для приложений в эксплуатации настройте журналирование и уведомления так, как описано в разделе Журналирование ошибок приложения. Этот раздел предоставит указания для отладки конфигурации развёртывания и более глубокого исследования с использованием полнофункционального отладчика Python.

В случае сомнений запускайте вручную

Возникли проблемы с настройкой приложения в эксплуатации? Если имеется доступ к командной строке на сервере, проверьте, можете ли вы запустить приложение вручную из командной строки в режиме разработки. Убедитесь, что запустили его под той же учётной записью, под которой оно установлено, чтобы отследить ошибки, связанные с неправильной настройкой прав доступа. Можете воспользоваться встроенным во Flask сервером разработки, передав ему аргумент debug=True на сервере эксплуатации, что может помочь в отлове проблем с настройками, но убедитесь, что делаете это временно в управляемом окружении. Не запускайте приложение в эксплуатацию с аргументом debug=True.

Работа с отладчиками

Для более глубокого исследования можно выполнить трассировку кода. Flask содержит отладчик в стандартной поставке (смотрите Режим отладки). Если вам нравится пользоваться другим отладчиком Python, учтите, что они могут мешать друг другу. Можно указать несколько опций, чтобы использовать ваш любимый отладчик:

• debug - указывает, нужно ли включить режим отладки и захват исключений.
• use_debugger - указывает, нужно ли использовать отладчик, встроенный во Flask.
• use_reloader - указывает, нужно ли перезагружать и перезапускать процесс, если произошло исключение.

Опция debug должна иметь значение True (то есть, исключения должны захватываться), для того чтобы учитывались две следующие опции.

Если вы используете Aptana/Eclipse для отладки, вам нужно установить обе опции use_debugger и use_reloader в False.

Возможно, лучшие всего настроить эти опции в файле config.yaml (измените блок, так как вам нужно):

FLASK:
    DEBUG: True
    DEBUG_WITH_APTANA: True

В точке входа в ваше приложение (main.py), нужно написать что-то вроде этого:

if __name__ == "__main__":
    # Чтобы разрешить aptana получать ошибки, задайте use_debugger=False
    app = create_app(config="config.yaml")
    if app.debug: use_debugger = True
    try:
        # Отключаем отладчик Flask, если запрошено использование внешнего отладчика
        use_debugger = not(app.config.get('DEBUG_WITH_APTANA'))
    except:
        pass
    app.run(use_debugger=use_debugger, debug=app.debug,
            use_reloader=use_debugger, host='0.0.0.0')

Примечания переводчика

Этот и другие переводы можно найти на сайте проекта перевода документации по Flask. Автор проекта - Виталий Кузьмин aka ferm32.