Введение
Каждый продукт в какой-то момент приходит в ту точку, когда вопросы производительности начинают выходить на первый план, и возникает задача: внедрить решение для тестирования и отслеживания изменений.
Первый вопрос, с которым может столкнуться менеджер - в какой момент начинать тестирование? С самого начала цикла разработки, на стадии feature complete, перед отправкой в продакшн? С одной стороны, чем раньше приступить к тестированию, тем больше вероятность отсмотреть большее количество сценариев, с другой стороны - продукт в активной стадии разработки довольно быстро меняется и потребует от команд тестирования постоянно адаптировать тестовые сценарии под новые требования. Тестирование же продукта на стадиях “альфа” и “бета”(когда продукт уже больше приближен к тому, что пользователи увидят на продакшене) может привести к ситуации, когда не останется времени либо на исправление найденных проблем, либо на тестирование внесенных правок.
Дальше встает вопрос ресурсов. Сколько времени в цикле разработки нужно выделить не тестирование производительности? Какие команды должны быть задействованы?
На сегодняшний день Veeam Backup and Replication с точки зрения разработки - это более 200 разработчиков в двух основных офисах, кодовая база более 5 миллиона строк, несколько тысяч юнит тестов, десятки билд процессов, и т. п. И несколько лет назад перед нами также встали эти вопросы. Поэтому в своей статье я хотел бы рассказать о нашем решении для мониторинга влияния изменений кодовой базы на производительность запросов базы данных.
Наша отправная точка
База данных - это один из основных компонентов нашего продукта. Сейчас это несколько сотен таблиц и представлений и порядка 5000 процедур и функций. В процессе разработки каждая команда постоянно вносит изменения в структуру базы, изменяя как свою зону ответственности, так и затрагивая общие компоненты. В активной фазе разработки каждый день может выполняться до нескольких десятков коммитов, связанных со схемой базы.
В какой-то момент мы столкнулись с такой проблемой: внесение изменений в хранимые процедуры стало приводить к просадке по времени выполнения, используемому процессорному времени и потреблению ресурсов. С одной стороны, за качество вносимых изменений отвечает разработчик, и, конечно, он проверяет на базовых сценариях производительность запроса. Но как быть в тех случаях, когда сценариев очень много и они не все известны? Например, были внесены изменения в представление, которое используется десятками хранимых процедур. Если в базовом сценарии джоин с какой-то абстрактной таблицей никак не повлияет на производительность, то в другом сценарии, где эта таблица может иметь несколько миллионов строк, могут возникнуть указанные сложности. Но проблема тут не в качестве кода, а скорее в том, что такие ошибки в разработке можно очень легко пропустить. По моему опыту, такие скрытые проблемы начинают проявляться не сразу, а спустя неделю, месяц и т.д. И для того, чтобы понять, что стало реальной причиной проблемы, иногда требуется довольно долго разбираться в коде, изучать историю изменений, искать авторов. Самое неприятное во всей этой истории -это то, что проблемы такого рода можем найти не мы, а пользователь.
Автоматизация процесса
После некоторого опыта в решении таких проблем мы совместно с нашей командой нагрузочного тестирования пришли к пониманию, что нам нужен инструмент для автоматического отслеживания и оценивания того, как вносимые в SQL код изменения влияют на производительность запросов. В первом приближении данный инструмент должен уметь:
получать статистику по выполнению выбранных нами наиболее критичных представлений и процедур,
проверка должны выполняться на ежедневной основе в рамках ночного билда,
заинтересованные люди должны получать краткий дайджест,
а также должна быть возможность более детального анализа статистики за период всего релизного цикла.
В итоге совместными усилиями мы реализовали следующую систему.
Основным компонентом является кроссплатформенная утилита командной строки, которая выполняет набор SQL скриптов и сохраняет по ним статистику. На вход утилита получает:
адрес сервера,
наименование инстанса и базы, на которых будут выполняться тесты,
а также координаты сервера и базы, куда будем сохранять результаты,
путь до папки, содержащей файлы тестов,
наименование продукта и номер билда
и прочую служебную информацию.
На выходе мы получаем структурированную информацию по выполненным тестам, а также статистику по запросам.
В качестве тестовых стендов мы используем набор максимально приближенных к реальности баз данных, которые отражают различные сценарии использования продукта. Эти базы развернуты в нашей тестовой инфраструктуре.
Работа всех компонентов системы координируется с помощью Jenkins. Выглядит это следующим образом: по завершению ночного билда на всех тестовых SQL серверах проводится обновление версии базы до актуальной. Далее для каждой тестовой базы данных производится запуск утилиты. Каждая утилита может выполнять свой набор скриптов, которые пишутся исходя из области интереса, также различаются и данные, на которых выполняются тесты. Например, одна база может отражать инфраструктуру сервис-провайдера, другая ориентирована на SQL Backup, третья - предназначена для бэкапа на кассеты, и т.д. По завершению всех тестов заинтересованные лица получают на почту краткий дайджест, где отражены различия в параметрах производительности между текущей версией и версией, выбранной в качестве эталона схемы БД. В нашем случае за эталонную версию мы считаем прошлый релиз.
Для того, чтобы более подробно посмотреть отчет по каждой базе и по каждому тесту, отдел тестирования сделал несколько дашбордов в Grafana. Первый вид - это историческая кривая по каждому параметру для каждого скрипта. На таком общем виде удобно смотреть общий тренд, а также искать аномалии, например, резкое падение или, наоборот, резкий рост.
Следующий вид более специфичный - он показывает данные по каждому выполнению скрипта. Здесь стоит сказать, что каждый отдельно взятый скрипт при каждом прохождении тестов выполняется 300 раз, и в качестве результата теста берется медианное значение. Это нужно для того, что бы уменьшить влияние внутренних механизмов оптимизации SQL сервера на конечный результат. На приведенных ниже графиках видно различие значений в зависимости от номера прогона.
Скрипт - это отдельный текстовый файл в формате yaml, состоящий из двух основных разделов: заголовок и блок с инструкциями.
В заголовке содержится служебная информация: название сценария, продукт, для которого сценарий написан, количество запусков в рамках одного прогона.
Блок инструкций содержит от одного до N шагов которые фактически являются инструкциями SQL.
Блоки могут быть двух типов: служебные и измеримые.
Первые необходимы для подготовки данных, получения необходимых параметров, очистки и т.п. Для этого типа статистика не собирается.
Второй тип - это как раз те запросы, по которым нам интересны статистические данные, те запросы, которые мы мониторим.
Выполнение блоков происходит последовательно. Также предусмотрен сценарий, когда данные, полученные при выполнении скриптов, могут быть использованы как входные параметры для следующего блока.
Вот пример одного из скриптов:
name: Test-BigViewPerformance
veeam-product: Backup
number-of-runs: 10
scripts:
- name: PrepareSomeData
body: SELECT id FROM SomeTable
- name: BigViewTest
body: SET STATISTICS IO ON
SET STATISTICS TIME ON
SELECT * FROM [SomeBigView] where id = @id
SET STATISTICS IO OFF
SET STATISTICS TIME OFF
is-statistics: true
- name: Clean
body: EXEC RemoveAllDataFromSomeTableВидим, что это сценарий тестирования Test-BigViewPerformance для продукта Backup, который будет выполнен 10 раз. Сценарий содержит 3 шага, причем id, полученный на первом шаге, будет использован в качестве входного параметра во втором. Интересный момент тут - это количество запусков. Дело в том, что полученная статистика может довольно сильно отличаться от запуска к запуску, так как, во-первых, работают механизмы оптимизации в самом SQL сервере, а во-вторых, сама среда выполнения динамическая. Эти два фактора мы должны учитывать, именно поэтому мы выполняем десятки прогонов одного сценария и потом смотрим дисперсию, среднее и квартили.
Статистику по выполнению запроса мы получаем стандартными средствами ADO.Net. Для этого достаточно подписаться на событие OnMessageReceived
msSql Database.OnMessageReceived += (s) => { scriptExecutionSummary.Messages += "\n" + s; }; Неприятный момент тут заключается в том, что статистика приходит в виде строк и требует преобразования для получения структурированных данных. Фактически это те же самые строки, что мы видим в SQL Server Management Studio.
SQL Server parse and compile time:
CPU time = 47 ms, elapsed time = 123 ms.
Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
Table 'Backup.Model.Backups'. Scan count 2, logical reads 12, physical reads 1, page server reads 0, read-ahead reads 4, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.
SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 17 ms.
(to be continued...)Как видно на изображениях выше, мы используем не все метрики, а только Total elapsed time, CPU time, Logical IO Reads. По нашему опыту тестирования, этих данных достаточно для того, чтобы быстро оценить запрос на предмет ухудшения или улучшения производительности. Более глубокий анализ запроса уже выходит за рамки нашей задачи и выполняется вручную в случае необходимости.
Опыт использования
На данный момент аптайм системы уже больше года. За это время на ежедневной основе мы проводим тестирование наших баз данных на десятке сценариев. Большую часть времени статистика по запросам находится в относительном равновесии. Общий тренд также не имеет сильных отклонений ни вверх, ни вниз. Конечно, бывают случаи, когда какой-то запрос резко идет вверх или вниз. Но ежедневный мониторинг помогает быстро находить проблемы и своевременно их устранять.
До внедрения системы процесс выглядел приблизительно следующим образом - команда QA приходила к нам примерно с таким дефектом: "Раскрытие списка бэкапа очень сильно тормозит. Билд на нагрузочных лабах мы давно не обновляли, вчера поставили свежий, и все стало плохо". С нашей стороны мы начинаем смотреть представление, отвечающее за раскрытие списка. Это примерно тысяча строк, около десятка временных таблиц, которые, в свою очередь, также содержат другие представления и функции. Путем пошагового анализа мы в итоге находим проблемное место. Но это стоит дорого. При такой сложности запроса - в том случае, если ты постоянно с ним не работаешь - ты каждый раз смотришь на него как впервые. То есть сначала тебе надо разобраться, как он в принципе работает, и что мы должны видеть на выходе. Хорошо, когда проблема на поверхности и это занимает всего несколько часов. Но иногда копать приходится очень глубоко, и можно потратить целый день, а то и два только на то, чтобы найти проблемное место. И часто бывает так: изменения, которые сильно повлияли на скорость выполнения, были внесены в процессе мерджа новой фичи из другой ветки около месяца назад. Разработчик, котрый изменения вносил, сделал все корректно (с точки зрения своей фичи) и проверил, что работает все быстро и правильно. Но он не учел, что при определенном наборе данных внесенные им изменения будут джойниться с таблицей на несколько миллионов строк. С одной стороны, он бы мог проверить все сценарии, а с другой стороны - наша реальность такова, что продукт большой, и отдельно взятому разработчику уже невозможно знать все сценарии, а по временным затаратам это будет колоссальный объем работы. В целом решение такого рода проблемы занимало примерно один день (и это в лучшем случае).
А сейчас, внедрив нашу систему, мы имеем следующую картину: каждое утро за чашечкой кофе мы смотрим дайджест, и, к примеру, видим, что две-три процедуры сильно прибавили в потреблении ресурса ЦПУ по сравнению с базовым билдом. Так как мониторим мы ежедневно, то знаем, что вчера такой проблемы не было. Значит, проблемы были привнесены за вчерашний день. После это иногда достаточно просто посмотреть историю коммитов, чтобы увидеть, что же стало причиной ухудшения показателей и кто внес эти изменения. Как результат - скорость нахождения проблемы сокращается в десятки раз.
Еще один плюс нашей системы - это накопленная статистика. Сейчас, к примеру, мы знаем, что отдельные запросы у нас ресурсоемкие, в силу своей сложности и специфики данных. И если к нам приходит отдел тестирования и говорит, мол, на моей машине все стало медленно, то мы можем посмотреть всю собранную за год использования статистику и объективно оценить, действительно ли все стало медленно - или, допустим, среда, в которой проводилось тестирование, не соответвует минимальным требованиям к продукту.
PS: Я пишу тут в основном о том, что если код стал работать медленно, то это плохо. Однако если ваш код сам по себе вдруг начал работать быстрее, не стоит раньше времени радоваться: возможно, кто-то просто закомментировал проблемное место.