Практическое применение DTrace

В недрах скриптов на PHP

Функциональность DTrace становится все популярнее, и ее добавляют не только в Java, но и в другие приложения. Далее мы рассмотрим изучение работы скриптов на php и СУБД, с которой они общаются, с помощью dtrace.

Как и в случае с JVM, нам потребуется php с встроенными в код датчиками. Для этого потребуется скачать и установить модуль dtrace.so для PHP. В Solaris Express Developer Edition 1/08 модуль уже есть – /usr/php5/5.2.4/modules/dtrace.so. Когда модуль уже готов к работе, надо вписать в php.ini строку

extension=dtrace.so

Проверяем, есть ли поддержка dtrace в PHP:

# /usr/php5/5.2.4/bin/php -i | grep -i dtrace
/etc/php5/5.2.4/conf.d/dtrace.ini,
dtrace
dtrace support => enabled

Теперь предположим, что у нас есть база данных, которая состоит из единственной таблицы, где хранится наша записная книжка. Чтобы облегчить задачу, предположим, что в ней записаны только имена, фамилии и телефоны наших знакомых:

CREATE TABLE notebook (
id INT AUTO_INCREMENT PRIMARY KEY,
name VARCHAR(50),
lastname VARCHAR(50),
phone VARCHAR(15)
);

Теперь напишем скрипт на php, который будет извлекать из этой таблицы сведения:

<?php
$dbname="personal";
$dbhost="localhost";
$dblogin="filip";
$dbpass="9bdx57";
$link = mysql_pconnect($dbhost, $dblogin, $dbpass);
mysql_select_db ($dbname,$link) or die ('Connection Error.');
$query = "SELECT name , lastname , phone FROM notebook";
$result = mysql_query($query) or die ('Execution error. ' .
mysql_error());
$message = '';
while ($row = mysql_fetch_array($result)) {
$message = $message . sprintf("%s %% %s %% %s
\n",$row[0],$row[1],$row[2]);
}
echo $message;
mysql_free_result($result);
?>

Пропустим здесь этап заполнения базы данных сведениями и предположим, что данные в таблице notebook уже есть. Интересно, много ли можно узнать с помощью датчиков DTrace в php? Провайдер php предоставляет два датчика, срабатывающих при вызове функции и окончании ее работы: function-entry и function-return.

Аргументы этих датчиков:

• arg0 – имя вызванной функции (указатель на строку внутри PHP);
• arg1 – имя файла скрипта (указатель на строку внутри PHP);
• arg2 – номер строки, откуда вызвана функция.

Возьмем простой скрипт для трассировки работы нашего приложения на php:

#!/usr/sbin/dtrace -Zqs
php*:::function-entry
{
printf("called %s() in %s at line %d\n",copyinstr(arg0),
copyinstr(arg1),arg2)
}

Ключ Z позволяет запустить скрипт, даже если дескриптор ( php*:::function-entry ) не соответствует ни одному датчику (а это в момент запуска скрипта будет именно так, потому что мы еще на запустили скрипт и модуль dtrace.so не загружен). В одном окне запустим наше приложение на php:

php simpledb.php
Philip % Rock % +74951110808
Ivan % Markov % +74951110808
а в другом – скрипт dtrace для отслеживания его работы:
./php-trace.d
called mysql_pconnect() in /export/home/filip/simpledb.php at line 7
called mysql_select_db() in /export/home/filip/simpledb.php at line 8
called mysql_query() in /export/home/filip/simpledb.php at line 11
called mysql_fetch_array() in /export/home/filip/simpledb.php at line 15
called sprintf() in /export/home/filip/simpledb.php at line 16
called mysql_fetch_array() in /export/home/filip/simpledb.php at line 15
called sprintf() in /export/home/filip/simpledb.php at line 16
called mysql_fetch_array() in /export/home/filip/simpledb.php at line 15
called mysql_free_result() in /export/home/filip/simpledb.php at line 20

Теперь мы знаем больше о том, как вызываются функции в нашем скрипте на php.

А еще можно выяснить, какие команды наше приложение передает серверу баз данных и сколько времени он на это тратит.

Внутри баз данных: Postgresql и MySQL

Мы рассмотрим возможности по динамическому наблюдению за сервером СУБД, которые предоставляет вживленный в MySQL и Postgresql код. По имеющимся сейчас сведениям от разработчиков MySQL провайдер mysql планируется включить в код СУБД в версии 6.0.4. Однако уже в версии 6.0 можно обнаружить предварительный вариант кода этого провайдера, и если вы хотите его попробовать уже сейчас, это можно сделать, указав при установке из исходных текстов ключ --enable-dtrace при вызове ./configure.

Более детально можно познакомиться с инструкциями по использованию DTrace в MySQL 6.0 на форуме пользователей DTrace по адресу http://www.opensolaris.org/jive/forum.jspa?forumID=7.

Здесь мы рассмотрим более хитрую методику отлова команд, переданных серверу MySQL, а затем перейдем к работе с postgresql, который уже давно поставляется с встроенными датчиками DTrace.

Дело в том, что с помощью провайдера pid мы можем получить информацию о вызове любой функции в любом приложении. Кстати, если нас больше интересует производительность ввода-вывода СУБД, то лучше обратиться к провайдеру io, но это уже предмет другой статьи.

В MySQL обработка запросов выполняется функцией mysql_parse

mysql_parse(THD *thd, char *inBuf, uint length)

Название ее второго аргумента звучит многообещающе. Попробуем следующий скрипт для того, чтобы получить список запросов, направленных серверу MySQL:

cat mysql-catch.d
pid$target::*mysql_parse*:entry
{
printf("%Y %s\n", walltimestamp, copyinstr(arg1));
}

Запустим его в одном окне

# dtrace -qs mysql-catch.d -p 1019

А в другом запустим уже знакомый скрипт на php для получения содержимого нашей записной книжки:

# php simpledb.php
Philip % Rock % +74951110808
Ivan % Markov % +74951110808

В первом окне мы получим ответ скрипта:

2008 Feb 7 22:58:35 SELECT name , lastname , phone FROM notebook

Готово!

Только придется помнить, что если на сервере запущено несколько экземпляров mysqld, надо позаботиться об указании правильного идентификатора процесса: это обязательно при работе с датчиками провайдера pid. Представленный скрипт справляется с тем, чтобы сообщить нам запрос, отправленный серверу. Может случиться так, что сервер отвергнет запрос – из-за отсутствия права доступа к данным у запрашивающего или из-за некорректности запроса.

Для анализа значения, которое возвращает функция, можно воспользоваться датчиком

pid$target::*mysql_execute_command*:return .

В arg1 у датчиков провайдера pid находится код возврата. Успешное завершение операции сервером MySQL даст код 0, и ненулевое значение — в противном случае.

Для контроля за выполнением операций достаточно добавить в скрипт mysql-catch.d еще один компонент:

pid$target::*mysql_execute_command*:return
{
printf("%Y %d \n", walltimestamp, arg1);
}

Теперь разберемся с Postgresql.

Начиная с версии postgresql 8.2 в него встроен код провайдера DTrace — posgresql.

Стало быть, для анализа запросов к этой СУБД можно использовать встроенные датчики, не исследуя исходный код сервера. Вот перечень этих датчиков:

probe transaction__start(int);
probe transaction__commit(int);
probe transaction__abort(int);
probe lwlock__acquire(int, int);
probe lwlock__release(int);
probe lwlock__startwait(int, int);
probe lwlock__endwait(int, int);
probe lwlock__condacquire(int, int);
probe lwlock__condacquire__fail(int, int);
probe lock__startwait(int, int);
probe lock__endwait(int, int);

Воспользуемся датчиками transaction-start и transaction-end для получения распределения времени транзакций:

#!/usr/sbin/dtrace -Zqs
postgresql*:::transaction-start
{
self->ts=timestamp;
@cnt[pid]=count();
}
postgresql*:::transaction-commit
{
@avg[pid]=avg(timestamp - self->ts);
}
tick-5sec
{
normalize(@avg, 1000000);
printf("%15s %30s %30s\n","PID","Total queries","Avegrage time (ms)");
printf("\t=================================================\n\n");
printa("%15d %@30d %@30d\n",@cnt,@avg);
printf("\t=================================================\n\n");
clear(@cnt);
clear(@avg);
}

Запуск этого скрипта даст нам реальную картину затрат времени на транзакции. Возможно, в вашем случае распределение будет иным – все зависит от фактической загрузки сервера:

# ./postgres_avg_query_time.d
PID Total queries Avegrage time (ms)
==========================================================
23814 46 57
23817 58 34
23816 59 32
23815 59 33
23818 75 26
==========================================================

А теперь обратимся к уже хорошо знакомому нам провайдеру pid и напишем скрипт для отслеживания запросов к СУБД (обратите внимание: имя функции в postgresql иное, нежели в mysql ):

#!/usr/sbin/dtrace -Zwqs
BEGIN
{
freopen("sql.trace");
}
pid$1::pg_parse_query:entry
{
printf("%s\n",copyinstr(arg0));
}

Обратите внимание на вызов freopen("sql.trace") – так мы перенаправим вывод скрипта с экрана в файл с указанным именем.

В этой лекции мы познакомились с тем, как использовать DTrace для анализа различных приложений, в том числе приложений на javascript, Java, PHP и SQL. Фактически, это дает нам полный набор инструментов для отладки как клиентской части приложений Web 2.0, так и серверной их части.

Мы старались показать, что даже если какое-то приложение не имеет встроенных датчиков DTrace, вы всегда можете либо добавить их в исходный код (как уже сделали разработчики PostgreSQL, например), либо использовать известные вам функции для анализа передаваемых ими аргументов и возвращаемых значений – с помощью провайдера pid.

Еще более подробную информацию о DTrace можно почерпнуть в руководстве "Dynamic Tracing Guide", где приводится подробное описание этих провайдеров. Этот документ вкупе с "DTrace User Guide" содержит полную документацию по DTrace и находится в свободном доступе на сайте http://docs.sun.com/. Также можно посоветовать страницу сообщества разработчиков DTrace на cайте opensolaris.org: http://opensolaris.org/ os/community/dtrace.