Где могут пригодиться графики
Пару месяцев назад я нашёл для себя неожиданно полезное применение графиков в своей работе. И нет, это не мониторинг в классическом понимании этого слова. Это наколенные прогнозы.
Описание задачи
Есть у нас в jenkins одна джоба, которая производит довольно длительную операцию с базой данных. Размер базы около 100Гб, самый долгий этап - обработка таблицы почти в 60 миллионов записей. Иногда этот процесс проходил за 7 часов, иногда за 21 час и я пытался обнаружить причину, по которой получается такая разница во времени обработки данных. Проблема была в том, что понять, насколько быстро выполняется очередная ревизия джобы из километрового лога с цифрами было достаточно сложно. Скрипт раз в 30 секунд выдавал количество обработанных строк и приходилось брать разницу в этом количестве на каком-то временном периоде и затем сравнивать её с аналогичным прошлым, позапрошлым и, возможно, поза-поза-чёрт-знает-сколько-прошлым запуском. Ведь нет смысла ждать и нагружать мощности, если за час работы скрипта можно определить, сколько примерно он будет работать. Но всё оказалось не так просто. Зависимость количества обработанных строк за единицу времени оказалась нелинейной и чтобы понять характер работы, мне понадобился график.
GNUPlot
Я слышал раньше о GNUPlot, но вот как-то не доводилось с ним работать. Везде, где оказывались нужны графики (а это преимущественно мониторинг), они уже были. Пару раз рисовал графики в шелле, используя svg и awk. Получалось даже симпатично, но на этот раз мне нужно было некое уже более-менее готовое решение и я решил посмотреть в сторону GNUPlot, благо, он есть практически в любом дистрибутиве.
Излишества в виде GUI нам не особо нужны, поэтому сразу ставим CLI версию:
sudo apt-get install gnuplot-nox
Собственно, это всё, что нам нужно для того, чтобы начать строить графики. Изучив результаты запроса "gnuplot examples" к гуглу, я получил начальное представление о возможности и синтаксисе. Если же для ваших целей будет недостаточно того, что будет приведено в скрипте ниже, то советую обратиться к туториалу на IBM и на wikibooks.org. Вообще, GNUPlot умеет на удивление многое, в том числе трёхмерные графики, гистограммы и прочее. Так же вот тут есть неплохая статья, как можно достаточно просто интегрировать gnuplot с web интерфейсом.
Пишем скрипт
Кусок лога, выгружаемый из джобы выглядит следующим образом:
...
06:45:34 INFO [app] processed 58927349 rows.. [] ["app" => "frontend","pid" => 313]
06:46:05 INFO [app] processed 58950594 rows.. [] ["app" => "frontend","pid" => 313]
06:46:36 INFO [app] processed 58973707 rows.. [] ["app" => "frontend","pid" => 313]
06:47:07 INFO [app] processed 58996974 rows.. [] ["app" => "frontend","pid" => 313]
06:47:39 INFO [app] processed 59020205 rows.. [] ["app" => "frontend","pid" => 313]
...
Фактически нам важна только пятая колонка с количеством обработанных записей, потому как разница в таймстемпах всегда примерно одинаковая. Если мы будем отталкиваться от времени, то графики у нас разойдутся по оси X и сравнивать их будет сложно и неудобно. Вместо таймстемпа нам нужны условные единицы, просто будем знать, что одна единица - это 30 секунд. Такое преобразование можно очень легко получить с помощью AWK - просто будем выводить номер строки лога перед значением. Логи лежат в файлах вида 123.log, где 123 - это номер запуска джобы, вместо него так же может быть какое-нибудь условное имя. При приведении логов в уодобоваримый вид, необходимо учиытвать, что если добавились новые логи, то уже обработанные трогать не нужно.
#!/bin/sh
cd `dirname "$0"`
# В этой переменой храним путь к конфигу для gnuplot
CFG='./plot.conf'
# Далее создаём сам конфиг и сохраняем его в файл
echo 'set terminal svg size 800,600 enhanced background rgb "white"
set title "Query counts by 30 seconds"
set output "graph.svg"
set xlabel "Time (1x = 30 seconds)"
set ylabel "Count of rows processed"
set ytics 5000000
set format y "%s"
set xtics 100
set grid
set multiplot' > "$CFG"
# В эту переменную будем сохранять список графиков, которые нам нужно построить.
plots=''
# Берём все файлы с расширением log, если нет файла с тем же именем
# и расширением txt, то создаём его, добавляя в первую колонку номер
# строки и во вторую - значение.
for f in *.log; do
num=`echo "$f" | cut -d "." -f 1`
[ -f "$num.txt" ] || awk '{ print NR" "$5 }' "$num.log" > "$num.txt"
# В переменную plots добавляем строки вида
# \"123.txt\" with lines title \"123\"
plots="$(echo "$plots"; echo " \"$num.txt\" with lines title \"$num\"")"
done
# Склеиваем строки в одну через замятую, добавляем директиву plot
# и убираем лишнее, затем дописываем в конфигурационный файл.
echo "$plots" | tr '\n' ',' | sed 's/^,/plot /;s/,$//' >> "$CFG"
# Добавляем перевод строки.
echo >> "$CFG"
# И директиву выхода для завершения скрипта
echo 'quit' >> "$CFG"
# Теперь просто запускаем gnuplot
gnuplot -c "$CFG"Более подробно о директивах конфигурационного файла
Тут всё очевидно. svg - формат, далее размер и указание того, что нам нужен белый фон. Вместо svg может быть png, jpg и многое другое вплоть до вывода графика псевдографикой (простите за тавтологию).
set terminal svg size 800,600 enhanced background rgb "white"
Это заголовок нашего графика:
set title "Query counts by 30 seconds"
Имя файла для сохранения:
set output "graph.svg"
Наименование осей X и Y:
set xlabel "Time (1x = 30 seconds)"
set ylabel "Count of rows processed"
Указание размера условной единицы по оси Y, через это количество значений у нас будут идти отметки на оси:
set ytics 5000000
Задание формата вывода значений по оси Y (иначе можно получить значения в экспоненциальном формате, что неудобно):
set format y "%s"
Размер условной единицы для отметки по оси X:
set xtics 100
Указание того, что мы хотим вывести сетку (размер ячеек так же зависит от xtics и ytics):
set grid
И наконец, директива, которая говорит о том, что мы хотим получить несколько графиков на одном поле:
set multiplot
Примеры графиков
И что же мы получаем в результате работы? Сразу оговорюсь, что графики сконвертировал в PNG, в svg они выглядят глаже и симпатичнее. Ниже приведу тот же график, что использовал вначале статьи.
Тут можно видеть результаты работы четырёх запусков джобы. 521-я и 522-я были запущены в момент, когда кредиты на операции ввода-вывода на инстансе были в нуле. В момент, когда 522-я джоба обрабатывала примерно 34-й миллион строк, я отскейлил блочное устройство с 500 до 750 гигабайт и базовый уровень IO соответственно вырос в полтора раза. По графикам можно примерно посчитать разницу во времени исполнения джоб. 523-я и 524-я джобы были запущены уже на полностью отскейленном блочном устройстве, нетрудно видеть, что её исполнение заняло практически в два раза меньше впремени, чем 521-й. А теперь любопытное - видите небольшой горбик после 10 миллионов 523-й джобы и после 15 миллионов 524-й? Это один из сотрудников запускал миграции на базе данных, откуда происходило считывание. Миграции были запущены в разное время относительно начала джобы, но затем графики практически снова совпали и уже не было смысле дожидаться полного окончания джобы, чтобы понять, сколько примерно времени она займет, поэтому джоба была прервана. Так же на графике отлично видна нелинейность количества обработанных запросов относительно времени. Это происходит из-за того, что база перестраивает индексы на большой таблице и каждый следующий инсерт даётся ей дольше, чем предыдущий. В самом начале график почти вертикально уходит вверх, постепенно затем становясь всё более пологим.
Исходя из этих экспериментов я выяснил, что проблема именно в дисковой подсистеме и IO. В качестве эксперимента джоба была запущена на более мощном инстансе другого типа, но с таким же бейзлайном на операции ввода-вывода, а затем ещё раз - с выводом дампа в /dev/null вместо заполнения базы.
Как легко можно видеть, графики запуска джобы 529 и запуска на инстансе c5.large практически совпадают, отличия на уровне погрешности из-за воздействия внешних факторов. А вот график с записью в dev-null недалеко ушёл от вертикальной прямой. Вывод - нужно более быстрое блочное устройство. Джоба скорее всего переедет в ближайшее время на инстанс с локальным SSD стораджем.