Настройка производительности Puppetmaster с помощью mod_mem_cache

Прошло довольно много времени с тех пор, как у меня было достаточно подробное или интересное сообщение на техническую тему, поэтому это было весьма приятным отклонением от обычной спринтерской работы в последнее время, когда у нас появились проблемы с производительностью Puppet. Во-первых, как и большинство людей, работающих в крупных корпорациях, я не могу дать вам никаких цифр, которые могли бы выдать количество серверов или что-то еще, что чувствительно, но очевидно, что у нас достаточно компьютеров, чтобы вызвать проблемы с производительностью в разумно настроенной среде Puppet. Я также поделюсь с вами некоторыми статистическими данными, которые дадут контекст и покажут вид до и после результатов работы.

Если вы привыкли работать с Puppet, вы можете привыкнуть к прогонам, занимающим, возможно, минуту или несколько минут для сложных каталогов. Когда ваше время пробежки начинает превышать десять минут, оно начинает чувствовать себя некомфортно, а когда оно становится намного больше, люди начинают жаловаться. Мы заметили, что для некоторых из наших основных систем требовалось очень много времени для выполнения прогонов (которые должны были выполняться каждые 15 минут), а также были некоторые сообщения об очень длинных прогонах для некоторых наших клиентов.

Прежде всего, мы исключили эту ошибку, хотя и пострадали от нее ненадолго. Если вы все еще используете 2.6 и используете этапы выполнения, обновитесь до 2.7, или вы скоро (или уже) будете страдать от довольно низкой производительности во время обработки графов клиентов. Как мы видим из отчета об ошибках, мы увидели на несколько порядков худшую производительность.

Как начать логически переходить к исправлению производительности?

• В марионеточных отчетах от клиента содержатся временные метки для времени обработки каждого ресурса, но нет продолжительности времени обработки клиентом или сервером (на самом деле, время на стене отдельного ресурса — это то, что нас интересует).
• Без углубления в точное время обработки каждого события невозможно увидеть, связаны ли проблемы с производительностью исключительно с клиентом, с сервером или с обоими. Puppet является довольно болтливым клиент-серверным приложением, поэтому запуск тесно связан между ними (по крайней мере, в стандартной конфигурации).
• Обычно клиенты будут превосходить число серверов по крайней мере на порядок, и, возможно, до четырех (пяти?), Если ваша конфигурация невелика или выполняется не часто. (Это, очевидно, приблизительное значение, и оно может значительно отличаться при активной балансировке нагрузки и настройке производительности. У вас могут быть только клиенты, но нет серверов.)
• Нам необходимо точно определить, какие операции обходятся нам в вычислительных ресурсах, и решить, что дало бы нам максимальный выигрыш при минимальных затратах времени.
• Поэтому нам нужна информация, чтобы получить представление об этих операциях.

Лучшая регистрация

Мы уже запускали наших Puppetmasters через Apache с Passenger (он же mod_rails / mod_rack), поэтому у нас уже были журналы в комбинированном формате. К сожалению, хотя вы можете получить представление о большом количестве статистики уже из этого формата журналов, вычислительные затраты на каждый запрос и ответ не ясны. Я решил добавить в журнал поле% D, которое дает время отклика в микросекундах для каждого запроса, что позволило бы мне лучше понять, что на самом деле занимает много времени. У меня были подозрения, что мы недавно достигли предела запросов, за пределами которого производительность будет ухудшаться быстро (не линейно), но мне нужны были реальные доказательства этого.

Для записи, вот фактическая спецификация формата журнала:

LogFormat "%h %l %u %t \"%r\" %>s %b %D \"%{Referer}i\" \"%{User-Agent}i\"" puppet
CustomLog /var/log/httpd/puppet.log puppet

И строки вывода журнала начинают выглядеть так:

192.0.2.1 - - [18/Mar/2012:04:02:25 +0000] "GET /environment1/file_metadata/modules/logrotate/etc/logrotate.conf HTTP/1.1" 200 333 42741 "-" "-"

В этом случае, у нас есть время отклика 42741
микро секунд. Не волнуйтесь, пока.

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

• Среды: мы разрешаем разделение отдельных приложений и выпусков этих приложений с помощью среды Puppet. Поэтому, взглянув на среду, мы можем получить представление о том, вызывает ли одно приложение чрезмерную загрузку или один конкретный выпуск этого приложения.
• Запросчик: Один хост или группа хостов поражают Puppetmaster больше, чем следовало бы?
• Indirector: Компиляции каталога занимают много времени и приводят к замедлению всего остального, занимает ли время обработка отчетов или мы обслуживаем чрезмерное количество файловых ресурсов? Я ошибочно назвал это «типом ресурса» в моем сценарии анализа, потому что я был в состоянии RESTful, но технически это Indirectors в Puppet Land.
• Ресурсы: внутри данного Indirector — это конкретный ресурс, на создание которого требуется много времени (например, особенно большой или сложный каталог или очень большой файл).

Это было то, с чего я думал начать. Очевидно, что стандартный пакет статистики http-журнала, такой как AWStats, не удовлетворит большинство моих требований, но на другом конце шкалы что-то вроде Puppet Dashboard / Console слишком специфично для событий вокруг запуска Puppet — я хотел что-то промежуточное , Я был бы удивлен, если бы никто больше не написал что-нибудь, но несколько вещей заставили меня принять решение написать свое; вызов, наивная вера в то, что это будет быстро и легко, обманывая себя, заставляя поверить, что это слишком специфическая проблема, чтобы повторно использовать чужой код и фактор явного интереса.

Анализ журнала и выявление проблем

Поэтому я написал puppet_log_analyse.py. Я пытаюсь получить этот открытый исходный код (что является общей целью для моей команды), но сначала он должен пройти через процесс проверки. Как только это будет завершено, я отправлю ссылку со ссылкой, где она доступна извне, если это будет полезно для всех.

Это мой первый кусочек Python за долгое время, так что это, вероятно, не блестящий код. Он прошел несколько итераций, так как я хотел получить больше информации из журналов, а также, когда я экспериментировал с различными способами хранения и запроса данных. Я изначально использовал heapq, поскольку искал худшее или лучшееРезультаты многих, и heapq поддерживает относительно недорогие затраты на вставку, предоставляя структуру данных, которая будет отсортирована уже при запросе. К сожалению, некоторые из более интересных статистических данных, которые я хотел получить, оказались сложнее, чем я ожидал, поэтому, несмотря на снижение производительности (и, вероятно, затрачивая гораздо больше памяти во время выполнения), я переключился на SQLite, где я мог выразить себя в знакомом SQL , сохраняя при этом все данные в памяти. Эй, у меня 8 лб в моем ноутбуке, так что это не проблема!

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

Top resource types:
  7129326 GET file_metadata
  285765 GET file_metadatas
  85287 GET catalog
  84108 PUT report
  1770 GET file_content
  15 GET certificate
  5 GET certificate_request
  5 PUT certificate_request
  5 GET certificate_revocation_list

Statistics by resource type:
                                   AVG      STD.DEV    MIN   MAX
 GET catalog                       6951.7ms 5430.7ms 8.175ms 2.9996e+05ms
 GET certificate                   10.722ms 3.6854ms 5.128ms 17.609ms
 GET certificate_request           22.437ms 29.293ms 5.567ms 80.777ms
 GET certificate_revocation_list   19.492ms 29.293ms 3.877ms 78.062ms
 GET file_content                  10.106ms 56.091ms 2.917ms 1457ms
 GET file_metadata                 13.58ms 639.82ms 2.243ms 2.9982e+05ms
 GET file_metadatas                123.61ms 2817.5ms 3.587ms 2.9197e+05ms
 PUT certificate_request           55.047ms 3.0518ms 50.834ms 58.675ms
 PUT report                        2005.5ms 2411.3ms 7.438ms 2.99e+05ms

Yikes, это один загруженный сервер. Вы можете видеть, что время отклика не велико по всем направлениям, но максимальные значения печальны. На создание каталогов тратится много времени (что неудивительно), но я не ожидал, что количество запросов file_metadata и file_metadatas будет на несколько порядков выше, чем даже каталогов (что точно соответствует количеству прогонов). что произошло). Если взять среднее время отклика запросов file_metadata и их количество по этим журналам, мы увидим, что сервер потратил около 26,88 часа из примерно 60 часов журналов, генерирующих суммы MD5 и возвращающих их. Вероятно, для одних и тех же файлов снова и снова, которые не меняются.

Включение кеширования в Apache

Каталоги могут быть предварительно скомпилированы, и есть множество других настроек, которые могут быть сделаны, но первая мысль, которая пришла в голову, это просто кэширование ответов file_metadata. Даже если Puppet кеширует ответы (и мне не ясно, что это когда-либо происходило ), мы все еще заставляем наши запросы проходить через множество медленных Ruby, чтобы получить тот же результат. Кэширование ближе к запросчику имеет смысл с точки зрения производительности, и я уже знал о mod_mem_cache. Вместо того, чтобы тратить больше времени на добавление слоя кэширования с отдельным продуктом, таким как Varnish, почему бы просто не добавить больше настроек в Apache, который уже был установлен?

Я придумал разумно выглядящую конфигурацию и провел некоторое базовое тестирование.

        <IfModule mod_mem_cache.c>
                CacheEnable mem /
                CacheDefaultExpire 300
                MCacheSize 1024000
                MCacheMaxObjectCount 10000
                MCacheMinObjectSize 1
                MCacheMaxObjectSize 2048000
                CacheIgnoreNoLastMod On
        </IfModule>

Я объясню некоторые из этих настроек позже. Какой выигрыш в производительности вы можете получить, кэшируя метаданные файла (который сейчас является просто суммой MD5 из-за
другой ошибки )? Очевидно, это зависит от размера файла и скорости хэширования процессора, но давайте рассмотрим разумный пример файла размером 256 КБ.

127.0.0.1 - - [01/Apr/2012:01:30:55 -0700] "GET /production/file_metadata/modules/testmodule/testfile HTTP/1.1" 200 342 7853 "-" "curl/7.15.5 (x86_64-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b zlib/1.2.3 libidn/0.6.5"

Мы видим, что этот запрос занял 7853 микросекунды или чуть менее 8 мс для обработки и возврата на в противном случае простаивающую машину. Это кажется довольно быстрым, но что происходит, когда мы включаем кеширование?

127.0.0.1 - - [01/Apr/2012:01:34:26 -0700] "GET /production/file_metadata/modules/testmodule/testfile HTTP/1.1" 200 342 6960 "-" "curl/7.15.5 (x86_64-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b zlib/1.2.3 libidn/0.6.5"
127.0.0.1 - - [01/Apr/2012:01:34:26 -0700] "GET /production/file_metadata/modules/testmodule/testfile HTTP/1.1" 200 342 226 "-" "curl/7.15.5 (x86_64-redhat-linux-gnu) libcurl/7.15.5 OpenSSL/0.9.8b zlib/1.2.3 libidn/0.6.5"

Первый запрос после перезапуска, как и ожидалось, примерно с той же скоростью, что и раньше, но последующий ответ примерно в 30 раз быстрее. Это большое улучшение для нашего наиболее частого запроса.

Итак, мы закончили, верно? Что ж, вы могли бы просто пойти дальше и реализовать это, как указано в том, что мы уже видели, но я хотел быть более уверенным, что на самом деле вижу разумное улучшение. Есть также некоторые оговорки к конфигурации, которые я перечислю в конце поста. Чтобы получить более конкретные показатели улучшения производительности, я решил провести несколько тестов производительности до и после изменений с использованием Apache JMeter .

Тестирование производительности решения

Я не буду вдаваться в подробности с JMeter, так как есть много информации об этом, и, честно говоря, это легко и просто настроить и использовать, даже если вы никогда не использовали его раньше. Основные проблемы, с которыми я столкнулся во время тестирования, были следующими:

• Создание нагрузки и обслуживание тестируемого приложения на одной и той же машине — это путь к катастрофе (что должно быть очевидно). Поэтому вам понадобится отдельный генератор нагрузки и отдельная машина для приложения (в данном случае Puppetmaster).
• Если вы пытаетесь выполнить распределенное нагрузочное тестирование (т. Е. С выделенными серверами JMeter и отдельным веб-интерфейсом), вы столкнетесь с обычными проблемами соединения RMI, если между вашими серверами и веб-интерфейсом существуют межсетевые экраны / NAT.
• Тестирование Puppetmaster требует использования SSL и клиентского сертификата для аутентификации / авторизации. В настоящее время кажется, что JMeter SSL Manager не будет отправлять детали сертификата клиента на серверы JMeter при проведении распределенного нагрузочного тестирования. Чтобы обойти это, я использовал stunnel непосредственно между сервером JMeter и Puppetmaster, но вскоре я столкнулся с узкими местами производительности из-за stunnel — он выглядит довольно неэффективным.
• Чтобы использовать имеющиеся у вас Puppet-сгенерированные сертификаты и закрытые ключи, вам необходимо упаковать их в файл формата PKCS # 12. Ради читателей, команда для этого является openssl pkcs12 -export -out jmeter.p12 -in cert.pem -inkey priv.pem. Вам нужно будет поместить ключевую фразу в экспортируемый файл (OpenSSL попросит вас об этом), но SSL Manager в JMeter обрабатывает это при загрузке файла.

Итак, я установил среду barebones X11 на моей машине с генератором удаленной нагрузки и запустил все это оттуда. Тестовый сценарий был довольно прост:

• HTTP-запрос был отправлен на https: // puppetmaster: 8140 / production / file_metadata / modules / testmodule / testfile с GET.
• Диспетчер заголовков HTTP был использован для установки «Accept: yaml».
• Слушатель Graph Results использовался для генерации простого графика вывода.
• Я использовал 100 параллельных потоков, каждый из которых делал 1000 запросов.

По общему признанию, тестируя только один файл в одном модуле, я не делал этот тест очень хорошим, но я хотел убедиться, что кэширование приведет к некоторой разумной экономии на многих клиентах, поэтому я предположил, что ответы в производственной системе будут кэшироваться достаточно быстро и повторно используется для достаточного количества клиентов, чтобы иметь значение. В этом случае файл попадает в кэш файловой системы после первого запроса, поэтому он обслуживается из памяти с кэшированием ответов или без него. Как я упоминал ранее, Puppetmaster, похоже, не выполняет никакой другой формы кэширования файла, поэтому разница в производительности должна быть только между выполнением кода Puppetmaster и генерацией суммы MD5 по сравнению с возвратом кэшированного ответа.

Вот как обычно выглядит вывод JMeter:

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

Перед кэшированием:

• Пропускная способность: ~ 20859 запросов / минута
• Среднее: 276 мс
• Медиана: 100 мс
• Отклонение: 712 мс
• Средняя загрузка клиента: ~ 3,5
• Средняя загрузка сервера: ~ 55

После включения кеширования:

• Пропускная способность: ~ 50000 запросов / мин
• Среднее: 84 мс
• Медиана: 41мс
• Отклонение: 735 мс
• Средняя загрузка клиента: ~ 11
• Средняя загрузка сервера: ~ 1.2

Это не в 30 раз быстрее, на что я надеялся, но все же удвоение пропускной способности — значительная победа. Значительно уменьшенное время отклика и очевидное улучшение нагрузки на сервер также, по-видимому, указывают на потенциальный большой выигрыш при его фактическом развертывании.

Теперь, вооружившись результатами, я решил внести изменения конфигурации в нашу сборку Puppetmaster (которая сама по себе автоматизирована) и выполнить некоторые последние проверки на дым в качестве контроля качества перед развертыванием.

Воплощение в жизнь… Почти

Генеральный план состоял в том, чтобы сделать новый выпуск нашего Puppetmaster, сделать несколько похожих тестов и затем выпустить его в производство. Я запустил новый Puppetmaster, используя наш рецепт автоматизации, и попытался выполнить те же основные запросы, используя curl, но увидел довольно противоречивые результаты. Я часто мог сделать десять или более запросов, прежде чем увидеть время отклика в журналах, соответствующее возвращаемому в кеше результату. Еще более удивительно, что при включенной отладке Apache я смог убедиться, что он кэширует результат, но не возвращает его все время.

К сожалению, я пропустил это примечание в документации mod_mem_cache :

... In particular, this module's cache is per-process, ...

В моем случае обработка запросов шла к несколько случайным дочерним процессам, и я получил кешированный ответ только после повторного нажатия на тот же дочерний процесс (при условии, что кешированный ответ все еще свежий). Легко увидеть при ручном тестировании, не так просто при отправке 1000 запросов от 100 тестовых клиентов в JMeter. Это имеет некоторые последствия, хотя:

• Помимо требований к памяти для приложения Puppetmaster, работающего через Passenger, вам фактически необходимо учитывать совершенно отдельный кеш, работающий в каждом дочернем процессе Apache. Если вы хотите обеспечить хорошую частоту попаданий, вам может потребоваться разумное количество оперативной памяти.
• Если у вас очень небольшое количество клиентов и запросов, много дочерних процессов Apache и много файлов, вполне вероятно, что большую часть времени вы не попадете в кэш, если кэшированные ответы распределены равномерно. В общем, в этом нет большого недостатка, так как вы получите повышение производительности даже при нескольких ударах, но у вас больше шансов пострадать от устаревших ответов, которые могут не оправдать изменения.

Заставить его жить по-настоящему

Вот некоторая статистика из логов для того же Puppetmaster после изменения:

Statistics by resource type:
                                   AVG      STD.DEV    MIN   MAX
 GET catalog                       7053.9ms 3062.9ms 4.559ms 55651ms
 GET certificate                   15.386ms 36.771ms 4.381ms 263.69ms
 GET certificate_request           7.351ms 2.5096ms 5.001ms 15.452ms
 GET certificate_revocation_list   4.4384ms 1.0202ms 3.252ms 7.733ms
 GET file_content                  15.078ms 150.57ms 2.466ms 5207.8ms
 GET file_metadata                 8.4615ms 109.2ms 0.049ms 20517ms
 GET file_metadatas                65.971ms 345.93ms 3.546ms 21223ms
 PUT certificate_request           53.68ms 2.56ms 49.41ms 59.803ms
 PUT report                        434.32ms 1281.1ms 4.569ms 2.3324e+05ms

Повсеместно операции не сильно изменились, но в целом они более последовательны. Операции File_metadata улучшились примерно на 60%, что является довольно большим изменением, учитывая количество этих операций, которые обрабатывает Puppetmaster. Что касается фактического влияния, которое это оказало на нагрузку, мы пошли от того, чтобы постоянно видеть примерно 1 работающий процесс на ядро, до примерно 0,5.

И наконец…

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

К счастью или к сожалению, всегда есть много работы, которая должна быть сделана по вопросам инфраструктуры и улучшениям, поэтому я добавлю небольшой плагин для моей компании. Если этот пост или что-то, что я написал в прошлом, заинтересует вас, мне нужно больше людей в моей команде! http://devops.nokia.com/ это место, чтобы пойти на борт

Заметки

• Сначала я начал тестирование в нашем внутреннем, частном облаке, но когда я столкнулся с проблемами производительности при тестировании JMeter, я перенес тестирование на пару экземпляров в облаке HP, к которым у меня есть бета-доступ. Производительность там была намного лучше, но я понял, что критическим узким местом было ошеломление, как я уже упоминал выше. После того как я подтвердил цифры, я перенес тестирование обратно во внутреннее облако и увидел эквивалентные цифры, за исключением контейнеров OpenVZ, где в некоторых случаях пропускная способность была почти в два раза выше. Это соответствует предыдущим примерам, которые мы видели по сравнению с KVM (который мы также поддерживаем внутри компании и на котором работает облако HP). Если вы работаете с Puppetmasters виртуально, рассмотрите OpenVZ или Virtuozzo.
• В нашей конфигурации mod_mem_cache я установил довольно малое время ожидания (300 секунд) и решил сказать Apache игнорировать отсутствие ETags или последних измененных заголовков (CacheIgnoreNoLastMod On) в ответах, которые обычно помогают ему в истечении срока действия устаревших ответов. К сожалению, Puppet еще не отправляет какие-либо метаданные, подобные этим, для ответов, поэтому мы не можем приятно проверить свежесть ответов, однако для ответов file_metadata, как это, возможно, это не имеет большого смысла в любом случае.
• В отличие от некоторых других систем управления конфигурацией, которые полагаются на проприетарные протоколы между клиентом и сервером (на ум приходит CFengine, хотя я давно не рассматривал это), Puppet полагается на REST между клиентом и сервером, что означает множество стандартных методологий. для улучшения веб-производительности применимы. На это действительно приятно вернуться, как вы можете видеть из того, что я написал.