LINUX.ORG.RU

Простенькие и удобные функции логирования

 ,


0

1

Задумался я как-то невзначай над тем, почему строки для trace и debug формировать труднее всего, но при этом они же чаще всего вообще не выводятся никуда. Ведь несправедливо же: интерпретатор старается, формирует какие-то дампы, куски json'ов вставляет - а мой любимый фремйворк для логирования, Log::Log4perl, всё это радостно сливает в /dev/null.

Также очень не хватало возможности выводить лог-сообщения в нормальном sprintf-стиле: я думаю, многих достала необходимость конкатенации строк для вставки переменных или использования для компиляции строки самой sprintf. Ну неудобно это! Мне куда легче не использовать %s и прочие немногочисленные валидные форматеры printf в тексте лог-сообщений, нежели каждый раз задумываться над тем, как собрать строку лога из разрозненных кусков.

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

Но как-то решил я невзначай порыть исходники этого модуля - и узрел, что там гигантский пласт кода, который делает что-то совершенно хакерски-химерическое (код самого Log::Log4perl проще и понятнее в $N раз), позволяет подключать все подряд фреймворки... Это всё было очень круто конечно, но мне с одной стороны не нужны были другие фреймворки, а с другой - не хотелось бы, чтобы поверх и без того относительно тяжёлого Log::Log4perl ещё гора кода наросла. Ну и встроенная sprintf-функциональность из-за тотальной универсальности логеров ни в одном из них не была реализована, в том числе и в Contextual.

В итоге я сломался и сделал свой велосипед: https://github.com/DRVTiny/Log4perl--KISS

Он позволяет делать как

debug {'String'}
, так и
debug_ 'String'
, что, собственно, мне и было в конечном итоге нужно.

Подробнее - см в SYNOPSIS прилагающегося README.

Относительно устранения гипотетического конфликта форматеров sprintf и логируемого содержимого - есть идеи как это реализовать :) Но в любом случае конечно только сам логирующий знает, могут в его контенте попадаться форматеры или нет.

★★★★★

Последнее исправление: DRVTiny (всего исправлений: 2)

Не перлист, но думаю что ты сделал полезное дело, ибо проблемы с логированием вроде как везде есть.

itn ★★★
()
[disarmer@grey~]% AE_VERBOSE=9 perl -wE 'use AE;AE::log debug=>123'
2017-04-28 21:17:10.000000 +0300 debug main: 123
[disarmer@grey~]% AE_VERBOSE=9 perl -wE 'use AE;AE::log warn=>sub{123}'
2017-04-28 21:17:35.000000 +0300 warn  main: 123
[disarmer@grey~]% AE_VERBOSE=9 perl -wE 'use AE;AE::log crit=>"test %f",123'
2017-04-28 21:18:36.000000 +0300 crit  main: test 123.000000
disarmer ★★★
()
Ответ на: комментарий от disarmer

Ничего так... Странно, что не нужно запускать event loop. Пойду почитаю, что у них с форматированием.

DRVTiny ★★★★★
() автор топика
Ответ на: комментарий от disarmer

Мда. Оно, по идее, выигрывает в производительности за счёт асинхронности при записи в файл, но оно совсем не для людей: «дружелюбность» интерфейса - это конечно нечто. Эту бы штуку, да аппендером к Log4perl...

DRVTiny ★★★★★
() автор топика
Ответ на: комментарий от disarmer
$ perl -e 'use Log4perl::KISS; fatal_ "test %f", 123'
22:31:56 | 28.04.2017 | 14940 | FATAL | test 123.000000

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

Автоматически средствам анализа логов в общем-то по-барабану, где именно часы и минуты и как записан уровень критичности. А вот человеку нужен удобный формат.

Хотя таймзона в некоторых случаях действительно нужна, но это легко настроить, сделав Log::Log4perl->init самостоятельно.

DRVTiny ★★★★★
() автор топика
Ответ на: комментарий от DRVTiny

выигрывает в производительности за счёт асинхронности

Так ты используешь event-loop или нет? Если нет, асинхронности тоже не будет. Если да, то выбора быть не может, синхронная запись в файл всё залочит при затупах диска.

но оно совсем не для людей: «дружелюбность» интерфейса - это конечно нечто

А что не так? Коротко и ясно, достаточно гибко

disarmer ★★★
()
Ответ на: комментарий от disarmer

А что не так?

То, что нужно опять всё вставлять каким-то чудесным форматирующим коллбеком. Это уже совсем не user-friendly. Я считаю, что если разработчик может сделать более человекоудобный интерфейс для работы с его библиотекой, то он и должен так поступить. В Log4perl же осилили.

А так да, наверное блокирующее что-либо в асинхронных приложениях в любом случае не есть гуд. Хотя по факту простое выполнение Perl'ового кода часто куда тормознее любого ввода-вывода: здесь кто-то, уж не ты/Вы ли, приводил пример максимально быстрого чтения из redis, когда быстрее всякого async раз в несколько раз оказывалось чтение через redis-cli. Т.е. блокирующий запрос на fork+exec с возвратом результата был быстрее небольшой кучки асинхронного кода на Perl'е.

Другое дело, что лог, зараза, в Log4perl по дефолту флушиться после каждой записи, а вот этот уже «бооооль»: если бы лог писался по факту в оперативную память и асинхронно флушился бы ядром ОС, то это было бы по определению эффективнее всякого AnyEvent/EV.

Файловый appender в Log4perl позволяет выключить autoflush... Вот только не знаю, хорошо ли это.

DRVTiny ★★★★★
() автор топика
Ответ на: комментарий от disarmer

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

Просто вспомни о том, что в асинхронном приложении абсолютно любой «синхронный» код всё лочит: захотел посчитать факториал - «всё залочил», а потом вдруг в цикле дорогостоящим интерпретируемым кодом объёмную структуру данных поменять захотел - аналогично, всё залочил. Тогда уж надо пропагандировать AnyEvent->idle - т.е. обработку чего бы то ни было тогда и только тогда, когда никакие иные события процесс не обрабатывает. Все эти чудесные асинхронные коллбеки - они же просто выстраиваются в цепочку, и если событие Б наступило в тот момент, когда событие А ещё отрабатывается колббеком - можно с таким же успехом считать, что обработка события Б была заблокирована коллбеком обработки события А.

В общем-то любой Perl'овый код, который не выглядит как одна большая цепочка в духе Mojo::IOLoop::Delay с прилепленными где-то сбоку обработчиками состояния Idle - является, мягко говоря, не вполне асинхронным.

Собственно, именно по этой причине в приложениях на Си для обработки асинхронных событий часто используются треды. Но мы-то знаем, почём треды Perl'а...

DRVTiny ★★★★★
() автор топика
Последнее исправление: DRVTiny (всего исправлений: 1)
Ответ на: комментарий от disarmer

Вообще очень интересно, как именно реализован «асинхронный print» внутри AnyEvent::Log

А то ведь есть MojoX::Log::Log4perl, который настолько же асинхронен, насколько я похож на балерину. Т.е. вообще никак не асинхронен, даже за на autoflush влиять никак не пытается.

DRVTiny ★★★★★
() автор топика
Ответ на: комментарий от disarmer

ASYNCHRONOUS DISK I/O

This module uses AnyEvent::IO to actually write log messages (in log_to_file and log_to_path), so it doesn't block your program when the disk is busy and a non-blocking AnyEvent::IO backend is available.

Вот это реально хорошо. Уже думаю над AnyEvent::Log::KISS :)

DRVTiny ★★★★★
() автор топика
Ответ на: комментарий от DRVTiny

Вот это реально хорошо. Уже думаю над AnyEvent::Log::KISS :)

ИМХО проще настроить формат в 10 строках, чем пилить модуль и потом с ним возиться.

Файловый appender в Log4perl позволяет выключить autoflush... Вот только не знаю, хорошо ли это.

Это не полное решение проблемы. И асинхронность тоже не решение. Надо определиться что важнее в критической ситуации, запись логов или работа приложения. Если первое - оставить как есть, если второе - делать аналог кольцевого буфера и отвязывать запись от основного процесса

disarmer ★★★
()

Логгирование — сложная тема. Сделать его просто можно только снаружи или для каких-то тривиальных случаев. Если задумывать логгирование, то нужные конфиги, депенденси инъекции, генерация кода при старте, чтобы при работе уже были скомпилированные и делающие только что надо и когда надо функции... Аппендеры должны уметь писать в файл, скрин, сокет, базу, память, уметь быть асинхронными... Информация в форматтерах должна быть не только та, что передаётся явно, но и с возможностью доступа из «текущего контекста», который должен бы очищаться автоматически.

Casus ★★★★★
()
Вы не можете добавлять комментарии в эту тему. Тема перемещена в архив.