Ko3: Profiler. Собираем статистику

Многие знают, что есть такой системный класс Profiler, и что он может выводить табличку со статистикой. А вот как он работает, как вести сбор своих данных и потом извлечь их обратно — об этом и пойдет речь в данной небольшой статье.

Итак, сперва посмотрим, что происходит обычно в 90% случаев:

1. Так как обычно статистика работы БД — самая интересная часть, то ее надо разрешить (по умолчанию запросы к БД не профилируются). Для этого смотрим параметр ‘profiling‘ для нужного профиля соединения с БД (в конфигурационном файле config/database.php). Само профилирование по умолчанию включено (см. вызов Kohana::init() в файле bootstrap.php), впрочем по ходу выполнения приложения его можно включать и выключать — работайте напрямую со свойством Kohana::$profiling.
2. Система сама накапливает информацию (время выполнения и затрачиваемая память), учитывая возможные повторы регистрируемых действий (например, один и тот же запрос к БД займет каждый раз разное количество ресурсов сервера).
3. Выводим статистику на экран, прописывая где-нибудь в шаблоне такую строчку:
   

   echo View::factory('profiler/stats');

В таком случае мы увидим статистику по затратам времени и памяти на выполнение отдельных задач. Данные разбиты на столбцы. BENCHMARK содержит сам показатель (текст запроса к БД, имя системной функции и т.д.), в скобках пишется количество зарегистрированных вызовов. Сама статистика хранится в столбцах MIN, MAX (тут все понятно), AVERAGE (среднее значение, имеет смысл при множественных вызовах, как в Kohana::find_file()) и TOTAL (общее значение затрат). Задачи группируются: запросы в БД расположены в секции Database, в Kohana размещена информация о самых популярных вызовах Kohana::init(), Kohana::modules() и Kohana::find_file(). В секции Requests можно узнать об осуществленных системных запросах (не забываем, что в Ko3 есть HMVC).

Отдельно надо сказать про секцию Application Execution. В ней показывается статистика выполнения работы приложения в целом, причем есть данные за последние сутки (берутся из кэша). Соответственно в MIN/MAX/AVERAGE выбираются данные среди всех запросов за сутки, TOTAL хранит общую продолжительность работы приложений.

Есть еще параметр Kohana::$rollover, который участвует при сборе статистики работы приложения. Если количество учтенных записей превышает данный показатель (по умолчанию 1000), то сбор начинается с начала, старые данные отбрасываются.

Как оно работает

Все это действительно полезно. Но нам ведь этого мало? Хочется свободы, хочется добавить чего-нибудь своего, действительно важного. Давайте посмотрим, что мы можем изменить, как использовать данную библиотеку под свои нужды.

Основной термин при работе с Profiler — токен (token). Это случайно сгенерированный код (на основе внутреннего счетчика класса), который позволяет иметь доступ к статистике по соответствующему параметру. Звучит так себе, поэтому вот вам сразу пример:

// хотим посмотреть статистику работы метода Х класса Y
// инициируем сбор статистики, метод Profiler::start() возвращает нам токен
$token = Profiler::start('class Y', 'method X');
// собственно сами обсчитываемые вызовы
Y::x();
// нужная нам часть кода отработала, останавливаем Профайлер
Profiler::stop($token);

Все просто. Когда мы вызываем Profiler::start($group, $name), происходит следующая цепочка шагов:

1. Увеличивается внутренний счетчик.
2. С помощью счетчика генерируется токен. По сути это число в 32-разрядной форме счисления, с префиксом ‘kp/‘ (сокращение от Kohana Profiler?).
3. В свойстве Profiler::$_marks добавляется новая запись под индексом $token, в которой хранится имя группы ($group), имя самого показателя ($name), и текущие значения времени в микросекундах и потребляемой памяти (стартовые показатели).

Теперь, когда мы вызовем Profiler::stop(), передав туда нужный токен, к статистике данного параметра добавятся конечные показатели (время и занимаемая память на момент вызова). Никто не запрещает вызывать Profiler::stop() несколько раз — в этом случае будут сохранены последние статистические значения.

Управляем статистикой

Токен продолжает «жить» и после остановки его «замеров». Чтобы получить данные по нему, применяется метод Profiler::total($token). Он возвращает массив из двух значений — затраченное время и память, полученные из разницы конечных показателей и стартовых. Если на данный момент конечные показатели не установлены (Profiler::stop() не был вызван), то будут взяты текущие значения.

Если статистика по токену уже не нужна (ошиблись или уже обработали), используйте Profiler::delete($token).

Можно собрать статистику и по целому ряду токенов. Это имеет смысл, если в приложении имеются неоднократные «тяжелые» вызовы (например в цикле). Собираем токены в массив, и получаем статистику из метода Profiler::stats($tokens). Результат приходит в виде массива с индексами ‘min‘, ‘max‘, ‘total‘ и ‘average‘ (думаю, тут все понятно).

А что же группы? Зачем мы тогда передавали в Profiler::start() какие-то имена? А вот зачем. Мы не хотим запоминать токены, все равно удобнее (и логичнее) работать с группой токенов, связанных одной общей идеей. Поэтому мы при запуске нового замера приписываем его к какой-нибудь абстрактной группе, и даем имя (оно может пригодиться для группировки однотипных замеров, например так сделано для запросов к БД или вызовов Kohana::find_file()). А дальше можно очень удобно получить статистику по целой группе:

// берем статистику вызовов Kohana::find_file()
$stat = arr::path(Kohana::groups(), 'kohana.find_file', array());
var_dump(Profiler::stats($stat));

В данном случае мы сперва получаем все токены с разбиением по группам и именам (метод Profiler::groups()). Например, если у нас было 10 вызовов Profiler::start() с группой ‘class Y‘ и именем ‘method X‘, то среди всего прочего Kohana::groups() будет содержать десять записей по ключу ['class Y']['method X']. В вышеуказанном примере для извлечения данных записей я использовал метод arr::path().

Стоит отметить, что пустой массив в методе Profiler::stats() вызовет ошибку «деление на ноль», т.к. количество элементов участвует в формуле вычисления средних значений. Также ошибку получим при передаче некорректного токена в один из методов stop()/total()/delete()/stats().

Напоследок

Что еще надо помнить про профилирование:

1. Модуль Database в качестве имени группы использует строку ‘Database ($instance)‘, где $instance — имя текущего профиля БД (по умолчанию ‘default‘). Имя замера — сам текст SQL-запроса.
2. Имя группы хранится в нижнем регистре, поэтому искать надо ‘kohana‘ вместо ‘Kohana‘, и ‘database (default)‘ вместо ‘Database (default)‘. А вот имя замера хранится как есть. Иначе во что бы превратились тексты запросов к БД!
3. Статистика Application Execution (общая статистика по работе приложения) вычисляется «на лету» (вот зачем нужны константы KOHANA_START_TIME и KOHANA_START_MEMORY из файла index.php) и не хранится в общем массиве Profiler::$_marks, поэтому получить ее методами типа Profiler::stats() не получится. Для доступа к текущим значениям есть метод Profiler::application(). Он возвращает массив с уже знакомыми нам ключами ‘min‘, ‘max‘, ‘total‘ и ‘average‘, а также ‘current‘ (текущие метка времени и занимаемая память) и ‘count‘ (общее число участвующих замеров).
4. Метод Profiler::stats() почему-то не возвращает количество зарегистрированных вызовов, поэтому если очень нужно их посчитать, используйте метод Profiler::groups(), с его помощью можно подсчитать количество токенов в нужной группе или отдельном замере.