Введение в Log4php, часть 2. Использование

Итак, в первой части мы подключили к проекту log4php, сконфигурировали его. А что дальше?

Базовое использование

У логгера log4php есть все те же уровни, что у логгера log4net. И, в соответствии с ними, функции (в порядке возрастания уровня):

• trace
• debug
• info
• warn
• error
• fatal

Все эти функции имеют одну и ту же сигнатуру: <functionName>(mixed $message, [mixed $caller = null]). $message — это, как нетрудно догадаться, то, что мы выводим в лог. А вот $caller вообще нигде не используется.
А теперь попробуем сотворить с логами что-нибудь интересное.

Категории

В параметрах conversionPattern был у нас такой ключ %c. Рассмотрим подробнее, что он значит.
Помимо RootLogger-а в конфиге log4php можно определять и другие логгеры:

<log4php:configuration xmlns:log4php="http://logging.apache.org/log4php/" threshold="all" debug="true">
    <appender name="default" class="LoggerAppenderDailyFile">
        <param name="file" value="logs/%s.log" />
        <param name="datePattern" value="Ymd" />
        <layout class="LoggerLayoutPattern">
            <param name="ConversionPattern" value="%d{H:i:s} %p    [%c]: %m (at %F:%L) %x%n" />
        </layout>
    </appender>

    <logger name="test">
        <appender_ref ref="default" />
    </logger>

    <logger name="modules">
        <appender_ref ref="default" />
    </logger>

    <root>
        <level value="DEBUG" />
        <appender_ref ref="default" />
    </root>
</log4php:configuration>

До этих дополнительных логгеров можно достучаться по имени:

$logger = Logger::getLogger("test");

Так вот, имя логгера — это и есть та самая категория, которую впоследствии выведет ключ %c.
Категории могут быть полезны в случае большого приложения из многих частей. Использование разных логгеров позволяет отлаживать каждую часть, не засоряя при этом лог сообщениями из других частей. Ведь логгер можно в любой момент запросто отключить:

<logger name="test">
    <appender_ref ref="default" />
    <level value="OFF" />
</logger>

Вывод объектов

Как уже говорилось, объекты выводятся с помощью функции var_export. Поэтому нужно уделять особое внимание объектам с циклическими ссылками — при попытке их вывести в лог обязательно вылезет ошибка. Выходом может быть написание собственных рендереров. А можно пойти в класс LoggerRendererDefault и в его единственном методе render заменить var_export на serialize или json_encode. Во случае serialize, правда, вывод будет совсем некрасивый. А json_encode не умеет ходить в приватные поля.

NDC

Nested diagnostic context (NDC) был описан в статье Patterns for Logging Diagnostic Messages. Попробую описать основную его идею.
Итак, у нас есть сайт, к которому идут всякие разные запросы. И для всего этого сплошной кашей валится лог, в котором черт ногу сломит, потому что непонятно, какое сообщение к какому запросу относится. И возникает желание кроме сообщений лога выводить параметры окружения, т.е. контекст, в котором выполняется запрос. Причем мы очень ленивые, и потому хотим, чтобы это происходило как-то само собой, так что вариант вручную добавлять что-либо к сообщению отпадает. Тут нам и приходит на помощь NDC.
Для работы с NDC в log4php есть специальный класс LoggerNDC с кучей статических функций со вполне очевидными названиями — push, pop, clear, и так далее. С помощью всех этих функций можно управлять стеком сообщений NDC, которые будут выводится абсолютно во все логи.
Рассмотрим синтетический пример. Пусть есть класс:

class User
{
    public $isAdmin;
    
    public function accessProfile()
    {
        $logger = Logger::getRootLogger();
        $logger->trace("Accessing profile");
        
        if ($this->isAdmin)
            $logger->trace("Accessing admin privileges");
    }
}

И пусть есть следующий код:

$user = new User();

if (!empty($user))
{
    LoggerNDC::push("user");
    
    if ($user->isAdmin)
        LoggerNDC::push('admin');
    
    $logger->trace("Try to access profile");
    $user->accessProfile();    

    if ($user->isAdmin)
        LoggerNDC::pop();        
}
$logger->trace("User proceed");

if (!empty($user))
    LoggerNDC::pop();

В конфиге же пропишем ConversionPattern = %p [%x] %m%n.
После исполнения такого кода в логе выведется:

TRACE [user] Try to access profile
TRACE [user] Accessing profile
TRACE [user] User proceed

Если мы добавим $user->isAdmin = true;, то лог будет следующий:

TRACE [user admin] Try to access profile
TRACE [user admin] Accessing profile
TRACE [user admin] Accessing admin privileges
TRACE [user] User proceed

Если же зададим $user = null;, то получим:

TRACE [] User proceed

Итак, все, что находится в NDC, выводится во все логи, откуда бы они ни были вызваны.

MDC

MDC расшифровывается, как Mapped Diagnostic Context. По сути это то же самое, что NDC, с тем отличием, что данные хранятся не в стеке, а в хеше. И можно обращаться к ним по ключу.
Для работы с MDC в log4php существует класс LoggerMDC, содержащий, опять же, статические функции. Причем, в отличие от LoggerNDC, их совсем немного — put, get и remove. Использование данного класса вполне очевидно:

LoggerMDC::put("user", "darja");
$logger->info("Hello, World");

Однако, для полного счастья этого недостаточно. Нужно сконфигурить логгер так, чтобы он выводил нужную нам информацию. В conversionPattern мы рассматривали ключ %X. Сам по себе он ничего не выводит. Нужно писать %X{key}, где key — ключ хеша. Итак, если мы зададим ConversionPattern = %p [%X{user}] %m%n, то наш код выведет в лог:

INFO [darja] Hello, World

Заключение

Мы рассмотрели некоторые интересные аспекты использования log4php. Видно, насколько мощные возможности предоставляет log4php для отладки приложений. Слава ему.
Надо сказать, что все сказанное относятся и к другим логгерам этого семейства.

Ссылки

• Patterns for Logging Diagnostic Messages