Skip to content

Instantly share code, notes, and snippets.

@churnikov
Last active April 11, 2022 14:31
Show Gist options
  • Save churnikov/0d31aac0263e5ed3650c8c2427504e4a to your computer and use it in GitHub Desktop.
Save churnikov/0d31aac0263e5ed3650c8c2427504e4a to your computer and use it in GitHub Desktop.
Loguru vs logging

Почему я думаю, что Loguru лучше Logging

Как говорится на главной странице Было ли вам когда-то лениво конфигурировать логгер и потому вы использовали print? У меня было так не раз. И используя loguru у вас нет причин не начинать сразу логировать.

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

TL;DR

Мне кажется, что коротко преимущества loguru описывает их оглавление:

  • Готов к использованию из коробки без шаблона;
  • No Handler, No Formatter, No Filter: one function to rule them all;
  • Простое использование файлов для логирования с ротированием / хранением / сжатием;
  • Современное форматирование строк с использованием фигурных скобок;
  • Дружит с потоками (Asynchronous, Thread-safe, Multiprocess-safe);
  • Красивое логирование с цветами;
  • Более качественное форматирование исключений;
  • Структурирование логирования по потребностям;
  • Ленивое выполнение дорогих функций;
  • Настраиваемые уровни логирования;
  • Лучшая обработка даты и времени;
  • Подходит для скриптов и библиотек;
  • Полностью совместим со стандартным logging;
  • Персонализируемые значения по умолчанию через переменные окружения;
  • Удобный парсер логов;
  • Исчерпывающие уведомления (может посылать логи практически куда угодно: хоть в телегу, хоть на почту используя notifiers);
  • В 10 раз быстрее, чем встроенная регистрация (будет когда-то, потому что они хотят кучу бэка переписать на C).

Лично мне нравится следующее:

Так что в итоге действительно нет причин не использовать его сразу.

Настройка логирования

TL;DR

Loguru работает из коробки и качественно, при этом, если есть потребность, то его легко настроить.

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

Logging

Может быть эти проблемы только у меня, но я не умею настраивать логирование в питоне. Я просто лезу в logging cookbook и тырю конфиг оттуда. Ибо он не работает из коробки:

Clipboard_2020-01-24-11-41-32

А вот конфиг

import logging

# create logger with 'spam_application'
logger = logging.getLogger('spam_application')
logger.setLevel(logging.DEBUG)
# create file handler which logs even debug messages
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)
# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
fh.setFormatter(formatter)
ch.setFormatter(formatter)
# add the handlers to the logger
logger.addHandler(fh)
logger.addHandler(ch)

logger.info('asdaasd')

Clipboard_2020-01-24-11-46-30

Clipboard_2020-01-24-11-46-47

При этом вы пробовали хоть раз настраивать логирование? У вас есть три варианта: dict config и конфигурация из кода. И как-то многие продвинутые гайды топят за dict config, но нигде нет нормального описания как им пользоваться. Ты учишься по примерам или копируешь чужие непонятные конфиги..

Опять же, мб проблемы только у меня, но мне кажется стандартным logging реально больно пользоваться.

loguru

Clipboard_2020-01-24-11-47-58

Clipboard_2020-01-24-11-49-58

Вот и все! 3 строчки против 13.

from loguru import logger
logger.add("spam.log")
logger.info("asdasdas")

Собственно это и было первым, что меня заинтересовало в loguru. После кучи раз копирования конфига логирования и logging cookbook, простой импорт логгера и его работа из коробки.. Мммм это ли не радость?

Но важно заметить, что по умолчанию loguru пишет в stderr, так что добавляется парочка строк, чтобы писать в stdout.

import sys

from loguru import logger
logger.remove() # Удаляет предыдущий логгер, т.е. то, что по умолчанию
logger.add(sys.stdout)
logger.info("asdasdas")

Разница по скорости

Обозначим сразу этот момент. Loguru медленнее logging в 2 раза.

logging

Clipboard_2020-01-24-12-24-09

loguru

Clipboard_2020-01-24-12-24-38

У всего есть своя цена и loguru проигрывает logging в 2 раза. Но тут речь про микросекунды ($10^{-6}$).

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

Использование в вэб приложениях

Думаю, что в целом всем известно, как использовать logging в приложении.

# Некий модуль
import logging

logger = logging.getLogger(__name__)

logger.info("adads")

Но вот беда, нам бы как-то настроить логирование в соответствии с соглашениями.

Раньше предлагалось использовать json-logging. В целом он норм, ключи пишет не так, как надо. А чтобы его настроить это надо лезть в его кишки, чего не очень хочется.

Как настроить json-logging под наш формат

import logging
import json
import traceback
from datetime import datetime
import copy
import json_logging
import sys

json_logging.ENABLE_JSON_LOGGING = True


def extra(**kw):
    '''Add the required nested props layer'''
    return {'extra': {'props': kw}}


class CustomJSONLog(logging.Formatter):
    """
    Customized logger
    """
    python_log_prefix = 'python.'
    def get_exc_fields(self, record):
        if record.exc_info:
            exc_info = self.format_exception(record.exc_info)
        else:
            exc_info = record.exc_text
        return {f'{self.python_log_prefix}exc_info': exc_info}

    @classmethod
    def format_exception(cls, exc_info):
        return ''.join(traceback.format_exception(*exc_info)) if exc_info else ''

    def format(self, record):
        json_log_object = {"@timestamp": datetime.utcnow().isoformat(),
                           "level": record.levelname,
                           "message": record.getMessage(),
                           "caller": record.filename + '::' + record.funcName
                           }
        json_log_object['data'] = {
            f'{self.python_log_prefix}logger_name': record.name,
            f'{self.python_log_prefix}module': record.module,
            f'{self.python_log_prefix}funcName': record.funcName,
            f'{self.python_log_prefix}filename': record.filename,
            f'{self.python_log_prefix}lineno': record.lineno,
            f'{self.python_log_prefix}thread': f'{record.threadName}[{record.thread}]',
            f'{self.python_log_prefix}pid': record.process
        }
        if hasattr(record, 'props'):
            json_log_object['data'].update(record.props)

        if record.exc_info or record.exc_text:
            json_log_object['data'].update(self.get_exc_fields(record))

        return json.dumps(json_log_object)


def logger_init():
    json_logging.__init(custom_formatter=CustomJSONLog)

# You would normally import logger_init and setup the logger in your main module - e.g.
# main.py

logger_init()

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
logger.addHandler(logging.StreamHandler(sys.stderr))

logger.info('Starting')
try:
    1/0
except: # noqa pylint: disable=bare-except
    logger.exception('You can\'t divide by zero')

Это пример с их страницы на гитхабе. Они имеют в виду, что тебе надо все это скопировать и добавить что тебе надо.

как сделать тоже самое, что делает json-logging с использованием loguru.

Для начала надо понять, что вообще может json-logging. Он может:

  • Генерить correlation_id. Когда в приложение поступает запрос, то для него генерируется уникальный идентификатор, и все логи потом пишутся в рамках этого запроса с этим correlation_id.
  • Оборачивать каждый запрос в json и добавлять мета инфу
  • Оборачивать каждое сообщение написанное logging в json со всей необходимой инфой.

Вся необходимая инфа, на самом деле, это следующие поля:

{
    "datetime": "2018-09-11T18:01:33+0300",
    "timestamp": 1536678093984,
    "level": "DEBUG | INFO | WARNING | ERROR | CRITICAL",
    "app": "app name",
    "msg": "..."
}

Для использования correlation_id в flask можно использовать объект g.

Чтобы логировать каждый запрос достаточно определить @after_request.

Чтобы писать логи в формате json и нужными ключами нужно написать следующее:

import json
import traceback as tb
from datetime import datetime

from loguru import logger


def json_sink(message):
    record = message.record
    data = {
        "datetime": record["time"].astimezone().strftime('%Y-%m-%dT%H:%M:%S%z'),
        "timestamp": int(datetime.timestamp(record["time"])),
        "level": record["level"].name,
        "app": "app name",
        "msg": record["message"],
        "module": record["module"],
        "function": record["function"],
        "line": record["line"]
    }
    if record["extra"]:
        data["extra"] = record["extra"]
    if record["exception"] is not None:
        data["exception"] = "".join(tb.format_exception(*record["exception"]))
    print(json.dumps(data))

logger.remove()
logger.add(json_sink)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment