Микросекунды в Yii Framework application.log

9 июля 2012 г. • 3 минуты чтения

Как добавить вывод микросекунд в файл application.log (стандартный лог в Yii Framework)?

Вот так выглядит конфиг с включенными логами

'preload' => array(
'log',
),
'components' => array(
'log' => array(
    'class' => 'CLogRouter',
    'routes' => array(
        array(
            'class' => 'CFileLogRoute',
            'levels' => 'warning, error, profile',
        ),
    ),
),
)
//... end main config

А вот так выглядит application.log:

2012/06/25 15:25:32 [error] [system.db.CDbCommand] CDbCommand::fetchAll() failed: SQLSTATE[42S02]
2012/07/06 12:57:33 [profile] [application] begin:posts with limit and offset
2012/07/06 12:57:38 [profile] [application] end:posts with limit and offset

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

Чтобы изменить и расширить вывод в application.log, можно создать небольшой extension унаследовавшись от CFileLogRoute Назовем файл ExtendedLogger.php

class ExtendedLogger extends CFileLogRoute
{
    protected function formatLogMessage($message,$level,$category,$time)
    {
        $micro = sprintf("%06d",($time - floor($time)) * 1000000);
        return date('Y-m-d H:i:s.'.$micro,$time)." [$level] [$category] $message\n";
    }
}

Как видно в нем переопределен метод formatLogMessage, в который добавлены микросекунды. Далее поместим ExtendedLogger.php в extensions/ExtendedLogger/ExtendedLogger.php и изменим конфиг на следующий:

    'preload' => array(
        'log',
    ),
    'components' => array(
        'log' => array(
            'class' => 'CLogRouter',
            'routes' => array(
                array(
                    'class' => 'CFileLogRoute',
                    'levels' => 'warning, error',
                ),
                array(
                    'class' => 'application.extensions.ExtendedLogger.ExtendedLogger',
                    'levels' => 'profile',
                ),
            ),
        ),
    )

И теперь application.log становится вот таким:

2012/07/05 19:52:32.707493 [profile] [application] begin:getPostsByUserId without cache
2012/07/05 19:52:33.775888 [profile] [application] end:getPostsByUserId without cache

Перевод этой статьи: English