Мониторинг приложений с помощью Pinba

Привет! Мы в Badoo стараемся активно участвовать в жизни IT-сообщества: используем многие open-source-технологии и инструменты, а также делимся своими разработками.

Один из таких инструментов – Pinba – сервис для получения realtime-статистики от работающих приложений без накладных расходов на её сбор. Узнать побольше вы можете в этой статье.

Мы стараемся помочь всем, кто использует Pinba в своих проектах и всегда рады слышать success stories, связанные с Pinba. Этот перевод – одна из подобных историй от разработчиков Dailymotion.

Введение

Для мониторинга, анализа и оптимизации своих приложений компания Dailymotion использует множество инструментов, таких как StatsD, Graphite, collectd и Datadog. Но есть среди них и менее известный — Pinba (расшифровывается как PHP Is Not a Bottleneck Anymore).

В настоящее время мы работаем над миграцией устаревшего монолитного PHP-приложения с большим количеством legacy-кода. Вместо него планируется развернуть несколько современных микросервисов. С помощью Pinba мы собираем:

• данные о текущем PHP-приложении. Это позволяет эффективнее выполнять обслуживание и развертывание (выявлять релизы, отрицательно влияющие на производительность), а также находить и анализировать возможные проблемы. К тому же полученные данные помогают определить, какие компоненты платформы стоит улучшать в первую очередь, чтобы получить наибольший прирост производительности;

• данные о новых микросервисах. Причем, в зависимости от языка разработки (в настоящее время это Python или Go), мы используем различных клиентов (хотя для них есть клиенты «из коробки» — прим. пер.).

Что такое Pinba?

Создатель Pinba, tony2001, описывает его так:

«Это сервер статистики, использующий MySQL в качестве интерфейса. Pinba собирает и обрабатывает данные, передаваемые множеством процессов PHP по протоколу UDP, а затем отображает статистику в виде простых и понятных отчетов. Кроме того, с помощью специального интерфейса можно получить доступ к необработанным данным в режиме «только для чтения», чтобы сформировать более подробные отчеты».

Как это работает?

Расширение Pinba для PHP установлено на всех серверах нашей веб-фермы. Оно собирает технические данные для каждого потока PHP и, после того как ответ отправлен клиенту, отправляет полученные метрики на центральный сервер Pinba через UDP (используется формат обмена данными Google Protobuf). На центральном сервере движок Pinba агрегирует содержимое этих сообщений и, прикидываясь read-only движком MySQL, предоставляет данные в виде таблиц, которые можно просматривать и делать по ним любые выборки с помощью любого знакомого вам клиента MySQL. Удобно и эффективно.

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

Конечно, Pinba не панацея и не решит всех проблем. Одна из распространенных ошибок связана с использованием этого сервиса для сбора точных данных (например, в качестве счетчика событий, имевших место за последнюю минуту). Сервис Pinba не предназначен для такого рода задач (как вы уже знаете, в целях повышения производительности сообщения protobuf отправляются через UDP, поэтому некоторые пакеты могут теряться по пути). Используйте этот инструмент для отслеживания тенденций, он не подходит для точной количественной оценки действий.

Наша архитектура

Какие метрики можно отслеживать с помощью сервиса?
Спектр технических метрик, отслеживаемых по умолчанию во всех процессах PHP, очень широк:

• doc_size — размер ответа;

• mem_peak_usage — выделенная память (максимальный объем);

• request_time — время, затраченное на создание процесса (обработку microsend);

• ru_utime/ru_stime — статистические данные об использовании ресурсов сервера (пользователем и системой);

• status — код ответа HTTP;

• memory_footprint — объем памяти, занимаемой процессом.

Движок хранит метрики для каждого процесса в таблице request, выделяя по одной строке для каждого ответа PHP за последние pinba_stats_history секунды (в нашем случае — 60 секунд).

mysql> SELECT script_name, doc_size, mem_peak_usage, status, memory_footprint, hostname  
FROM request  
LIMIT 10;  

script_name	doc_size	mem_peak_usage	status	memory_footprint	hostname
[PROD]video_item	5.422	10240	200	54728	web-065
[PROD]widget_dispatch_v3	38.056	14848	200	31624	web-031
[PROD]video_list	154.369	20736	200	87176	web-004
[PROD]rest_api	0.235	22784	200	51568	web-128
[PROD]rest_api	9.306	34048	200	55624	web-024
[PROD]rest_api	5.448	35072	200	54676	web-041
[PROD]controller_dispatch	2.003	11776	200	36388	web-033
[PROD]widget_v3_chunks	22.525	12544	200	33544	web-165
[PROD]cdn_director	0	9984	302	42892	web-034
[PROD]rest_api	0.019	20736	200	32500	web-085

Таблица request содержит метрики для каждого процесса PHP, и получить доступ к необработанным данным может быть довольно сложно в случае интенсивного трафика:

mysql> SELECT COUNT(1) from request; 

COUNT(1)
1197502

То есть в рамках всей нашей веб-фермы за 60 секунд было сгенерировано 1 197 502 ответа PHP.

К счастью, движок параллельно выполняет моментальную агрегацию, помещая сводные метрики в таблицу report_ *. Метрики, сгруппированные по значению в поле script_name, находятся в таблице report_by_script_name, поэтому мы можем анализировать метрики для конкретных значений script_name. Например, мы можем получить статистические данные о десяти наиболее часто вызываемых маршрутах:

mysql> SELECT script_name, req_count, req_per_sec, memory_footprint_total, req_time_median  
FROM report_by_script_name  
ORDER BY req_count DESC  
LIMIT 10;  

script_name	req_count	req_per_sec	memory_footprint_total	req_time_median
[PROD]rest_api	276508	4608.47	12916600000	0.0514983
[PROD]embed_player	162808	2713.47	8074990000	0.109837
[PROD]cdn_director	122526	2042.1	5103160000	0.0280768
[PROD]widget_dispatch_v3	105822	1763.7	4349350000	0.049904
[PROD]history_logger	98481	1641.35	4060860000	0.0127946
[PROD]video_item	66250	1104.17	3563420000	0.254091
[PROD]autocomplete_list	56313	938.55	2322790000	0.0104993
[PROD]webapp_ads_mopub	52187	869.783	2183980000	0.0326299
[PROD]gravity_report	45992	766.533	1895290000	0.0167253
[PROD]player_data	33584	559.733	1724540000	0.113651

Мы также можем вычислить средний объем выделенной памяти, просто выполнив запрос

memory_footprint_total/req_count AS avg_mem_footprint

По умолчанию движок еще и консолидирует метрики в нескольких других удобных таблицах:

• report_by_server_name;

• report_by_hostname;

• report_by_server_and_script;

• report_by_hostname_and_server;

• report_by_hostname_server_and_script.

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

mysql> SELECT hostname, server_name, script_name, req_count, req_per_sec, req_time_median  
FROM report_by_hostname_server_and_script  
ORDER BY req_count DESC  
LIMIT 2; 

hostname	server_name	script_name	req_count	req_per_sec	req_time_median
web-121	api.dailymotion.com	[PROD]api_oauth_token	4144	69.0667	0.0104435
web-038	api.dailymotion.com	[PROD]rest_api	3455	57.5833	0.0441618

Сбор собственных метрик

Как вы видите, Pinba предоставляет много полезной информации без дополнительных настроек, но это далеко не всё! Помимо таблиц отчетов вы можете использовать таблицы tagreport*. Метрики консолидируются в этих таблицах в соответствии со значениями тегов, которые вы определяете в своем коде.

Например, в старой базе кода Dailymotion у нас два вида тегов:

• I/O: любой доступ извне, блокировка выполнения процесса (доступ к
  серверам типа MySQL, Elastic, Redis, memcached или внешним API,
  например, Facebook или Twitter);

• algo: алгоритмы, за которыми мы хотим наблюдать.

Например, для memcache мы используем теги следующим образом:

код клиента

$pinbaTimer = $this->pinbaService->startTimer([
        'group' => 'memcached',
        'memcached' => $this->pinba_pool,
        'method' => 'get',
        'namespace' => 'dm_cache'
]);
$value = $this->memcache->get($this->prefix . $key);
$this->pinbaService->stopTimer($pinbaTimer);

сервис Pinba

public function startTimer(array $tags) {  
    if (!$this->isPinbaInstalled) {
        return null;
    }

    $timerId = 't' . ++$this->incr;
    $this->timers[$timerId] = pinba_timer_start($tags);
    return $timerId;
}

public function stopTimer($timerId) {  
    if ($this->isPinbaInstalled && isset($this->timers[$timerId])) {
         pinba_timer_stop($this->timers[$timerId]);
        unset($this->timers[$timerId]);
    }
}

Затем мы создаем пользовательские таблицы в базе данных Pinba, с помощью комментариев объясняя движку, что в них хранить.

Например, так выглядит таблица для хранения метрик, характеризующих использование memcached:

CREATE TABLE `tag_report_memcached_method_namespace` (  
  `script_name` varchar(128) DEFAULT NULL,
  `memcached` varchar(64) DEFAULT NULL,
  `method` varchar(64) DEFAULT NULL,
  `namespace` 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,
  `timer_median` float DEFAULT NULL,
  `index_value` varchar(256) DEFAULT NULL
) ENGINE=PINBA DEFAULT CHARSET=latin1 COMMENT='tagN_report:memcached,method,namespace';

А так — таблица для хранения метрик о параметрах ввода-вывода приложения:

CREATE TABLE `tag_report_group_method` (  
  `script_name` varchar(128) DEFAULT NULL,
  `group` varchar(64) DEFAULT NULL,
  `method` 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,
  `timer_median` float DEFAULT NULL,
  `index_value` varchar(256) DEFAULT NULL
) ENGINE=PINBA DEFAULT CHARSET=latin1 COMMENT='tag2_report:group,method';

Примечание для себя: в следующий раз не использовать зарезервированные слова SQL (group, ...) в качестве имен столбцов.

Эти таблицы позволяют нам получить подробные статистические данные, например, обо всех операциях ввода-вывода для конкретного маршрута:

mysql> SELECT `group`,  
    SUM(req_count) AS req,
    AVG(timer_median) AS timer_median,
    SUM(timer_value)/SUM(hit_count) AS tph,
    SUM(timer_value)/SUM(req_count) AS tpr,
    SUM(timer_value) AS timer_total
FROM tag_report_group_method  
WHERE script_name='[PROD]video_item'  
    AND `group` != "int_api"
GROUP BY `group`  
ORDER BY timer_total DESC;  

group	req	timer_median	tph	tpr	timer_total
mysql	118124	0.009819403290748596	0.003329653064723691	0.05909533790217434	6980.5776943564415
memcached	188049	0.00976656749844551	0.0003179184672595343	0.01067464985796328	2007.3572311401367
Elastic	32049	0.011334048118442297	0.016838098360988627	0.026841974640797184	860.2584452629089
Redis	48999	0.009611431136727333	0.011986066101148827	0.012204265879965226	597.9968238524161
DMX	61436	0.009767306968569756	0.0016191925102048436	0.0073448760845254615	451.23980712890625
Curl	24882	0.06987743234882753	0.008533559191620778	0.008533559191620778	212.3320198059082
cleeng	50	0.12915635108947754	0.1352721940790749	1.0902938842773438	54.51469421386719
Facebook API	22	0.5436198115348816	0.5515929568897594	0.5515929568897594	12.135045051574707
Live API	1	0.01953125	0.0049230000004172325	0.0049230000004172325	0.0049230000004172325

Подробные сведения о MySQL SELECT:

mysql> SELECT mysql, method, timer_value,  
    timer_value/req_count AS avg_timer_value,
    hit_count/req_count AS avg_op_count,
    timer_value/hit_count AS avg_op_value,
    hit_count,
    req_count
FROM tag_report_mysql_method  
WHERE method='select'  
    AND script_name='[PROD]video_item'
    AND req_count > 200
ORDER BY avg_op_count DESC  
LIMIT 4;  

mysql	method	timer_value	avg_timer_value	avg_op_count	avg_op_value	hit_count	req_count
video	select	3971.99	0.10144789052722653	16.6880	0.006079103953896177	653384	39153
video_view_summary	select	264.027	0.007824405328308366	12.6024	0.000620868312581275	425254	33744
static_asset_video_sprite	select	15.4905	0.022613802443455604	7.6496	0.0029561936400318875	5240	685
video_has_repost	select	1468.93	0.027541118671605483	6.7955	0.0040528553527407	362444	53336

Мы отслеживаем использование запросов select. Если их количество становится очень большим, возможно, кеширование выполняется неэффективно.

Дополнительные возможности

Мы также используем еще одну интересную возможность Pinba — теги, позволяющие различать запросы разных типов. Запросы помечаются тегами, которые вы определили. Например, мы используем теги для следующих запросов:

• format: формат ответа (html, rss, atom, ...);

• site_content: языки контента сайта (en, de, fr, jp, ru, ...);

• bot: реальный клиент или бот? (yes/no);

• auth: пользователь прошел проверку подлинности (выполнил вход)? (yes/no);

• provider: определяем различия между версиями PHP: стандартный PHP или HHVM и т.д.

Затем мы создаем таблицы и в комментариях для движка указываем что и где нужно хранить. Например, мы можем сформировать таблицу на основе report_by_script_name, в которой движок сохраняет данные только для процессов PHP со значением no для тега запроса bot и значением no для тега запроса auth. Другими словами, это реальные пользователи, не выполнившие вход в систему — обычная ситуация.

CREATE TABLE `auth_no_bot_no_report_by_script_name` (  
  `req_count` int(11) DEFAULT NULL,
  `req_per_sec` float DEFAULT NULL,
...
  `req_time_median` float DEFAULT NULL,
  `index_value` varchar(256) DEFAULT NULL
) ENGINE=PINBA DEFAULT CHARSET=latin1 COMMENT='report1::tag.auth=no,tag.bot=no';

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

Pinba хранит полученные метрики всего одну-две минуты. Поэтому для построения графиков данные требуется консолидировать на внешних ресурсах. Здесь мы используем collectd в паре с плагином MySQL. При этом выполняются запросы к базе данных Pinba, а результаты сохраняются в Whisper. Затем мы запрашиваем Whisper с помощью Graphite и Tessera или Grafana.

Заключение

Использование Pinba с нашим устаревшим PHP-приложением позволило нам:

• обнаружить возможные источники проблем в приложении;

• выявить ошибки (необоснованно большое число запросов к серверам на некоторых маршрутах);

• построить графики и настроить оповещения, чтобы выявлять случаи снижения производительности после релиза.

Мы также используем Pinba в своих проектах на Python. Специализированную версию Pynba создал наш старый друг (а теперь и коллега) johnnoone.

Единственное, что мы заметили во время использования Pinba: расширение не всегда верно «забывает» информацию о старых запросах. Иногда таблицы отчета содержат фантомные результаты — данные об активности, имевшей место более минуты назад. Это может стать проблемой, если с помощью Pinba нужно убедиться, что что-то не происходит (обычно после развертывания нового кода на продакшене). Это один из немногих случаев, когда причина ошибки не в вашем коде.

Самый простой способ устранить ее — перезапустить движок Pinba. В результате появятся небольшие пробелы на графиках, но фантомные данные точно исчезнут. (Примечание: TRUNCATE TABLE вам не подходит, поскольку это не движок MySQL.)

Полезные ресурсы для пользователей Pinba

1. GitHub: https://github.com/tony2001/pinba_engine
2. Документация: https://github.com/tony2001/pinba_engine/wiki
3. Мониторинг производительности PHP-кода с помощью Pinba:
   https://habrahabr.ru/company/badoo/blog/149695/

Автор: Badoo

Источник