Як (не) варто налаштовувати логування в Python

Привіт!

Мене звати Павло Шушков, я — Software Engineer у компанії Yalantis. Протягом останніх трьох років я працюю над проєктом американського необанку, де моя роль охоплює повний цикл розробки. Зокрема йдеться про співпрацю з бізнес-аналітиками та дизайнерами, розробку та підтримку проєкту, а також спілкування з фінансовими партнерами та платіжними мережами.

Моя робота дозволила мені глибше зрозуміти значення якісного логування, яке може полегшити роботу розробника, зменшити часові витрати й створити більш структуровані та зрозумілі дані для всієї команди.

У статті я розповідаю про роботу модуля logging в Python, а також розгляну ключові компоненти, які слід інтегрувати в логи. Матеріал буде корисним тим, хто бажає оптимізувати вже наявні методи й способи логування або ж налаштувати їх з нуля.

Досвід на моєму проєкті та чому я зіштовхнувся з логами

Проєкт тісно пов’язаний з операціями з платіжними картками, що зобов’язує нас дотримуватися стандарту PCI DSS (Payment Card Industry Data Security Standard). Стандарт встановлює вимоги до безпеки обробки платіжних даних, включаючи зберігання логів протягом певного періоду часу, захист даних картки, моніторинг і виявлення шахрайства, контроль доступу, захист від зловживань, а також вимоги до аудиту та звітності.

Крім того, обробка персональних даних (PII) та співпраця з великою кількістю сторонніх сервісів, робить логування невіддільною частиною нашої роботи.

Для наочності можна згадати приклад, коли до нас звернувся сапорт з тікетом, що клієнт замовив кредит скор-репорт, але не отримав його протягом п’яти годин — потрібно було якомога швидше впоратись із цією ситуацією. Пробігши очима кодом та проаналізувавши логи, ми ідентифікували причину: кредитне бюро змінило поведінку вебхуків, а саме: перенесло деякі поля та не попередило нас.

Виправлення було проведено оперативно, а також були виправлені всі зачеплені користувачі, висновки що цей кейс потрібно додати в моніторинг (це, до речі, також цікава тема для статті).

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

Зберігання великої кількості логів дозволяє нашій команді оперативно виявляти, аналізувати та усувати будь-яку неправильну поведінку в системі. Крім того, це надає можливість переглядати записи у минулому для переконання в тому, що з нашими клієнтами не відбулося нічого підозрілого, що підвищує рівень довіри до продукту.

Що таке логи та що використовують для створення логів в Python

Логи (логування) — це процес ведення та фіксації подій, дій або стану програми(або ж комп’ютерної системи) під час їх роботи.

У далекому липні 2003 році була випущена остаточна та стабільна версія Python 2.3. Поруч із такими нововведеннями, як функції sum та enumerate, були додані модулі для логування повідомлень:

• github.com/...​/Doc/whatsnew/2.3.rst#L26
• github.com/...​Doc/whatsnew/2.3.rst#L441.

Він є частиною PEP-282 та описує запропонований пакет логування для стандартної бібліотеки Python, де основною мотивацією виступає створення єдиного механізму логування з різними рівнями важливості повідомлень та різні логічні потоки логування (або «канали»).

Починаючи із цього моменту, можна стверджувати, що модуль logging стає основним для логування в python.

Чи можна замінити або покращити logging

Хоча теоретично можна замінити модуль logging на інші інструменти, я особисто ніколи не стикався з такою потребою та вважаю, що це не варто робити. Наявний модуль надає широкий спектр функціональних можливостей для логування, що зазвичай задовольняє потреби більшості проєктів.

Однак, давайте також подивимось на альтернативи:

1. Loguru — *17.7k github stars github.com/Delgan/loguru
2. Logbook — *1.5k github stars github.com/getlogbook/logbook
3. Structlog — *3.1k github stars github.com/hynek/structlog

* на день написання матеріалу.

Ці бібліотеки мають одну загальну мету: спростити та зробити логування більш елегантним. Вони пропонують різні шаблони та додаткові можливості, такі як асинхронне логування. У версії 3.2 Python було додано QueueHandler, що мав розв’язати проблеми з операціями введення/виведення для асинхронного логування, але не забезпечує повного вирішення. Тому існують різні підходи до розв’язання цієї проблеми.

Отже, додаткові бібліотеки для логування використовуються лише у випадках, коли вони необхідні або просто на власний розсуд розробника. У більшості проєктів вистачає використання модуля logging.

Базові знання по Python logging

Коротко пригадаймо, як працює модуль логування і який механізм його роботи.

Рівні логування

Якщо ми розглянемо файл logging/__init__.py, ми зможемо побачити, що існують наступні рівні логування:

CRITICAL = 50  
FATAL = CRITICAL  
ERROR = 40  
WARNING = 30  
WARN = WARNING  
INFO = 20  
DEBUG = 10  
NOTSET = 0 

Рівні логування в модулі logging визначають, які повідомлення будуть зафіксовані, а які проігноровані. Наприклад, якщо логер налаштований на рівень WARNING, це означає, що повідомлення з рівнем INFO будуть проігноровані, а повідомлення з рівнем ERROR будуть зафіксовані.

1. Loggers — відповідають за створення та запис логів та кожен з них має унікальне ім’я. Логери можуть утворювати ієрархію за допомогою крапки у їхніх іменах, наприклад, parent та parent.child відповідно. root логер використовується за замовчуванням та завжди є батьківським для всіх інших логерів.
2. Handlers — обробники ж отримують записи від логера та надсилають їх до визначених вихідних точок, таких як консоль, файли, сокети або інші системи логування. Вони відповідають за забезпечення того, що повідомлення логування справді потраплять у вказані місця.
3. Formatters — призначені для форматування записів логування перед їхнім надсиланням обробникам. Вони дозволяють налаштувати вигляд кожного повідомлення логування, включаючи додавання додаткової інформації, такої як час, рівень логування, ім’я логера тощо.

Під час записування логів, Logger передає LogRecord обробникам (Handlers), які своєю чергою використовують форматувальники (Formatters) для створення остаточного запису логу у вказаному форматі та направленні його до відповідного місця призначення, такого як консоль або файл.

Після цього короткого пояснення, якщо ви відчуваєте, що щось не зрозуміли, раджу прочитати та власноруч практикувати, використовуючи посилання.

Python Logging Best Practices OR Logs Must Have

Варто замислитись над логуванням в ідеалі на самому початку роботи над проєктом. І так, на це варто знайти час та умовно запровадити певну етику логування. Таке рішення полегшить роботу команді, забезпечить ефективне та зручне відстеження роботи коду та зробить роботу з проєктом зручною та прозорою.

Виникає необхідність мати можливість відновлення та аналізу конкретного кейсу у випадку інцидентів. Ділюся власним досвідом та набитими шишками, а також прикладами.

1. Перейти до форматування логів у формат JSON

Перше з чого потрібно почати — конвертування текстових логів у формат JSON. Це стандартна практика, і вона полегшує подальшу обробку та аналіз даних. Зазвичай, на більшості проєктах ці JSON-логи можуть бути легко інтегровані з різними системами моніторингу, такими як ELK, Datadog etc., що забезпечує зручний доступ до них, або хоча б архівувати їх у файли з ротацією, наприклад, AWS S3.

import json
import logging
from datetime import datetime

class JSONFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        return json.dumps(
            {
                "timestamp": datetime.now().isoformat(),
                "message": record.getMessage(),
                "level": record.levelname,
                "logger_name": record.name,
            },
        )

LOGGING = {
    "formatters": {
        "json": {
            "()": "utils.logging.utils.JSONFormatter",
        }
    },
    "handlers": {
        "default": {
            "level": "INFO",
            "class": "logging.StreamHandler",
            "formatter": "json",
        }
    },
    "loggers": {
        "default": {
            "handlers": ["default"],
            "level": "INFO",
            "propagate": False,
        },
    }
}

2. Використовувати кастомну функцію для логування

Використання власної функції для логування дозволяє централізувати всі налаштування щодо логування — рівень логування, формат запису та обробники логів в одному місці. До того ж це надає можливість легко додавати нові поля та додаткову інформацію у логи за необхідності.

def log(
    msg: str,
    level: int = logging.INFO,
    logger_name: str = settings.DEFAULT_LOGGER_NAME,
    **kwargs,
):
    logger = logging.getLogger(name=logger_name)
    logger.log(level=level, msg=msg, extra=kwargs)

3. Використовувати __name__ для getLogger()

Рекомендується передавати __name__ в параметр name, що дозволить автоматично використовувати ім’я поточного модуля. Це спростить процес розуміння та аналізу логів.

logger = logging.getLogger(__name__)

4. Обирайте осмисленні меседжі для логів

Під час створення повідомлень логування, слід надавати перевагу стислості та зрозумілості. Уникайте включення зайвих змінних у повідомленнях, оскільки це може ускладнити пошук та розуміння даних, як, наприклад {... "msg": "The user #{number} created an account #{acc_num}"} > {"msg": "Account has been created", "data": {"user_id": 1, "account_number": 1}

5. Уніфіковане поле для додаткової інформації

Для полегшення майбутнього пошуку та доступу до додаткової інформації рекомендується зберігати її у спеціальному полі під назвою data.

def log(
    msg: str,
    level: int = logging.INFO,
    logger_name: str = settings.DEFAULT_LOGGER_NAME,
    data: dict | None = None,
    **kwargs
):
    extra = kwargs.copy()
    logger = logging.getLogger(name=logger_name)
    if data:
        extra.update(data=data)

    logger.log(level=level, msg=msg, extra=extra)

6. Timestamp в форматі ISO-8601

Лог без таймштампу — не лог :) Використовуйте один загальновживаний формат дати й часу, ISO-8601, щоб забезпечити сумісність та однаковий підхід до роботи з логами у всьому проєкті. Це дозволить уникнути проблем при обробці та аналізі даних. Також варто одразу після зміни перевірити коректність та додатково покрити тестом.

class JSONFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        return json.dumps(
            {
                "timestamp": datetime.now().isoformat()
            }
        )

7. Додаємо та використовуємо Tags

Додавання тегів в логи є досить корисними, оскільки вони надають додаткового контексту.

def log(
    msg: str,
    level: int = logging.INFO,
    logger_name: str = settings.DEFAULT_LOGGER_NAME,
  tags: Sequence[str] | None = None,
    **kwargs,
):
    logger = logging.getLogger(name=logger_name)
  extra = kwargs.copy()
  if tags:
    extra.update(tags=tags)

    logger.log(level=level, msg=msg, extra=extra)

8. instance, application — прокидаємо через os env

Додавайте інформацію про назву застосунка (application), а також ідентифікатори контейнера (pod) та контейнера (container id) у логи для полегшення налагодження та аналізу.

Це особливо важливо для сучасних бекенд-застосунків, які можуть складатися з різних мікросервісів та бути розгорнутими на платформі k8s, де інформація про конкретний контейнер може бути корисною. Проте важливо враховувати, що такі дії можуть здійснюватися як з боку розробників, так і з боку DevOps.

9. Ідентифікатор користувача

Зберігайте ідентифікатор користувача (user_id) в запиті та додайте його до кожного логу. Це спрощує виявлення останніх дій користувача та можливих складнощів, з якими він міг зіштовхнутись. Якщо ви отримуєте веб хуки від інших сторонніх сервісів, рекомендується також додавати ідентифікатор користувача до запиту та логів.

10. trace_id — унікальний ідентифікатор запиту

Він допомагає у рідких кейсах розуміти, що насправді зі сторони клієнту було декілька запитів з різних девайсів. Можливо додавати навіть просто UUID для того, щоб можна було зібрати різні логи в рамках одного запиту від користувача. Можна використовувати open telemetry або data dog, проте я б обрав open telemetry.

11. Вимикач логів

Рекомендується використовувати вимикачі логів для конкретних частин програми, що може значно знизити кількість збережених логів та призводить до зменшення потреби у ресурсах для їхнього зберігання.

12. Правильно використовувати рівні логування

Домовитися на рівні команди про використання різних рівнів логування та уникнення зловживання рівнями ERROR та CRITICAL.

13. Використовувати додаткові дані

Прокидувати додаткові дані через параметр extra для збереження всіх необхідних та додаткових полів.

def log(
    msg: str,
    level: int = logging.INFO,
    **kwargs,
):
    logger = logging.getLogger(name=logger_name)
    logger.log(level=level, msg=msg, extra=kwargs)

14. Вхідні та вихідні запити до third party

Рекомендується забезпечувати зберігання логів при надсиланні та отриманні запитів до сторонніх сервісів з можливістю їхнього вимкнення. Це не лише сприяє полегшенню усунення неполадок, але й дозволяє ефективно відповідати на запити сторонніх служб щодо надання журналів з запитами та відповідями.

15. Створити загальний список логів за повідомленнями

Варто створити таблицю в Confluence зі стовпцями Message та Description, що містять детальні пояснення логів та дані, які надсилаються. Це дозволить усім швидко знаходити необхідну інформацію.

16. Анонімізувати чутливі дані та особисту ідентифікаційну інформацію (PII)

Важливо анонімізувати дані, які ми надсилаємо в логах, оскільки вони можуть містити чутливу інформацію або особисто ідентифіковані дані (PII). Зважаючи на те, як компанії звертають увагу на безпеку та кількість випадків зливання даних або неправомірного доступу до інформації з логів, стає очевидним, що для забезпечення безпеки необхідно уважно стежити за даними, які ми надсилаємо.

Існують багато різних методів анонімізації. Для початку можна використовувати метод маскування, щоб приховати всі дані та залишити лише останні чотири символи. У разі потреби варто витратити трохи часу на створення власних правил маскування для різних типів даних.

Наприклад, для електронної пошти можна застосувати такий підхід: замінити перші символи на «no****y@example.com». А для номерів телефонів: залишити перші три й останні одиниці, приховавши проміжні числа.

Підсумок

Варто підкреслити важливість приділення більшої уваги логуванню. Дотримуючись рекомендацій, ви отримаєте логи з більш чіткою структурою та зручним форматом, що значно спростить їхнє використання, пошук та аналіз.

P.S Це моя перша стаття на DOU. Якщо ви помітили помилку або маєте зауваження або рекомендацію, які не були враховані в статті, будь ласка, залиште коментар, і я з радістю внесу відповідні зміни.

Підписуйтеся на Telegram-канал «DOU #tech», щоб не пропустити нові технічні статті