Логирование чего угодно в Perl
Для логирования сообщений Перл предлагает несколько готовых решений. Все они, как водится, размещены на CPAN’е. По запросу «log» можно найти кучу модулей на все случаи жизни.
Однако, среди всех этих модулей есть один особенный, называется он Log: Any.
Особенность этого модуля для логирования заключается в том, что он не занимается, собственно, логированием. Модуль Log: Any предоставляет программе (и программисту) универсальное API для обращений к другим модулям, которые занимаются непосредственно логированием.
Если вас мучает проблема выбора способа логирования в Перле — эта статья для вас.
Проблема
Допустим, у вас есть модуль, который загружает из сети некий файл. Вы хотели бы знать, в какое время началась загрузка, сколько она продолжалась и сколько байт было загружено. Вы можете поступить простейшим образом — добавить в модуль строчки:
print "$time Начинаю загрузку файла\n";
# тут выполняется загрузка
print "$time Закончена загрузка файла\n";
print "$time Загружено $size байт\n";
Обратите внимание — для того, чтобы вычислить время $time, потребуются еще какие-то дополнительные действия, но я даже не буду заострять на этом внимание, потому что это не главная проблема.
Все будет прекрасно, пока вы запускаете этот скрипт с этим модулем руками из командной строки. Сообщения будут выводиться вам на консоль, вы их прочитаете и узнаете всё, что хотели.
Но в какой-то момент возникнет необходимость сохранять эти сообщения на будущее. Или возникнет необходимость запускать этот скрипт из Крона, а не руками. Или возникнет необходимость писать эти сообщения в базу, для дальнейшего разбора. Ну, или загружаемых файлов будет много, и вам будет сложно читать длинный лог с консоли.
И тогда вы захотите перенаправить вывод лога с консоли куда-нибудь ещё. В файл, в базу, в другую программу, в какой-нибудь веб-сервис по API, к чёрту на рога etc. Тут-то и возникнет проблема — куда же именно и как логировать сообщения?
- Писать в файл? А вдруг ваш модуль будет использоваться в окружении, где нельзя писать файлы?
- Писать в базу? А вдруг модуль для работы с базой будет не установлен?
- Перенаправлять в другую программу? А вдруг пользователь вашего скрипта предпочитает совсем не ту программу, которую выбрали вы?
Есть много отличных модулей для логирования, но все они обладают одним и тем же общим недостатком — этих модулей больше одного. Вам нравится один способ логирования, а пользователю — другой, клиентам — третий, начальству — четвертый. Фатальный недостаток ©.
Решение
Использовать модуль Log: Any.
Log: Any решает описанную выше проблему выбора таким образом, что удовлетворенными оказываются все — программист думает только о том, что он хочет отправить в лог, а потребители лога самостоятельно решают, куда и как записывать полученные сообщения.
Идея этого модуля заключается в том, чтобы разделить процедуру логирования на две отдельные части, которые могут работать независимо друг от друга. При этом, та часть, которая генерирует сообщения, не имеет понятия о том, как и куда эти сообщения будут далее записываться. А часть, которая сообщения куда-то записывает, не имеет понятия о том, откуда эти сообщения взялись и как они были сформированы.
Вот как это работает
Пунктирные линии на диаграмме означают подключение модулей через use, а сплошные — направление движения логируемых сообщений.
Отправка сообщений
Для отправки сообщения ваш код (в модуле или в скрипте, не важно) вызывает стандартную функцию, предоставляемую модулем Log: Any:
# Это загрузка модуля Log::Any с одновременным импортом объекта $log, к которому далее нужно будет обращаться для логирования
use Log::Any qw($log);
# А это - уже логирование (кроме метода error есть и другие методы)
$log->error("Что-то случилось при выполнении какой-то задачи");
Указанные выше две строчки — это всё, что нужно, для того, чтобы начать логирование. Но отправленное сообщение пока что не будет никуда записано, так-как мы еще не выбрали, куда конкретно писать лог.
Запись сообщений
Теперь нам нужно решить, куда мы писать лог. Для этого в скрипте нужно воспользоваться одним из адаптеров:
# Этот встроенный адаптер будет просто выводить все сообщения на экран
use Log::Any::Adapter ('Stdout');
# Этот встроенный адаптер будет записывать все сообщения в файл
use Log::Any::Adapter ('File', '/path/to/file.log');
# А этот внешний адаптер будет отправлять все сообщения в отдельный навороченный модуль для логирования Log::Dispatch
use Log::Dispatch;
my $log = Log::Dispatch->new(outputs => [[ ... ]]);
Log::Any::Adapter->set( { category => 'Foo::Baz' }, 'Dispatch', dispatcher => $log );
В комплекте с Log: Any поставляется несколько простых встроенных адаптеров — File, Stdout и Stderr. Как можно догадаться по названию, первый из них записывает сообщения в файл, а два других отправляют сообщения на стандартные выводы.
Помимо встроенных адаптеров на CPAN’е можно найти внешние, такие как Log4perl или Syslog. Внешние адаптеры позволяют писать логи куда угодно — хоть в Твиттер.
А если надо в Фейсбук? Тоже не проблема. Вы можете без особых усилий написать свой собственный адаптер к чему угодно. Создание своего адаптера описано в документации модуля, или вот тут на русском языке.
Я не буду здесь вдаваться в детали написания адаптера, поскольку по ссылкам выше эта задача хорошо описана. Вместо этого я рассмотрю другую задачу — внедрение логирования в уже существующий код.
Логирование уже имеющихся действий
Коннекторы
Если вы пишете код с нуля, вы можете сразу добавить логирование в нужные места. Но если у вас уже есть какой-то объем кода, то добавление функций логирования может потребовать большого объема работы по перекапыванию и модификации имеющегося кода. Вместо этого есть способ добавить логирование, ничего (почти) для этого не делая.
Для этого нужно воспользоватся коннектором — модулем, который подключается к уже имеющемуся коду и сам добавляет в него функции логирования.
Ремарка — термин «коннектор» я выдумал сам, возможно, имеется какое-то другое общепринятое название.
Модули-коннекторы обычно размещаются в пространстве имен Log: Any: For. Есть несколько готовых коннекторов, например, Log: Any: For: DBI или Log: Any: For: LWP.
Написание своих собственных коннекторов не формализовано, так-как сильно зависит от того, к чему, собственно, пишется коннектор. В общем и целом, коннектор работает так:
- Перехватывается событие, которое нужно логировать. Для этого могут быть использованы разные средства, типа моков или tie.
- Сообщение о событии отправляется в лог с помощью стандартного вызова $log→method ('сообщение').
Использование коннектора происходит так (на примере коннектора LWP):
# Подключаем LWP
use LWP::Simple
# Подключаем коннектор к LWP
use Log::Any::For::LWP;
# И загружаем страничку из сети с помощью функции из LWP
get "http://www.google.com/";
В этом коде не сделано никаких явных действия по отправке сообщений в лог, кроме подключения коннектора. Но, однако, функция get волшебным образом получит логирование и начнет выводить много всяких полезных сообщений.
Логирование предупреждений и исключений
К сожалению, время от времени в программе случаются события, которые не предусмотрены и — по хорошему — не должны случаться. К примеру, внезапно оказалось, что в какой-то функции происходит обращение к неинициализированной переменной, или отваливается коннект к базе, или вообще происходит крах программы. В таких случаях интерпретатор Перла выбросит предупреждение или исключение.
Если такое событие случилось в простом скрипте, который вы запускали из консоли, то соответствующее сообщение появится у вас перед глазами и вы его сразу увидите (хотя, тоже не факт). Если же программа запускается из Крона или работает под управлением веб-сервера, или еще что-нибудь в этом духе, то заметить такое сообщение будет не так-то просто.
Правильное решение — записать такое сообщение в лог. Но как? Ведь в лог пишутся сообщения, которые были явно отправлены туда программистом через объект $log, а варнинги и исключения выбрасывает интерпретатор, который ничего про наше замечательное логирование не знает и валит все свои сообщения просто на STDERR.
Значит, нужно всё, что идет на STDERR, принудительно перенаправить в лог.
Для решения этой задачи я не нашел подходящего коннектора на CPAN’е, поэтому написал свой — Log: Any: For: Std. Этот коннектор отправляет в лог все возможные сообщения интепретатора, на любом этапе исполнения программы.
Для перехвата STDERR иcпользуется функция tie:
tie *STDERR, __PACKAGE__;
Эта конструкция заворачивает абсолютно всё, что отправляется на STDERR, в нужный нам пакет, а в нем уже не составляет труда перенаправить сообщения в лог с помощью Log: Any.
При желании вы можете реализовать любой другой коннектор для перехвата предупреждений и исключений (или вообще можете их не перехватывать).
Фильтрация сообщений
Обстоятельства могут сложиться так, что имеющийся код уже выводит какие-то сообщения. Например, у меня есть большой проект с легаси-кодом, в котором всё логирование сделано так:
print STDERR "$time --- $login --- $pid --- некое сообщение\n";
Как можно видеть, здесь все сообщения отправляются на STDERR, а в тексте сообщений имеются всякие переменные, разделители, да плюс ещё перевод строки. Вдобавок, хоть это и не видно на глаз, все сообщения написаны без использования utf8.
Перенаправление сообщений с STDERR в лог легко решается с помощью коннектора Log: Any: For: Std, а вот лишний мусор из текста сообщения придется убирать отдельно. Для этого при подключении модуля Log: Any нужно включить фильтрацию.
Делается это примерно так:
use Log::Any '$log', filter => sub { my $msg = $_[2]; utf8::decode($msg); return $msg };
Каждое сообщение, отправляемое в лог с помощью $log→method (), будет пропускаться через функцию, указанную в аргументе filter. Переменная $_[2] в этой функции содержит отправляемое сообщение. Если вы хотите что-то сделать с сообщением, то вы должны взять его из этой переменной, модифицировать и возвратить. Возвращенное значение будет записано в лог.
К примеру, в приведенном выше коде текст сообщения приводится к utf8.
Пример скрипта
Давайте соберем всё это вместе в скрипте test.pl:
#!/usr/bin/perl
use strict;
use warnings;
use Log::Any '$log', filter => sub { my $msg = $_[2]; $msg =~ s/привет/прЕвеД/; return $msg };
use Log::Any::Adapter ('Stdout');
use Log::Any::For::Std;
print "Это просто сообщение\n";
$log->info("А это сообщение в лог");
$log->info("Тут на слове привет сработает фильтрация");
Module::func();
warn "Предупреждение тоже окажется в логе";
die "И даже исключение можно завернуть в лог";
# Модуль
package Module;
use Log::Any '$log';
sub func {
$log->info("Сообщение из модуля окажется в логе");
}
Запускаем и видим следующее:
$ ./test.pl
Это просто сообщение
А это сообщение в лог
Тут на слове прЕвеД сработает фильтрация
Сообщение из модуля окажется в логе
Предупреждение тоже окажется в логе at ./test.pl line 18.
И даже исключение можно завернуть в лог at ./test.pl line 20.
Все сообщения будут выведены на консоль, но не верьте глазам своим — только первая строчка является обычным выводом, всё остальное — это лог. Просто этот лог выведен на консоль.
А что, если теперь нам вдруг захочется отправить лог не на консоль, а в файл? С модулем Log: Any нет ничего проще:
# Достаточно сменить адаптер с этого
# use Log::Any::Adapter ('Stdout');
# На этот
use Log::Any::Adapter ('File', 'file.log');
Запускаем и видим:
$ ./test.pl
Это просто сообщение
Как и ожидалось, на консоль будет выведен только print.
А вот куда делось всё остальное:
$ cat file.log
[Fri Jun 19 17:25:44 2015] А это сообщение в лог
[Fri Jun 19 17:25:44 2015] Тут на слове прЕвеД сработает фильтрация
[Fri Jun 19 17:25:44 2015] Сообщение из модуля окажется в логе
[Fri Jun 19 17:25:44 2015] Предупреждение тоже окажется в логе at ./test.pl line 18.
[Fri Jun 19 17:25:44 2015] И даже исключение можно завернуть в лог at ./test.pl line 20.
Резюме
- Модуль Log: Any позволяет добавить в ваши программы и модули гибкое логирование, которое потом не потребуется переделывать при смене способа сохранения лога
- Адаптеры Log: Any: Adapter позволяют адаптировать вашу программу к любому способу сохранения лога
- Коннекторы Log: Any: For позволяют подключить логирование к любому источнику сообщений