Компания
242,68
рейтинг
16 августа 2012 в 13:14

Разработка → Мониторинг производительности PHP-кода с помощью Pinba

Давайте представим себе типичный, набирающий популярность стартап, использующий, например, PHP или Python. Сначала все находится на одном сервере — PHP (или Python), Apache, MySQL. Затем вы выносите MySQL на отдельный сервер, устанавливаете nginx для раздачи контента, возможно, добавляете memcached для кеширования и еще несколько серверов приложений…

Со временем число серверов будет расти, и рано или поздно вы зададитесь вопросами
«А что сейчас вообще происходит с системой? Как часто выполняется тот или иной скрипт и как долго? Какие операции занимают большую часть времени?» Системы мониторинга типа Zabbix дают лишь общую, поверхностную картину состояния приложения.

Чтобы получить ответы на эти вопросы, в Badoo был разработан сервиc мониторинга и статистики в реальном времени — Pinba. В данной статье мы расскажем о нашем опыте использования его для мониторинга и профайлинга нашей системы.

Пару слов о Badoo


Чтобы оценить уровень сложности задачи, опишем в нескольких словах, что представляет из себя Badoo. На сегодняшний день у нас функционируют 2 дата-центра, один — в Америке, второй — в Европе. В дата-центрах установлены сотни PHP-серверов, MySQL-серверов, десятки memcached и «самописных» сервисов, написанных на C/C++. Внутри Badoo существуют свои подпроекты (например, веб-сайт, приложения для мобильных устройств и рабочих столов), реализация и характер нагрузок на которые сильно различаются. В одном PHP-запросе могут происходить взаимодействия с десятками различных источников данных (база, кеш, сервис). Это плохо для производительности, но необходимо для решения поставленных бизнес-задач. И вдобавок к этому мы выкладываем новый код от 2 до 5 раз в неделю. Мониторинг производительности такой системы — непростая задача. Pinba помогла решить большой пласт проблем, связанных с мониторингом производительности PHP-скриптов. Данный сервис собирает информацию обо всех обработанных PHP-запросах и формирует подробные отчёты по этим данным.

Как всё работает


На Хабрахабре уже была статья о том, как начать работать с Pinba: «Pinba — мониторим php в реальном времени». В ней автор описал, как установить и настроить Pinba, поэтому сейчас мы сконцентрируемся на более интересных вещах: как это всё работает и какую информацию можно получить.

Общая схема работы с Pinba отображена на диаграмме:



Pinba состоит из PHP-модуля (англ. PHP extension) и сервера. Модуль Pinba автоматически шлёт данные обо всех обработанных запросах на сервер. Pinba-сервер — это сервис, написанный на С, который:
  • собирает по протоколу UDP данные об обработанных запросах;
  • хранит все эти данные в памяти и строит по ним отчёты;
  • предоставляет доступ к сырым данным и отчётам по протоколу MySQL, то есть фактически является MySQL engine.

Чтобы узнать, что происходит с системой в данный момент, достаточно соединиться с сервером любым MySQL-клиентом и сделать несколько запросов из таблиц-отчётов. Например, можно посмотреть статистику по запросам на каждый из PHP-скриптов (один из наиболее используемых отчётов в Pinba):
mysql> SELECT * FROM report_by_script_name;


Ниже мы подробнее опишем, как работать с отчётами в Pinba.

Как работает PHP-модуль для Pinba


Еще на этапе планирования первой версии сервиса Pinba сразу же возникла идея организации сбора общей статистики без внесения изменений в PHP-код. Люди, имеющие опыт написания PHP-модулей, знают, что последние имеют возможность выполнять некоторые действия перед каждым запросом (фаза PHP_RINIT) и после его обработки (фаза PHP_RSHUTDOWN). Например, в фазе PHP_RINIT модуль может инициализировать свои внутренние ресурсы, а в RSHUTDOWN — освободить их. PHP-модуль для Pinba использует обе эти фазы. В RINIT он инициализируется, в RSHUTDOWN — вычисляет, сколько ресурсов было потрачено на обработку запроса, а затем все данные отсылаются UDP-пакетом на Pinba-сервер.

Отправка UDP-пакета на C осуществляется достаточно быстро, поэтому модуль Pinba не добавляет в PHP-процесс дополнительной нагрузки. А за счет того, что Pinba работает в виде модуля, то достаточно установить и настроить его, и вы сразу же, без внесения изменений в PHP-код, сможете узнать такие параметры вашей системы, как количество запросов на каждый из скриптов, среднее время работы и многое другое.

К сожалению, если у вас сложная система, общих параметров будет недостаточно.

Таймеры


Изначально в первой версии Pinba (назовем её Pinba v0.1) не было таймеров. Эта версия могла сказать нам, как часто вызывается тот или иной скрипт, каково среднее время ответа, каков средний размер ответа в байтах и тому подобное. Нельзя было узнать частоту запросов к MySQL, memcached или другим сервисам. Вам может показаться это не столь критичным, но в нашей системе помимо MySQL и memcached используется еще с десяток различных сервисов, написанных на C/C++.

Если в системе появлялась проблема (например, что-то начинало «тормозить»), то Pinba v0.1 показывала нам, что проблема есть, но не всегда можно было быстро понять, в чем именно она заключается. Чаще всего в таких ситуациях виновным был какой-то из сервисов, к которому PHP делал запросы (MySQL, memcached и другие).

Чтобы научиться находить такие проблемные места быстро, в следующей версии Pinba были введены таймеры.

Фактически мы решили замерять время работы вызовов mysql_connect / mysql_query / memcache_connect и т.п., отсылать это время на Pinba-сервер и строить отчёты по таймерам. На псевдо-PHP-коде это выглядит примерно так:

pinba_timer_start(array('type'=>'db::connect', 'host'=>'users.sql'));
$conn = mysql_connect(...);
pinba_timer_stop();

Здесь мы замеряем время работы вызова mysql_connect и привзязываем к таймеру 2 тега, по которым впоследствии сможем строить отчёты.

Все таймеры вместе со всеми данными отсылаются на Pinba-сервер и там по ним строятся отчётные таблицы. Это позволяет увидеть, какие операции занимают больше всего времени в данный момент. Более того, если у вас, например, сотни MySQL-серверов и тормозит только один из них, Pinba позволяет легко вычислить тот самый проблемный сервер благодаря очень гибкой схеме отчётов по таймерам.

Начинаем работать с таблицами


Вот список таблиц, к которым Pinba дает доступ:

mysql> SHOW TABLES FROM pinba;
+--------------------------------------+
| Tables_in_pinba                      |
+--------------------------------------+
| info                                 | 
| report_by_hostname                   | 
| report_by_hostname_and_script        | 
| report_by_hostname_and_server        | 
| report_by_hostname_server_and_script | 
| report_by_script_name                | 
| report_by_server_and_script          | 
| report_by_server_name                | 
| report_by_status                     | 
| request                              | 
| tag                                  | 
| timer                                | 
| timertag                             | 
+--------------------------------------+
13 rows in set (0.00 sec)

Условно все таблицы можно разделить на 2 типа: таблицы с «сырыми» данными и отчёты.
Есть 4 таблицы с «сырыми» данными: request, tag, timer, timertag. Эти таблицы содержат запись о каждом вызове скрипта, таймера и тега за последние несколько минут. В высоконагруженных системах, эти таблицы могут содержать миллионы записей, поэтому мы не рекомендуем их использовать напрямую. Вместо этого лучше использовать таблицы-отчёты, которые содержат достаточно полезных данных для анализа производительности системы.

Таблицы отчётов


Report_by_script_name — один из наиболее используемых отчётов; содержит информацию о том, как часто вызывался каждый скрипт, среднее время его выполнения, использование им CPU, количество приходящегося на него трафика.

mysql> DESC report_by_script_name;
+------------------+--------------+------+-----+---------+-------+
| Field            | Type         | Null | Key | Default | Extra |
+------------------+--------------+------+-----+---------+-------+
| req_count        | int(11)      | YES  |     | NULL    |       | 
| req_per_sec      | float        | YES  |     | NULL    |       | 
| req_time_total   | float        | YES  |     | NULL    |       | 
| req_time_percent | float        | YES  |     | NULL    |       | 
| req_time_per_sec | float        | YES  |     | NULL    |       | 
| ru_utime_total   | float        | YES  |     | NULL    |       | 
| ru_utime_percent | float        | YES  |     | NULL    |       | 
| ru_utime_per_sec | float        | YES  |     | NULL    |       | 
| ru_stime_total   | float        | YES  |     | NULL    |       | 
| ru_stime_percent | float        | YES  |     | NULL    |       | 
| ru_stime_per_sec | float        | YES  |     | NULL    |       | 
| traffic_total    | float        | YES  |     | NULL    |       | 
| traffic_percent  | float        | YES  |     | NULL    |       | 
| traffic_per_sec  | float        | YES  |     | NULL    |       | 
| script_name      | varchar(128) | YES  |     | NULL    |       | 
+------------------+--------------+------+-----+---------+-------+
15 rows in set (0.00 sec)

Поля с суффиксом _total — это сумма соответствующих значений для всех запросов за последние 5 минут. То есть, например, req_time_total — это сумма времени выполнения всех запросов для соответствующего скрипта за последние 5 минут. А req_time_total/req_count — среднее время выполнения скрипта. Поля req_utime_* и req_stime_* показывают использование CPU в user mode и system mode соответственно.

В нашей компании по этим данным мы строим графики количества запросов к тому или иному скрипту и графики потребления CPU скриптами (графики 1, 2):

График 1.


График 2.


Report_by_hostname: данный отчёт показывает, сколько всего запросов идет на конкретный сервер. Он имеет почти такой же список полей, но вместо поля script_name таблица содержит поле hostname.

mysql> DESC report_by_hostname;
+------------------+-------------+------+-----+---------+-------+
| Field            | Type        | Null | Key | Default | Extra |
+------------------+-------------+------+-----+---------+-------+
| req_count        | int(11)     | YES  |     | NULL    |       | 
.........
| hostname         | varchar(32) | YES  |     | NULL    |       | 
+------------------+-------------+------+-----+---------+-------+
15 rows in set (0.00 sec)

Наверное, некоторые ожидали увидеть в переменной hostname домен, переданный в HTTP-заголовке Host. Но на самом деле hostname — это содержимое переменной $_ENV['HOSTNAME'] и содержит имя машины.

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

Report_by_server_name: в этом отчёте данные сгруппированы по домену, на который пришел запрос. Он показывает количество запросов, идущих на тот или иной домен. Структура таблицы такая же, как у предыдущих двух, только данные теперь сгруппированы по полю server_name.

Report_by_status: этот отчёт используется для просмотра HTTP-статусов, с которыми завершаются наши скрипты:

mysql>  SELECT req_count, status FROM report_by_status;
+-----------+--------+
| req_count | status |
+-----------+--------+
|    540622 |    200 | 
|      2578 |    301 | 
|     21955 |    302 | 
|       296 |    403 | 
|      2090 |    404 | 
+-----------+--------+
5 rows in set (0.14 sec)

Если в отчёте есть статус 500, то значит, что у нас где-то происходят «Fatal error» в PHP-коде.

Таймеры и теги


Отчёты, рассмотренные выше, полезны для общего анализа системы. Но для более детального анализа мы используем таймеры и теги.

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

pinba_timer_start(array('group'=>'db::connect', 'host'=>'users.sql'));
$conn = mysql_connect(...);
pinba_timer_stop();

мы замеряем время выполнения функции mysql_connect и привязываем 2 тега — group и host.

По умолчанию в Pinba нет никаких отчётов о таймерах и тегах, но она дает очень гибкие возможности по их созданию. Ниже рассмотрим подробнее, как это сделано в Badoo.

В первую очередь мы используем таймеры для получения статистики запросов к различным источникам данных: MySQL, memcached, сервисам, написанным на C/C++. Все такие запросы мы «обернули» Pinba-таймерами с двумя тегами: group и host (host — это адрес базы или сервиса, group — это операция над сервисом).

Итак, если мы внедрили в нашу систему тег, который отсылается в Pinba, мы можем построить несколько отчётов. Прежде всего это будет полный отчёт по всем значениям тега. В нашем примере с тегом group мы можем построить отчёт о том, как часто вызывается та или иная операция и сколько времени (суммарно) на неё уходит. Для этого нужно создать таблицу:

CREATE TABLE `tag_info_group` (
  `tag_value` varchar(64) DEFAULT NULL,
  `req_count` int(11) DEFAULT NULL,
  `req_per_sec` float DEFAULT NULL,
  `hit_count` int(11) DEFAULT NULL,
  `hit_per_sec` float DEFAULT NULL,
  `timer_value` float DEFAULT NULL
) ENGINE=PINBA DEFAULT CHARSET=latin1 COMMENT='tag_info:group'

Имя таблицы произвольное и ни на что не влияет. Важно, чтобы порядок полей был именно таким, как в примере, а также значения для ENGINE и COMMENT='tag_info:group'. В комментарии group — это имя тега, по которому мы создаем отчёт. А tag_info — это тип отчёта (есть еще tag_report, речь о котором пойдет ниже).

После создания таблицы Рinba автоматически начнет вносить туда данные. Этот отчёт будет иметь примерно такой вид:

mysql> SELECT * FROM tag_info_group ORDER BY timer_value;
+--------------------+-----------+-------------+-----------+-------------+-------------+
| tag_value          | req_count | req_per_sec | hit_count | hit_per_sec | timer_value |
+--------------------+-----------+-------------+-----------+-------------+-------------+
| curl_request       |     56216 |      281.08 |     56710 |      283.55 |     11977.3 | 
| memcache_get       |   2563499 |     12817.5 |  11462991 |       57315 |     6823.04 | 
| hsc_connect        |   2319186 |     11595.9 |   2870366 |     14351.8 |      6140.5 | 
| hsc_open_index     |   2319158 |     11595.8 |   3285335 |     16426.7 |     5805.61 | 
| hsc_select         |   2312567 |     11562.8 |   3158465 |     15792.3 |     5778.57 | 
| memcache_connect   |   2563064 |     12815.3 |   4007451 |     20037.3 |     2389.65 | 
| memcache_set       |    917102 |     4585.51 |   1616016 |     8080.08 |     1059.08 | 
| memcache_delete    |    600720 |      3003.6 |   2451872 |     12259.4 |     785.702 | 
| scribe_receive     |    382881 |     1914.41 |    975892 |     4879.46 |     382.522 | 
| hsc_update         |     84877 |     424.385 |     85287 |     426.435 |     317.637 | 
| hsc_insert         |     41564 |      207.82 |     41574 |      207.87 |     280.468 | 
| scribe_send        |    382894 |     1914.47 |    975892 |     4879.46 |     174.156 | 
| memcache_increment |     60817 |     304.085 |     88734 |      443.67 |     30.9102 | 
| memcache_add       |     14818 |       74.09 |     16281 |      81.405 |     4.71686 | 
| memcache_multi_get |      2543 |      12.715 |      2543 |      12.715 |     1.59621 | 
| hsc_delete         |         4 |        0.02 |         9 |       0.045 |    0.003373 | 
+--------------------+-----------+-------------+-----------+-------------+-------------+
16 rows in set (0.00 sec)

Например, из этого отчёта видно, что у нас есть какие-то очень медленные curl_request.

Отчеты типа tag_info дают общую картину по его использованию в системе. Чтобы более детально изучить, откуда вызываются те или иные операции, нужно построить такой же отчёт, но с группировкой по имени скрипта. Для этого в Pinba нужно создать такую таблицу:

CREATE TABLE `tag_report_group` (
  `script_name` varchar(128) DEFAULT NULL,
  `tag_value` varchar(64) DEFAULT NULL,
  `req_count` int(11) DEFAULT NULL,
  `req_per_sec` float DEFAULT NULL,
  `hit_count` int(11) DEFAULT NULL,
  `hit_per_sec` float DEFAULT NULL,
  `timer_value` float DEFAULT NULL
) ENGINE=PINBA DEFAULT CHARSET=latin1 COMMENT='tag_report:group'

Структура таблицы во многом похожа на предыдущий отчёт tag_info_group. Обратите внимание на то, что появилось поле script_name, и в поле COMMENT мы создали отчёт типа tag_report. Из этой таблицы мы можем получить все те же данные, что и из предыдущей, но сгруппированные по script_name.

Можно посмотреть, какие операции выполняются в том или ином скрипте:

mysql> SELECT tag_value, req_count, hit_count, timer_value, hit_count/req_count FROM tag_report_group WHERE script_name='/admin/messages/all.phtml' ORDER BY timer_value DESC;
+--------------------+-----------+-----------+-------------+---------------------+
| tag_value          | req_count | hit_count | timer_value | hit_count/req_count |
+--------------------+-----------+-----------+-------------+---------------------+
| memcache_get       |    107439 |   3227537 |     1060.68 |             30.0406 | 
| memcache_connect   |    107439 |    887789 |     270.919 |              8.2632 | 
| scribe_receive     |    107573 |    283478 |     68.9106 |              2.6352 | 
| memcache_set       |     34339 |    153080 |     50.6079 |              4.4579 | 
| scribe_send        |    107573 |    283478 |     39.7583 |              2.6352 | 
| memcache_delete    |     18236 |     21306 |     4.54436 |              1.1683 | 
| curl_request       |        15 |        15 |    0.514396 |              1.0000 | 
| memcache_decrement |      1250 |      1250 |    0.251141 |              1.0000 | 
| memcache_multi_get |       125 |       125 |    0.066473 |              1.0000 | 
| memcache_increment |         2 |         2 |    0.000336 |              1.0000 | 
+--------------------+-----------+-----------+-------------+---------------------+
10 rows in set (0.03 sec)

В этом примере показана разница между полями hit_count и req_count. Req_count — это число HTTP-запросов, во время обработки которых хотя бы один раз был вызван таймер с указанным tag_value. Hit_count — сколько раз всего был вызван таймер с указанным tag_value.

В примере выше видно, что в нашем скрипте /admin/messages/all.phtml в среднем 30 раз вызывается memcache_get. Скорее всего это ошибка программиста, и страница нуждается в оптимизации.

Если у вас много серверов баз данных, memcached и других сервисов, то возможны случаи, когда «тормозит» только один сервер. И его «торможение» на общем фоне может быть не очевидным. Для этих целей мы сделали еще один тег с именем server. Для него можно создать общий отчёт tag_info:server и посмотреть общую статистику для каждого хоста. Вот пример данных для memcached-статистики:

mysql> SELECT * FROM tag_info_server WHERE tag_value LIKE 'memcache%' ORDER BY timer_value;
+------------------+-----------+-------------+-----------+-------------+-------------+
| tag_value        | req_count | req_per_sec | hit_count | hit_per_sec | timer_value |
+------------------+-----------+-------------+-----------+-------------+-------------+
| memcached7.mlan  |    350702 |     1753.51 |   1767513 |     8837.57 |     781.644 | 
| memcached3.mlan  |    336217 |     1681.08 |   1734430 |     8672.15 |     871.633 | 
| memcached1.mlan  |    350082 |     1750.41 |   1823910 |     9119.55 |      883.52 | 
| memcached8.mlan  |    357798 |     1788.99 |   1793808 |     8969.04 |     908.848 | 
| memcached10.mlan |    343287 |     1716.44 |   1757085 |     8785.42 |     909.042 | 
| memcached5.mlan  |    398042 |     1990.21 |   1861729 |     9308.64 |     914.772 | 
| memcached4.mlan  |    401584 |     2007.92 |   1877775 |     9388.88 |      937.53 | 
| memcached2.mlan  |    459912 |     2299.56 |   2028406 |       10142 |     971.189 | 
| memcached6.mlan  |    399768 |     1998.84 |   1912571 |     9562.86 |     975.094 | 
| memcached9.mlan  |    425276 |     2126.38 |   1939575 |     9697.88 |     1008.29 | 
+------------------+-----------+-------------+-----------+-------------+-------------+
10 rows in set (0.00 sec)

Общий отчёт по тегу host недостаточно информативен. Он показывает частоту вызова таймеров с тем или иным хостом, но без информации о производимых операциях. К счастью, Pinba умеет создавать отчёты типа tag_info и tag_report с группировкой по 2 тегам:

CREATE TABLE `tag_info_group_server` (
  `group_value` varchar(64) DEFAULT NULL,
  `server_value` varchar(64) DEFAULT NULL,
  `req_count` int(11) DEFAULT NULL,
  `req_per_sec` float DEFAULT NULL,
  `hit_count` int(11) DEFAULT NULL,
  `hit_per_sec` float DEFAULT NULL,
  `timer_value` float DEFAULT NULL
) ENGINE=PINBA DEFAULT CHARSET=latin1 COMMENT='tag2_info:group,server'

Данный отчёт позволяет получить статистику операций над каждым хостом. Например, можно посмотреть статистику операций на определенном хосте:

mysql> SELECT * FROM tag_info_group_server WHERE server_value = 'dbs101.mlan' ORDER BY timer_value;
+-------------+--------------+-----------+-------------+-----------+-------------+-------------+
| group_value | server_value | req_count | req_per_sec | hit_count | hit_per_sec | timer_value |
+-------------+--------------+-----------+-------------+-----------+-------------+-------------+
| db::replace | dbs101.mlan  |       154 |        0.77 |       154 |        0.77 |    0.257526 | 
| db::delete  | dbs101.mlan  |      1340 |         6.7 |      1340 |         6.7 |     1.84398 | 
| db::begin   | dbs101.mlan  |      6437 |      32.185 |      6589 |      32.945 |     2.96375 | 
| db::commit  | dbs101.mlan  |      6437 |      32.185 |      6589 |      32.945 |     3.04067 | 
| db::insert  | dbs101.mlan  |      4674 |       23.37 |     11171 |      55.855 |     13.9457 | 
| db::update  | dbs101.mlan  |      6358 |       31.79 |     10399 |      51.995 |      18.197 | 
| db::connect | dbs101.mlan  |     16826 |       84.13 |     16826 |       84.13 |     22.1383 | 
| db::select  | dbs101.mlan  |     14372 |       71.86 |     47106 |      235.53 |     180.235 | 
+-------------+--------------+-----------+-------------+-----------+-------------+-------------+
8 rows in set (0.01 sec)

По понятным причинам, именно SELECT занимают большую часть времени.

Также, например, можно сравнить статистику для одной и той же операции на разных хостах. Пример для memcache_connect:

mysql> SELECT server_value, req_count, hit_count, timer_value FROM tag_info_group_server WHERE group_value='memcache_connect' ORDER BY timer_value;
+------------------+-----------+-----------+-------------+
| server_value     | req_count | hit_count | timer_value |
+------------------+-----------+-----------+-------------+
| memcached1.mlan  |    366138 |    365061 |     191.808 | 
| memcached3.mlan  |    354688 |    353760 |     192.184 | 
| memcached10.mlan |    365358 |    364341 |     197.353 | 
| memcached8.mlan  |    368912 |    367839 |     213.768 | 
| memcached7.mlan  |    374160 |    373152 |     215.914 | 
| memcached5.mlan  |    415444 |    414434 |     217.855 | 
| memcached4.mlan  |    423394 |    422242 |     252.416 | 
| memcached2.mlan  |    478949 |    477641 |     272.346 | 
| memcached6.mlan  |    414088 |    413003 |     279.038 | 
| memcached9.mlan  |    441589 |    440481 |     377.952 | 
+------------------+-----------+-----------+-------------+
10 rows in set (0.01 sec)

Ещё можно сделать отчёт типа tag2_report, в котором информация по 2 тегам разбита по скриптам:

CREATE TABLE `tag_report_group_server` (
  `sc0зript_name` varchar(128) DEFAULT NULL,
  `tag1_value` varchar(64) DEFAULT NULL,
  `tag2_value` varchar(64) DEFAULT NULL,
  `req_count` int(11) DEFAULT NULL,
  `req_per_sec` float DEFAULT NULL,
  `hit_count` int(11) DEFAULT NULL,
  `hit_per_sec` float DEFAULT NULL,
  `timer_value` float DEFAULT NULL
) ENGINE=PINBA DEFAULT CHARSET=latin1 COMMENT='tag2_report:group,server'

Приведем пример, где эта таблица может быть полезной. В нашей системе все пользователи распределены между сотнями MySQL-серверов. Это называется «шардинг». Также есть определенные центральные MySQL-сервера для специфических задач. В теории все веб-скрипты должны делать запросы только на «шарды» и не делать запросы на центральные базы. Hostname наших «шардов» начинается на dbs* или dbb*. Проверить, есть ли скрипты, делающие коннекты на другие MySQL-сервера, можно вот таким запросом:

mysql> SELECT * FROM tag_report_group_server WHERE tag1_value='db::connect' AND tag2_value NOT LIKE 'dbs%' AND tag2_value NOT LIKE 'dbb%';

Он покажет какие скрипты делают запросы на центральные базы данных.

nginx + Pinba


Но даже всего этого нам оказалось недостаточно. Когда клиент шлёт нам HTTP-запрос, то последний сначала попадает в nginx и далее проксируется в PHP. Что будет, если PHP-процесс в этот момент не может принять и обработать запрос? Например, если сервер перегружен, или в следствие сетевых проблем nginx не сможет связаться с php-fpm процессом? Пользователь в этом случае увидит ошибку, а мы в PHP о ней не узнаем (правда, она будет в логах nginx).

Для того, чтобы иметь представление о том, какие ответы (какие HTTP-статусы) мы возвращаем клиенту, разработчик Pinba Антон Довгаль сделал модуль для nginx. Модуль для nginx работает также, как и PHP-модуль, но по понятным причинам не имеет таймеров. Наиболее полезные отчёты, которые он делает — report_by_script_and_status и report_by_status.

Построение графиков


Pinba хранит данные за последние несколько минут. Это время можно поменять в настройках. Но этого недостаточно, если вы хотите следить за тем, как со временем меняется производительность системы. Для этого нужно хранить данные отчётов Pinba (не обязательно всех) за продолжительное время и строить по ним графики. Таким образом можно наблюдать динамику изменения нагрузки на системы и на отдельные ее скрипты, а также отслеживать, как ваш PHP-код нагружает базы, memcached и другие источники данных.

Pinba не умеет строить графики и хранить данные за долгий период. Для этого нужно использовать отдельные утилиты. Можно настроить Zabbix, чтобы он мониторил Pinba и строил графики по каким-то её значениям. Можно использовать кольцевые (циклические) базы данных типа RRDtool или Graphite. В нашей компании мы используем RRDtool.

RRDtool не описать в двух словах. У него много своих нюансов, и у разных людей разные предпочтения в построении графиков, поэтому эта тема достойна отдельной статьи. В интернете уже достаточно руководств, которые помогут вам с нуля начать работу с этим набором утилит.

Результаты


Что же нам дала Pinba? Большинство проблем производительности стали выявляться намного быстрее, чем до её внедрения. Если какой-то скрипт стал намного чаще запрашиваться пользователями, он легко может быть найден в Pinba. Если вдруг какой-то из сервисов (MySQL, memcached и т.п.) стал медленней работать, то при наличии правильных отчётов в Pinba можно легко локализовать этот сервис. А если он стал «тормозить» из-за высокой частоты запроса, то благодаря Pinba иногда можно локализовать скрипты, часто запрашивающие конкретный проблемный сервис.

Очень полезно смотреть графики Pinba после выкладки новой версии кода на сервера. Можно увидеть, как поменялась нагрузка на систему. Но для этого важно продумать, какие графики будут строиться.

Однако не стоит воспринимать Pinba как замену полноценному мониторингу серверов. Мы, например, используем Zabbix для мониторинга потребления CPU, памяти, дисков и сетевой активности на всех серверах. С другой стороны, есть Pinba с графиками в RRD. Сопоставляя графики из этих двух систем, можно легко посчитать «стоимость» PHP-запроса и оценить, сколько запросов в секунду способны обработать ваши сервера. А это, в свою очередь, позволяет спланировать, нужны ли закупки новых серверов в ближайшее время или же есть возможности для оптимизации кода.

Не считая PHP-модуля, Pinba никак не завязана на PHP и может использоваться для мониторинга систем, написанных на других языках. На GitHub уже есть проекты по использованию Pinba в Python и Ruby.

Максим max_m Матюхин, разработчик
компания Badoo


Полезные ссылки


Автор: @Badoo
Badoo
рейтинг 242,68

Комментарии (63)

  • 0
    Макс =) привет, попробуйте графит =) штука очень клевая =) гораздо гибче чем RRDTool настраивается… единственное под ваш объем данных диски нужны хорошие…
    • 0
      Мне вообще вот эта штука нравится opentsdb.net/
      Судя по презентации проект интересный, но на практике не пробовали
  • 0
    кстати, что насчет Nginx модуля? я правильно понимаю что аггрегации для данных собираемых с nginx надо поднимать отдельный Instance pinba?
    • 0
      Разные источники данных — разные инстансы, да.
      Технически смешивать никто не мешает, но смысла в этом мало — получится «в среднем по больнице 36.6».
      Поэтому у нас отдельные инстансы под FPM, CLI, nginx и еще по кластерам сервисов.
  • –1
    Платная?
    • +2
      бесплатная
    • +8
      GPL
      Оплата патчами =)
      • 0
        Фичереквесты принмаете? :)
        • 0
          Конечно. А фичереквесты с патчами — так вообще без проблем.
  • 0
    Спасибо за очередную отличную статью! Вы молодцы, что делитесь своими наработками.
    • 0
      Всегда пожалуйста. Кстати если есть пожелания, о чем бы вам было интересно прочитать, можете оставлять их здесь.
      • 0
        Расскажите про ваш внутренний php-framework: какие особенности, шаблоны проектирования, приёмы в нём используются, в целом про качество и тестируемость кода. Может быть уже где-то есть почитать даже?
        • 0
          Спасибо, подумаем.
          Насчет качества и тестируемости кода. Недавно наш девелопер на www.itmozg.ru/high-performance-conference/ делал доклад о том как, мы расскладываем код. Частично эта тема затрагивает качество кода и тестируемость. Вроде бы в течение нескольких недель организаторы опубликуют видео докладов, так что следите за анонсами.
        • 0
          на Хайлоаде fisher говорил, что у них нет ни какого фреймворка.
          уже что-то изменилось?
          • 0
            Возможно, у Фишера более строгие требования к тому, что называть фреймворком :)
            Наверное просто по разному трактуем этот термин
          • 0
            На мастер-классе от fisher слышал именно в такой формулировке.
            • 0
              а можно с этого момента и поподробнее?
              • 0
                Больше мне ничего не известно, поэтому и спросил.
  • 0
    есть потребность мониторить Сишный модуль,
    сейчас думаю над использованием pinba
    • +1
      Не знаю какой тупица минуснул, но не вижу принципиального различия, что мониторить РНР код или Сишный модуль.
      Обмен идет по protobuf протоколу, который вполне может сформировать Сишный модуль.
      Не вижу трудностей отправки его по UDP.
      Модуль так же принимает разные урлы, производительность которых нужно промониторить, правда хост один…
      Модуль обращается к мускульным базам, мемкешам и прочим демонам…
      почему бы не использовать pinba-engine для приема и анализа статистики???
  • 0
    Можно использовать кольцевые (циклические) базы данных типа RRDtool или Graphite.

    Ну, строго говоря, у Graphite кольцевая база называется Whisper. Сам Graphite — это несколько больше, чем просто база. Утрируя, можно сказать, что Graphite = Carbon + Whisper. Ну и еще graphite-web сбоку, конечно :)
  • 0
    Получается для анализа приложений с Front Controller не очень система пригодна? Или в script_name учитываются все include/require?
    • 0
      А для таких случаев есть pinba.org/wiki/Manual:PHP_extension#pinba_script_name_set.28.29
      • 0
        Я имел в виду «сбор общей статистики без внесения изменений в PHP-код», так-то сразу мысль мелькнула об использовании тэгов для этого.
        • +1
          Нет, без внесения изменений никак не выйдет. Если у вас работает один скрипт, то его вы везде и увидите, а как по-другому?
          • 0
            Вместо занесения $SERVER['SCRIPT_NAME'] заносить URL? Вернее даже не URL, а классифицировать URL'ы по маске (утрируя /company/*/blog/* /post/* и т. п.) и заносить маску.
            • 0
              это всё очень неочевидная магия которая будет работать далеко не всегда
              Проще одну строчку кода добавить в то место где определяется, какой контроллер должен выполняться
              • 0
                Зачастую это определяется во внутренностях фреймворка, который далеко не все готовы «патчить». А насчёт не всегда — можно позаимствовать механизм определения location у nginx и заносить его имя. Ещё не встречал ситуаций, чтобы он не справился, вплоть до таких, наверное, экзотических как направление запроса /index.php?page=user&mode=view&id=* в обработчик рельсового приложения с приведением к /user/*
                • 0
                  Ну, технически мы всё-таки профайлим не УРЛы, а скрипты.
                  И, соотв-но, результат index.php — совершенно верный. Это именно он выполняется N раз в секунду и именно его надо оптимизировать, а не /user/profile/view или тому подобное.
                  • 0
                    Просто для приложений с единой точкой входа время выполнения index.php может различаться на порядки для отдачи (псевдо)статической страницы и для страницы требующей, например, десятков, если не сотен обращений к БД. Без информации об урле время выполнения скрипта почти ничего не скажет — оно может отличаться на порядки.
                    • 0
                      Честно говоря, не понимаю о чем мы сейчас говорим =)
                      Вопрос решается одной строкой, не надо никаких location и т.п.
                      • 0
                        Одной строкой в коде фреймворка…
                        • 0
                          Зачастую в фреймворках предусмотрены механизмы вызова пользовательского кода на различных стадиях, надо лишь копнуть чуть глубже. Например в питоне это стандартизировано и делается с помощью middleware. В пхп стандарта нет и каждый фреймворк делает по-своему.

                          pinba_script_name_set() _необязательно_ вызывать в самом начале, можно и в конце скрипта
  • +1
    Ребята, а когда вы допилите пакеты на .deb? Оно вывается на debian 6 при попытке установиться, т.к. в dotdeb mysql 5.5, а у вас requirement 5.1. Я бы с удовольствеим использовал, но не хочу заниматься самостоятельной поддержкой компиляции и разворачивать компиляторы на боевых серверах.
    • 0
      Так на dotdeb.org лежит собранная pinba.
      • 0
        битый:

        root@web:~# apt-get install pinba-mysql-engine
        Reading package lists… Done
        Building dependency tree
        Reading state information… Done
        Some packages could not be installed. This may mean that you have
        requested an impossible situation or if you are using the unstable
        distribution that some required packages have not yet been created
        or been moved out of Incoming.
        The following information may help to resolve the situation:

        The following packages have unmet dependencies:
        pinba-mysql-engine: Depends: mysql-server (= 5.1.62-1~dotdeb.0)
        E: Broken packages
        • 0
          Так а что мешает отдельный сервер с Пинбой держать на 5.1? Это же зависимость только для сервера, клиентская библиотека зависимости от MySQL-сервер не имеет.
          • 0
            стоимость аренды серверов около ~800$ в месяц. До кучи, пакет 5.1.62-1~dotdeb.0 вообще уже из dotdeb выпилен, и поставить даже с 5.1 не представляется возможным.
            • 0
              Собрать MySQL и пинбу из исходников — это 10 минут времени от силы.
              Вы больше времени на поиск .deb потратили.
              • 0
                … и 300 метров говна на сервере :)
        • 0
    • 0
      Если вы можете сделать пакеты — сделайте, я поставлю на офиц. сайте ссылку на ваш репозиторий.
      Я лично дебиан не использую и у меня такой необходимости нет.

      >разворачивать компиляторы на боевых серверах

      Непонятно зачем это делать. Соберите бинарник 1 раз и скопируйте его везде.
      Одна проблема — версия пакета mysql должна быть везде идентична.
      • 0
        да, а я имею привычку ставить security update.
        • 0
          Простите, а зачем ставить security update на то, что никто кроме вас видеть не будет?
          Отключите доступ по сети, оставьте только unix-сокет и используйте этот инстанс mysql только для сбора данных пинбы.
          От кого тут защищаться надо?
          • 0
            Это одна из поддерживающих баз. На ней нет продакшена, но требуется 5.5.

            Что за привычка объяснять «вам это не надо» на вопрос «как»?
            • 0
              я еще раз повторяю: используйте этот инстанс mysql только для сбора данных пинбы.
              а у вас откуда привычка хамить тем, кто вам пытается помочь?
              • 0
                Это не хамство, с моей точки зрения, совет «а ты не обновляй» иногда звучит как «а ты, когда гости придут, закрой спальню чтобы не убираться лишний раз».
      • 0
        оно под 5.5 вообще компилится?
        • 0
          оно вообще под 5.5 компилится.
          и под 5.6 тоже.
          спасибо, что спросили.
    • 0
      twitter.com/dotdeb/status/236412408615284736
      по многочисленным просьбам товарищей.
  • +1
    Активно используем пинбу в течении последних 2х лет. Сразу как-то не понравилась зависимость от MySQLя, т.к. хотели хранить данные и иметь возможность мониторить работу в реальном времени.

    В итоге был сделан свой демон: github.com/aryoh/pinba2zmq — слушает пинбу и отдает данные в zmq сокет раз в секунду. Теоретически можно и чаще, но нафига? :)

    Написан на питоне, установка может показаться нетривиальной. Работает в продакшене на слабенькой vps'ке уже года полтора, сейчас держит нагрузку в 10к запросов к пхп в секунду, с 35-40к таймеров.

    С него данные потом собираются и сохраняются в постоянное хранилище, плюс можно смотреть данные онлайн. Пример «клиента»:

    #!/usr/bin/env python
    
    from gevent_zeromq import zmq
    import ujson
    
    def pinba_slow():
        context = zmq.Context()
        sub = context.socket(zmq.SUB)
        sub.connect("tcp://[хост с pinba2zmq]:5000")
        sub.setsockopt(zmq.SUBSCRIBE, '')
        try:
            while True:
                ts, requests = ujson.decode(sub.recv())
                cnt = 0
                for info in requests:
                    (hostname, server, script), (rps, request_size, request_time), timers = info
                    cnt = cnt + rps
                print ts, 'requests per second:', cnt
        except KeyboardInterrupt:
            pass
    
    if __name__ == '__main__':
        pinba_slow()
    


    Буду рад если кому-то ещё он будет полезен :)
    В дальнейшем надеюсь выложим в опенсорс и вывод графиков и остальные компоненты системы.
    • 0
      Сразу как-то не понравилась зависимость от MySQLя, т.к. хотели хранить данные и иметь возможность мониторить работу в реальном времени. Не понял вот эту фразу. Вы хотели хранить все данные за все время?
      • 0
        Да, хотим хранить данные за всё время.
        Само собой архивные данные группируются за бОльший интервал, но цель была хранить данные за максимальный срок для анализа того как у нас меняются показатели с течением времени.
        Например стали ли наши скрипты за год работать лучше или хуже.
        • 0
          мы для этих целей используем rrdtool
          Храним там даннные отчетов за последние пол-года.
          • 0
            Если бы всё было так просто :) Пробовали, не подошло по кучи разных причин.
            Но основной плюс данного демона — возможно посмотреть что происходит (тормозит) вот прям сейчас.
            • 0
              возможно посмотреть что происходит (тормозит) вот прям сейчас.
              pinba ведь тоже это показывает. Или вы хотите агрегировать данные посекундно?
              • 0
                Да, посекундно. Пинба это да показывает, но не дает возможности по простому получать секундные среды, кроме как раз в секунду вычитывать новые записи из таблиц, что не очень удобно. Плюс не очень удобна работа с таймерами и «отчётами» по таймерам — нужно заранее сделать отчёты (и в случае с ррд графики по ним), в моем случае я всегда могу посмотреть что было пол-часа назад имея все данные и имея возможность делать какие угодно отчёты.
            • 0
              Не совсем понятно что вы понимаете под «прямо сейчас».
              Пинба тоже хранит данные за «прямо сейчас и за N секунд до этого».
              Чем меньше период хранения данных, тем меньше получается «инерция» графиков и тем более актуальны они на данный момент.
              А чем ваш демон отличается?
              • 0
                Вот в первую очередь не хватает банального таймстемпа у запросов (его же нет, да?). Из-за этого я не могу получить точных секундных срезов. Во всяком случае по простому.
                В моем случае я имею источник секундных «сырых» данных, которые потом как угодно используются. Хоть для реалтаймовых графиков, хоть для хранения с последующей агрегацией.
                • 0
                  >Вот в первую очередь не хватает банального таймстемпа у запросов (его же нет, да?).
                  Да и вполне намеренно — я не смог найти ему ни одного применения.
      • 0
        К слову как раз смотрю в сторону OpenTSDB как более удобное хранилище.
        • 0
          Лушче посмотрите в сторону graphite + megacarbon
  • 0
    Одна из немногих статей которую я продолжил читать после первых двух предложений. Вот такое начало — лучшее начало для поста!

Только зарегистрированные пользователи могут оставлять комментарии. Войдите, пожалуйста.

Самое читаемое Разработка