Comments 19
Для конфигурации лучше использовать файл, а не код. Например:
logging.config.fileConfig(Path(__file__), "logging.ini")
Вот если честно, я встречал такое мнение, но лично я не вижу особой разницы: использовать файл-конфиг или использовать отдельный метод/функцию/модуль для общей настройки логгинга.
Но, на сколько я понимаю, это справедливо только для языков, не требующих перекомпиляции при изменениях кода.
Использовал оба подхода. Какие есть существенные аргументы в пользу использования файлов-конфигов?
Например, читабельность, сравните конфиг из статьи и такой:
[loggers]
keys=root
[handlers]
keys=consoleHandler
[formatters]
keys=json
[logger_root]
level=INFO
handlers=consoleHandler
[handler_consoleHandler]
class=StreamHandler
level=INFO
formatter=json
args=(sys.stdout,)
[formatter_json]
class=pythonjsonlogger.jsonlogger.JsonFormatter
format=%(asctime)s %(process)d %(thread)d %(levelname)s %(name)s %(funcName)s %(message)sЕсли сравнивать с конфигом из статьи, то конечно, это вариант смотрится гораздо лучше. Но я имел в виду задание конфигурации стандартными методами/функциями из модуля logging - .basicConfig(), создание хендлеров, форматтеров и прочее. Зачем вместо этого использовать голый dict - для меня загадка.
Прошу прощения, нужно было это момент сразу уточнить.
не вижу особой разницы: использовать файл-конфиг или использовать отдельный метод/функцию/модуль
Как только у вас появляются разные среды (dev1, dev2, test, prod), в которых должны быть разные настройки, то хранение конфигов в коде превратится в боль и страдание. Вы сразу же перейдете или к переменным окружения (env'ам), или к конфиг-файлам. Особенно быстро это произойдет если добавить CI\CD.
При логировании лучше использовать % а не f строки. В этом случае подстановка аргументов в строку будет происходить в последний момент. Например если у вас много debug логов, то в warning режиме методы строки не будут создаваться, + не будут вызываться методы приведения к строке у аргументов.
Вы хотите сказать, что если у меня будет выражение
f'Result = {heavyOperation()}'И эту строку я пихаю в logging.debug(), и при этом включаю логи уровня warning+, то heavyOperation() все равно будет выполняться?
Если да, то чем будет отличаться поведение с %?
Если нет, то тогда не понял смысл комментария
UPD: почитал из интереса - действительно выражение считается в рантайме для % и в компайлтайме для f-строк, прошу прощения
Думал разница только в удобстве и версии питона
Думаю, с примером сразу станет всё ясно.
тут строка-результат формируется до вызова debug (точнее в debug передается уже сформированная строка-результат)
logger.debug(f"User {user} logged in")
А тут - строка-результат формируется внутри вызова debug, потому что сам вызов содержит только набор аргументов, соответственно, при уровне INFO новая строка формироваться не будет.
logger.debug("User %s logged in", user)
В обоих случаях будет вычисляться аргумент user, и если это что-то сложнее обычной переменной (типа вызова функции) то возможны и побочные эффекты и замедление.
Сборка же самой строки, как правило, занимает ничтожное время по сравнению со всем остальным, так что выигрыш тут близок к нулю, разве что имеем дело с объектами - там ещё будет экономия на отсутствии вызовов __repr__ или __str__, и то только если они сложные и/или медленные.
Единственный надёжный способ с этим бороться - это использовать конструкции типа:
if __debug__:
logger.debug(f"User {user} logged in")В этом случае, если приложение запускается не в отладочом режиме (python -O) то всё что внутри if __debug__ вообще будет вырезано и не будет выполняться.
К сожалению, эта магия работает только с __debug__ и только если нет других условий - удобной условной компиляции методов как в C# у Python нет, увы.
Прятать сложные вычисления внутри вызова .debug() - вообще идея не очень, в таком случае лучше воспользоваться чем-то вроде https://docs.python.org/3/library/logging.html#logging.Logger.isEnabledFor или https://docs.python.org/3/library/logging.html#logging.Logger.getEffectiveLevel, которые работают для любого уровня логирования.
Форматирование строк - операция всё же довольно затратная, если .debug() вызовов много, то лучше использовать С-style форматирование. Даже если аргументы типа user уже известны на момент вызова (а это происходит в 99% случаев).
И оба варианта не позволяют писать структурные логи. Я, как знакомый с .NET разработкой с болью и печалью смотрю на устаревший подход к журналированию, которые до сих пор используется в проектах Python.
Например, такой вывод в лог на .NET:
_logger.LogInfomation("User {UserName} is logged in", userName);
Даёт следующее:
Строка "User {UserName} is logged in" является константой и не приводит к выделению памяти.
Так как журнал полностью асинхронный, т.е. запись журнала в файл/эластик/oltp идёт из буфера, и не блокирует код, отсутствие лишних выделений памяти чувствительно
Самое главное, в журнале будет следующее:
{
"@timestamp": "2023-10-11T17:44:27Z",
"message": "User \"Vasya Pupkin\" is logged in",
"UserName": "Vasya Pupkin",
...
}
Т.е. UserName запишется отдельным полем в журнал. И ничего специально для этого не надо делать. А это даёт просто колоссальные преимущества для эффективной работы с журналом.
На наших проектах на Python этого здорово не хватает.
Возможно, вот это будет для вас полезно?
https://docs.python.org/3/howto/logging-cookbook.html#adding-contextual-information-to-your-logging-output
Как-то на одном из проектов автоматически добавляли к логам query_id, но похоже, что и в вашем случае может быть полезно (но если честно, то я особо не вникал).
Плюс pythonjsonlogger.jsonlogger.JsonFormatter, как было сказано в статье, если нужны логи в формате JSON.
UPD: почитал из интереса - действительно выражение считается в рантайме для % и в компайлтайме для f-строк, прошу прощения
f-строки и С-style строки с % не могут считаться во время "компиляции", потому что значения аргументов становятся известны как правило только во время выполнения. Потому что нет смысла использовать заранее известные значения для форматирования строк, проще сразу использовать строковые литералы.
смысл есть.
При использовании записи вида
logger.debug("hello, %s", user)из инстанса Record можно будет легко достать этот аргумент. Использовать это можно, например, в фильтрах или при форматировании.
если же использовать
logger.debug("hello, %s" % user)то, как тут уже написали, строка будет формироваться ещё до создания Record и, соответственно, Record.args будет пустым
Мы много обсуждали это на работе, но в итоге свичнулись на f-strings. Разница в производительности даже на debug-коде мизерная, а сложные строки с выводом 3-4 переменных выглядят куда понятнее в виде f-strings, чем в виде форматированного через % кода.
Риски безопасности: Корневой регистратор может быть
изменен любым модулем приложения, что может создать риски для
безопасности, если злоумышленник сможет изменить настройки журнала.
Кто нибудь может объяснить этот момент? Есть ли в python возможность защитить какой то модуль от модификации при компрометации другого модуля? Или это тут для красного словца.
logger.propagate = False
propagate не спроста по умолчанию установлено в True. Как правило, логгер вообще не должен заниматься решением того кто будет, а кто не будет читать его записи. Его задача - формировать эти записи, а дальше там разберутся
Про f-string выше уже написали. Хотя для меня важнее не само то что они вычисляются в момент формирования записи, а то что далее из этой записи невозможно будет достать эти аргументы для фильтрации и/или форматирования. Поэтому, несмотря на мою любовь к f-string, именно в логгерах использовать желательно % синтаксис.
Ведение журнала в json - чистая вкусовщина. Вполне может быть оправдана, если к примеру данные должны передаваться для анализа в другое приложение. В других случаях большого смысла в этом нет.
В целом статья очень слабая. Очевидно что автор (авторка?) не имеет достаточного опыта чтобы называть свои статьи "10 Best Practices ..." . Вроде и не хочется шеймить и, возможно, какая польза есть. Но есть ощущение, что подобные статьи являются информационным шумом, который мешает людям добраться, наконец, до документации python где всё подробно написано.
10 лучших практик логирования в Python