Правильно представлені логи — цінний компонент набору розробника. Чому вчора під час перевірки користувач отримав помилку? Які дані він вводив? Логи дозволяють відповісти на всі ці питання.
Практика ведення логів варіюється від дуже простих статичних операторів рядка до насичених структурованими даними подій. У цій статті ми розглянемо, як логування в Python може покращити розуміння того, що відбувається у вашому застосунку. Крім того, ми проаналізуємо найкращі практики, які допоможуть отримати максимальну користь від логів.
Багато посібників Python показують читачам як використовувати print у ролі інструмента для налагодження.
>>> import sys
>>>
>>> try:
... 1/0
... except:
... print(sys.exc_info())
...
(<class 'ZeroDivisionError'>, ZeroDivisionError('division by zero',), <traceback object at 0x101acb1c8>)
None
Хоча це корисно у невеликих програмах, зі зростанням вашого застосунку й операційних вимог, print перестає бути життєздатним рішенням. Він не пропонує гнучкості для відключення цілих категорій вихідних операторів, і дозволяє виводити тільки у stdout. Він також пропускає таку інформацію як номер рядка і час, коли він був згенерований, що могло б допомогти при налагодженні. print — найлегший підхід, оскільки він не потребує налаштування, й може обернутися додатковими проблемами. До того ж надсилати пакет, який безпосередньо друкується в stdout, є поганою практикою, бо це прибирає можливість користувачу контролювати повідомлення.
logging.info()
Модуль логування є частиною стандартної бібліотеки Python з версії 2.3. Він автоматично додає контекст, такий як номер рядка й часові мітки, у ваші логи. Модуль спрощує додавання логування простору імен та рівнів пріоритетності, надаючи вам більше контролю над тим, що і коли виводиться.
Початок роботи з модулем логування простий, ось все, що вам потрібно зробити:
>>> import logging
>>> logging.basicConfig()
>>> logger = logging.getLogger(__name__)
>>>
>>> logger.critical('логування простіше, ніж я гадав')
CRITICAL:__main__:логування простіше, ніж я гадав
Що тільки що сталося? getLogger надав нам екземпляр логера. Тоді ми передали йому подію 'логування простіше, ніж я гадав' з рівнем critical.
Рівні
Модуль Python дозволяє вам розрізняти події на основі рівня їх пріоритетності. Рівні представлені як цілі числа між 0 та 50. Модуль визначає 5 констант по всьому спектру, що дозволяє легко розрізняти повідомлення.
Кожен рівень має значення, яке йому надається, і ви повинні критично відноситися до рівня, на якому ви логуєте.
- debug: низький рівень логування системної інформації для подальшого використання у налагодженні;
- info: загальна системна інформація;
- warning: інформація про невеликі проблеми, що виникли під час роботи застосунку;
- error: інформація про помилки, що виникли під час роботи застосунку;
- critical: інформація про критичні помилки.
>>> logger.critical("this better be bad")
CRITICAL:root:this better be bad
>>> logger.error("more serious problem")
ERROR:root:more serious problem
>>> logger.warning("an unexpected event")
WARNING:root:an unexpected event
>>> logger.info("show user flow through program")
>>> logger.debug("used to track variables when coding")
Зверніть увагу на те, що info та debug не виводять повідомлення. За замовчуванням логер друкує тільки повідомлення warning, error або critical. Ви можете налаштувати цю поведінку і навіть змінити її під час виконання, щоб динамічно активувати більш детальне логування.
>>> # має показуватись; info більшого рівня, ніж debug
>>> logger.setLevel(logging.DEBUG)
>>> logger.info(1)
INFO:root:1
>>>
>>> # не має показуватись; info меншого рівня, ніж warning
... logger.setLevel(logging.WARNING)
>>> logger.info(2)
Форматування логів
Форматер за замовчуванням не підходить для форматування логів, оскільки він не включає критичну інформацію. Модуль логування спрощує для вас її додавання за допомогою зміни формату.
Ми встановимо формат для відображення часу, рівня й повідомлення:
>>> import logging
>>> logFormatter = '%(asctime)s - %(levelname)s - %(message)s'
>>> logging.basicConfig(format=logFormatter, level=logging.DEBUG)
>>> logger = logging.getLogger(__name__)
>>> logger.info("test")
2018-06-19 17:42:38,134 - INFO - test
Деякі дані, такі як time та levelname можуть бути взяті автоматично, проте ви можете (і маєте) додавати extra контекст у ваші логи.
Додавання контексту
Звичайне повідомлення логу надає так само мало інформації, як і повідомлення, яке не стосується логів. Уявіть, якщо вам потрібно було пройти через ваші логи, і ви побачили removed from cart. Це ускладнює можливість відповісти на такі питання, як: Коли цей елемент було видалено? Хто його видалив? Що було видалене?
Краще всього у ваші логи додавати структуровані дані замість рядкових об'єктів, щоб їх збагатити. Без структурованих даних буде важно розшифрувати потік логу в майбутньому. Найкращий спосіб владнати це – додати важливі метадані в об'єкт extra. Використовуючи такий підхід, у вас буде можливість збагатити ваші повідомлення у потоці.
>>> import logging
>>> logFormatter = '%(asctime)s - %(user)s - %(levelname)s - %(message)s'
>>> logging.basicConfig(format=logFormatter, level=logging.DEBUG)
>>> logger = logging.getLogger(__name__)
>>> logger.info('purchase completed', extra={'user': 'Sid Panjwani'})
2018-06-19 17:44:10,276 - Sid Panjwani - INFO - purchase completed
Продуктивність
Логування вводить накладні витрати, які мають бути збалансовані згідно з вимогами до продуктивності програмного забезпечення, яке ви пишете. Хоча накладні витрати, як правило, є незначними, погана практика й помилки можуть привести до невдалих ситуацій.
Ось кілька корисних порад:
Огорніть дорогі виклики (Expensive Calls) у перевірку рівня:
У документації Python з логування рекомендується, щоб дорогі виклики були огорнені у перевірку рівня.
if logger.isEnabledFor(logging.INFO):
logger.debug('%s', expensive_func())
Тепер expensive_func буде викликана тільки тоді, якщо рівень логування більший або дорівнює INFO.
Уникати логування у Hot Path
Hot Path — код, який є критичним для продуктивності, тому він часто виконується. Краще уникати логування, тому що це може стати вузьким місцем вводу-виводу, хіба що це не є необхідним, тому що дані для логу недоступні поза hot path.
Зберігання й доступ до логів
Тепер, коли ви навчились писати ці (красиві) логи, ви маєте визначити, що з ними робити. За замовчуванням, логи записуються у стандартний пристрій виводу (можливо, у вікно терміналу), але модуль логування Python надає багатий набір параметрів для налаштування оброблення виводу. Логування у стандартний вивід є рекомендованим, а такі платформи, як Heroku, Amazon Elastic Beanstalk та Docker будують на цьому стандарті, захоплюючи стандартний вивід й перенаправляючи інші засоби логування на рівень платформи.
Логування у файл
Модуль логування дозволяє з легкістю записувати логи у локальний файл, використовуючи «обробник» для довгострокового зберігання.
>>> import logging
>>> logger = logging.getLogger(__name__)
>>>
>>> handler = logging.FileHandler('myLogs.log')
>>> handler.setLevel(logging.INFO)
>>>
>>> logger.addHandler(handler)
>>> logger.info('You can find this written in myLogs.log')
За допомогою grep можна легко проводити пошук по лог-файлу.
grep critical myLogs.log
Тепер ви можете шукати повідомлення, які містять ключові слова critical або warning.
Обертальні логи
Python модуль логування дозволяє логувати в іншому файлі через визначений проміжок часу або після того, як файл логу досягне певного розміру. Це стає корисним, якщо ви автоматично хочете позбутися старих логів або якщо ви хочете провести пошук по логах за визначену дату, оскільки вам не захочеться шукати по всьому величезному файлу, щоб знайти набір логів, які вже згруповані.
Для того, щоб створити handler, який кожного дня робить новий лог-файл та автоматично видаляє логи, яким понад п'ять днів, можна використати TimedRotatingFileHandler.
Ось приклад:
logger = logging.getLogger('Rotating Log by Day')
# записує у pathToLog
# створює новий файл кожен день `when="d"` та `interval=1`
# автоматично видаляє логи, яким 5 днів або більше `backupCount=5`
handler = TimedRotatingFileHandler(pathToLog, when="d", interval=1, backupCount=5)
Недоліки
Важливо розуміти, де застосовні логи, коли річ заходить про спостереження за вашим застосунком. Я рекомендую читачам поглянути на 3 стовпи принципу спостереження – у цих логах мають бути один чи кілька інструментів, до яких ви вдаєтесь, коли спостерігаєте за своїм застосунком. Логи є компонентом вашого стеку спостереження, проте метрика й трасування не менш важливі.
Логування може стати дорогим, особливо в масштабі. Метрики можуть використовуватися для агрегації даних й відповісти на питання про ваших клієнтів без необхідності відстеження всіх дій, в той час як трасування дозволяє вам побачити шлях запиту по всій вашій платформі.
Підведення підсумків
Логи слугують джерелом правди для дій користувачів. Навіть для ефемерних дій, таких як розміщення предмета у кошик та його витягнення звідти, необхідно мати можливість відстежувати кроки користувача для звіту про помилку, а логи дозволяють вам визначати їх дії.
Модуль логування Python спрощує цю роботу. Він дозволяє вам форматувати логи, динамічно розрізняти повідомлення, використовуючи рівні, а також надсилати логи назовні, використовуючи «обробники». Хоча це не єдиний механізм, який ви маєте використовувати, щоб отримати представлення про дії користувача, це ефективний спосіб захоплення необроблених даних подій й відповідей на невідомі питання.
Ще немає коментарів