Drawing Привет, Хабр! Мы в 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, поэтому некоторые пакеты могут теряться по пути). Используйте этот инструмент для отслеживания тенденций, он не подходит для точной количественной оценки действий.


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


enter image description here


Какие метрики можно отслеживать с помощью сервиса?
Спектр технических метрик, отслеживаемых по умолчанию во всех процессах 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/
Поделиться с друзьями
-->

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


  1. lexore
    20.01.2017 14:20
    +2

    Pinba хранит полученные метрики всего одну-две минуты.

    На самом деле, не совсем так. Время хранения зависит от настроек движка pinba в mysql.
    Здесь два фактора — время, как явно указанный параметр и размер пула в памяти, в котором хранятся данные.
    По умолчанию время 15 минут, а пул примерно такого размера, чтобы влезли все данные, которые прилетят за 15 минут от не сильно нагруженного сервиса.
    Для больших нагрузок нужно или увеличивать пул, или уменьшать время, или и то и другое.
    Не сомневаюсь, что у Dailymotion настолько большая нагрузка, что при большом пуле они все равно могут хранить данные только за последние 1-2 минуты.


    1. Sannis
      20.01.2017 17:53

      В Badoo практически всегда используется pinba_stats_history=60.
      Raw данные мы не используем, только отчеты, а для них совершенно не нужно хранить данные за 15 минут.