Привет, Хабр! Меня зовут Вова, я разрабатываю observability-платформу в Ozon. Как-то раз в наш уголок на 42 этаже заглянули коллеги — и поделились наблюдением. Если открыть рядом графики времён запросов и ответов двух живущих в Kubernetes и общающихся между собой микросервисов, то иногда можно наблюдать большую разницу в высоких квантилях: клиент считает, что один ответ из сотни ему приходит за сто миллисекунд, сервер же говорит, что успевает ответить за десять.
Куда ушло время? Можно ли его вернуть? Сегодня расскажу о том, с какими граблями может столкнуться микросервис, живущий в типичной инсталляции Kubernetes.
От YAML до прерываний — один шаг
Прежде всего нужно отметить, что в Ozon приложения написаны на базе собственного фреймворка — платформы с интегрированным service discovery. Когда-нибудь расскажем об этом подробнее, но сейчас важно сказать две вещи:
Приложения ходят друг в друга напрямую: без сетевых и L7-балансировщиков, прокси-серверов, — словом, накладные расходы минимизированы, насколько это возможно. Это помогает в дебаге — простые вещи лучше поддаются пониманию и ремонту.
Платформа предоставляет готовое инструментирование: из коробки любой сервис будет покрыт богатым набором метрик и обмазан распределённым Jaeger-трейсингом.
Собственно, трейс проблемного кейса будет выглядеть как-то так:
На основе трейсов сварили метрику, показывающую распределение разниц времён запросов и ответов для 100% запросов. Назвали незамысловато — сlient-server span gap.
Для всех запросов?
В отличие от стандартной инсталляции Jaeger, использующей head-based sampling, мы сохраняем (пусть и ненадолго) и анализируем весь поток прилетающих спанов.
Итак, наш попугаеметр показывает условную сотню пар сервисов, имеющих проблему. Дело за малым — найти причину и починить. Первый кандидат — собственные ошибки и неверные допущения. Инструментирование в случае gRPC реализовано с помощью стандартного механизма — интерцепторов. Это значит, что наша метрика будет включать время на маршалинг и анмаршалинг ответа, который может быть произвольно большим. Исключим из рассмотрения пары сервисов с ответами размером больше сотни килобайт — и видим, что 99 из 100 сервисов по-прежнему зааффекчены.
:more_cpu:
Следующий типичный ответ: «Давайте зальём проблему железом, а там разберёмся». Однако тут есть два нюанса:
Глобальный дефицит чипов несколько затрудняет процесс.
Далеко не от каждой проблемы можно отделаться, кидаясь в неё пачками денег.
Второй, разумеется, критичнее.
Берём в руки шашку и пишем пару сервисов — танк и мишень — обменивающихся раз в десять миллисекунд минимальными сообщениями в стиле ping-pong и логирующих trace_id проблемных запросов для удобства. Видим, что проблема по-прежнему иногда воспроизводится, даже если запустить приложения в guaranteed-подах на хостах со static cpu policy.
Что делать? Как всегда, достаём микроскоп и начинаем забивать гвозди. Берём нашу пару тестовых приложений, расчехляем tcpdump на обоих концах, оставляем работать до появления в логах проблемных trace_id. После открываем два окна Wireshark и начинаем зачитывать полученные дампы по ролям. Показания клиента и сервера действительно отличаются:
Клиент думает, что отправляет запросы один за одним, а потом одним махом получает пачку ответов. С точки зрения сервера же всё происходит штатно: видны последовательные запросы и ответы без задержек.
«Виноваты NOC-и!»
— воскликнет типичный разработчик, если его разбудить среди ночи и сказать, что видны какие-то затупы. После чашки кофе, однако, возникают сомнения в верности этой народной мудрости. Ведь data plane типовых датацентровых маршрутизаторов обрабатывает пакеты не центральным процессором общего назначения, а специально заточенными под это дело чипами, укомплектованными небольшим (12-32 мегабайт) объёмом быстрой памяти под буферы, распределение которой между физическими портами более-менее статично. Несложно подсчитать, что для буферизации одной миллисекунды загруженного линка в 25 Гб/с требуется чуть менее 3 мегабайт памяти. И таких линков в стойке 20-40 штук: Top of Rack-маршрутизатору попросту негде хранить пакеты в течение сотни миллисекунд, и потеря пакетов на порядки более вероятна такой задержки. Потому будем продолжать искать проблему у себя.
Расскажите поподробнее
Пользуясь случаем, рекомендую к прочтению 14-ю часть «Сетей для самых маленьких» за авторством @eucariot
We need to go deeper
Предельно упрощённо воркфлоу нашего тестового серверного приложения выглядит следующим образом:
А выделяется ли приложению процессорное время? Убеждаемся с помощью утилитки cpudist из проекта BCC. C ключом --offcpu
она покажет распределение off-CPU-отрезков времени:
$ sudo /usr/share/bcc/tools/cpudist --offcpu --milliseconds --pids --pid 54512 5
<...>
pid = 54512 test-grpc-shoot
msecs : count distribution
0 -> 1 : 68269 |****************************************|
2 -> 3 : 316 | |
4 -> 7 : 123 | |
8 -> 15 : 11 | |
16 -> 31 : 4 | |
Видим четыре паузы продолжительностью от 16 до 31 миллисекунд, что неожиданно. Тестовые приложения мы запускаем в guaranteed-подах на хостах со static cpu policy, то есть приложение прибито к конкретным процессорным ядрам, на которые K8s обещает не селить другие контейнеры. Разобраться поможет perf: соберём стектрейсы с ядер приложения раз в миллисекунду и найдём те, что не относятся к приложению:
$ sudo perf record -F 1000 -g --cpu 0
$ perf script
<...>
:6789 6789 [003] 27757.080040: 1000000 cpu-clock:pppH:
ffffffffc011c3fa e1000_clean+0x46a (/lib/modules/5.13.0-39-generic/kernel/drivers/net/ethernet/intel/e1000>
ffffffff96bc9571 __napi_poll+0x31 (/usr/lib/debug/boot/vmlinux-5.13.0-39-generic)
ffffffff96bc9a4f net_rx_action+0x23f (/usr/lib/debug/boot/vmlinux-5.13.0-39-generic)
ffffffff972000cf __do_softirq+0xcf (/usr/lib/debug/boot/vmlinux-5.13.0-39-generic)
ffffffff962aa7f4 irq_exit_rcu+0xa4 (/usr/lib/debug/boot/vmlinux-5.13.0-39-generic)
ffffffff96df732a common_interrupt+0x4a (/usr/lib/debug/boot/vmlinux-5.13.0-39-generic)
ffffffff97000cde asm_common_interrupt+0x1e (/usr/lib/debug/boot/vmlinux-5.13.0-39-generic)
NAPI — фреймворк для написания драйверов сетевых карт в Linux, стандарт для general-purpose-драйверов. В основе дизайна — простая идея: нужно балансировать latency и накладные расходы на обработку прерываний, обрабатывая накопившуюся пачку пакетов разом, — и уступить процессор следующему потребителю. Для большинства задач это работает хорошо, но не в тех случаях, когда каждая миллисекунда на счету. Потому мы унесём сетевые прерывания на специальные ядра:
# Снизим параллельность обработки пакетов на сетевой карте
$ sudo ethtool -L eno1 combined 4
# Посмотрим на номера назначенных сетевушке прерываний
$ cat /proc/interrupts | fgrep eno1
146: <...> IR-PCI-MSI 13631489-edge i40e-eno1-TxRx-0
147: <...> IR-PCI-MSI 13631490-edge i40e-eno1-TxRx-1
148: <...> IR-PCI-MSI 13631491-edge i40e-eno1-TxRx-2
149: <...> IR-PCI-MSI 13631492-edge i40e-eno1-TxRx-3
$ lstopo-no-graphics
Machine (376GB total)
NUMANode L#0 (P#0 187GB)
Package L#0 + L3 L#0 (36MB)
L2 L#0 (1024KB) + L1d L#0 (32KB) + L1i L#0 (32KB) + Core L#0
PU L#0 (P#0)
PU L#1 (P#48)
L2 L#1 (1024KB) + L1d L#1 (32KB) + L1i L#1 (32KB) + Core L#1
PU L#2 (P#1)
PU L#3 (P#49)
L2 L#2 (1024KB) + L1d L#2 (32KB) + L1i L#2 (32KB) + Core L#2
PU L#4 (P#2)
PU L#5 (P#50)
<...>
HostBridge L#2
PCIBridge
PCIBridge
PCIBridge
PCI 8086:37d0
Net L#0 "eno1"
<...>
NUMANode L#1 (P#1 189GB)
Package L#1 + L3 L#1 (36MB)
Не забудем на время отключить irqbalance, чтобы наши изменения не были перезаписаны. После экспериментов же irqbalance можно будет включить обратно, подсунув ему policyscript.
$ sudo systemctl stop irqbalance.service
CPU0 и его SMP-пару не рекомендуется использовать для критичной к задержкам нагрузке, потому что на нём исполняются прерывания системных таймеров. Потому начинаем с единицы:
$ echo 1 | sudo tee /proc/irq/146/smp_affinity_list
$ echo 49 | sudo tee /proc/irq/147/smp_affinity_list
$ echo 2 | sudo tee /proc/irq/148/smp_affinity_list
$ echo 50 | sudo tee /proc/irq/149/smp_affinity_list
Но унести прерывания мало. Необходимо также обеспечить возможность softirq-хендлерам перекладывать пакеты, когда это требуется. В основном этому будут мешать userspace-приложения, которые выполняют долгие (по нашим меркам) системные вызовы. Традиционный способ, доступный с 2004 года (ядро 2.6.9) — использование boot-флага ядра isolcpus
: на обозначенные ядра по умолчанию не будут шедулиться userspace-приложения. Это работает для любого дистрибутива, поскольку не предъявляет требований к способу запуска приложений. У этого подхода, однако, есть существенный недостаток: его применение требует перезагрузки, что ограничивает cadence, с которым можно тюнить настройки. Для современных систем, так или иначе заворачивающих всё в cgroups, рекомендуется использовать cpuset. В случае systemd — расставить CPUAffinity и перезапустить сервисы. Но можно ли обойтись без перезапусков? Мы как лауреаты премии «Золотой костыль» нашли лазейку. Создадим отдельную пустую cgroup с флагом cpu_exclusive и отдадим в её распоряжение «сетевые» ядра:
# Уносим системные процессы в общий пул ядер
mkdir /sys/fs/cgroup/cpuset/systemtasks
echo "0,3-48,51-95" > /sys/fs/cgroup/cpuset/systemtasks/cpuset.cpus
cat /sys/fs/cgroup/cpuset/cpuset.mems > /sys/fs/cgroup/cpuset/systemtasks/cpuset.mems
# Ядерные треды подвинуть не получится, потому ошибки придётся потерпеть
set +e
xargs --arg-file="/sys/fs/cgroup/cpuset/tasks" -I {} bash -c \
"echo {} > /sys/fs/cgroup/cpuset/systemtasks/tasks 2>/dev/null"
set -e
# Уносим на общие ядра дерево kubernetes
# /sys/fs/cgroup/cpuset/kubepods/QoS_CLASS/POD/CONTAINER/
# Контейнеры
find /sys/fs/cgroup/cpuset/kubepods -mindepth 4 -name cpuset.cpus -print0 \
| xargs -0 -I {} bash -c "echo 0,3-48,51-95 > {}"
# Поды
find /sys/fs/cgroup/cpuset/kubepods -mindepth 3 -maxdepth 3 -name cpuset.cpus -print0 \
| xargs -0 -I {} bash -c "echo 0,3-48,51-95 > {}"
# QoS-классы
find /sys/fs/cgroup/cpuset/kubepods -mindepth 2 -maxdepth 2 -name cpuset.cpus -print0 \
| xargs -0 -I {} bash -c "echo 0,3-48,51-95 > {}"
# Корень.
echo 0,3-48,51-95 > /sys/fs/cgroup/cpuset/kubepods/cpuset.cpus
# Добрались до сети
mkdir /sys/fs/cgroup/cpuset/networkcpus
echo "1-2,49-50" > /sys/fs/cgroup/cpuset/systemtasks/cpuset.cpus
cat /sys/fs/cgroup/cpuset/cpuset.mems > /sys/fs/cgroup/cpuset/systemtasks/cpuset.mems
echo 1 > /sys/fs/cgroup/cpuset/cpuset.cpu_exclusive
echo 1 > /sys/fs/cgroup/cpuset/networkcpus/cpuset.cpu_exclusive
Было:
/sys/fs/cgroup/cpuset/ (системное барахло и ядерные треды)
├── kubepods (поды k8s)
(96 ядер)
Стало:
/sys/fs/cgroup/cpuset/ (ядерные треды)
├── kubepods
(92 ядра)
├── networkcpus (пустая)
(4 ядра)
├── systemtasks (порождённые systemd процессы и их наследники)
(92 ядра)
Таким нехитрым способом мы получили функциональный эквивалент isolcpus, который можно менять в рантайме за единицы секунд. Применим на всём кластере — и получим заметный эффект:
Span gap уменьшился и стал менее шумным: клиенты получают ответы за предсказуемое время.
Итак, сегодня мы применили широкоизвестные инструменты диагностики Linux-based систем, и с помощью CPU affinity разделили обработку сетевого стека и исполнение приложений. В результате этого ускорилось кросс-сервисное взаимодействие приложений в нашем Kubernetes-кластере.
Безусловно, на этом рано ставить точку: хочется тратить на сеть меньше процессора — и перед нами возникает множество путей, о которых расскажем в следующий раз. Не переключайтесь и читайте Брендана Грегга.
Комментарии (23)
zerospiel
25.04.2022 18:44+1За статью спасибо, очень просто и понятно написано
Когда работал в этой компании — не знал в таких подробностях о решении проблемы. В связи с новыми деталями есть вопрос от бездыря-разработчика в гугле забаненого:
Что за magic numbers с echo (
echo 0,3-48,51-95
,echo 49
,echo 1
etc.)?Pono Автор
25.04.2022 19:02+1В приведённом примере машинка с двумя процессорами, по 24 физических / 48 гипертредовых ядер на сокет — итого 96 логических ядер, нумерованных от 0 до 95. Две гипертредовых пары мы вынесли под сетевые прерывания — ядра 1 и 49, 2 и 50.
0,3-48,51-95
— это просто свёрнутое представление всех остальных ядер на этой машинке. На каком-нибудь твоём сервере или виртуалки нужные числа будут другие — нужно смотреть топологию конкретной железкиAsviel
26.04.2022 11:26+1Огромное спасибо за статью.
Правильно ли я понял, что вы взяли первую попавшуюся пару HT ядер относящихся к одному физ ядру в кол-ве 2 шт (1, 49 и 2, 50), после cpu0? Т.е. это с тем же успехом могла бы быть и пара 3, 51 и 23,71, например. Или это какие-то "специальные" ядра под прерывания? Иными словами, не очень понял, как определился маппинг
ядра должны принадлежать процессору, на PCI-линиях которого сидит сетевая карта
Pono Автор
26.04.2022 11:54+1Да, ровно так дело и обстоит: это могли быть и другие ядра той же NUMA-ноды.
Что до того, что ядра берутся именно HT-парами: это сделано для того, чтобы меньше вымывался кеш инструкций.
beono
25.04.2022 18:50+1расчехляем tcpdump на обоих концах, оставляем работать до появления в логах проблемных trace_id
А как отлавливали проблемные трейсы? Получается, нужно каждый трейс автоматически проверять на "гепы"? Понятно, что как-то это решается, но интересно вдруг есть элегантное решение, чем просто просто перебирать спаны?
Приложение должно требовать процессорное время не реже раза в 10 миллисекунд
А с чем связано ограничение в 10 мс?
Pono Автор
25.04.2022 19:10+1А как отлавливали проблемные трейсы? Получается, нужно каждый трейс автоматически проверять на "гепы"? Понятно, что как-то это решается, но интересно вдруг есть элегантное решение, чем просто просто перебирать спаны?
Все трейсы, разумеется, проверять не нужно — тестовое приложение-клиент писало в логи trace_id только аномально длинных запросов. Эти trace_id искались в wireshark с помощью простого совпадения по строке (find packet -> string), а вся сессия находилась через follow -> tcp stream
А с чем связано ограничение в 10 мс?
Только с тем, что приложение было написано так, чтобы отправлять запрос раз в десять миллисекунд. Цифра в 10мс была выбрана достаточно большой, чтобы отделить от штатно отработавших запросов-ответов (1мс), но в то же время не сильно большой, чтобы отловить "микрозатыки".
vitkovskii
25.04.2022 19:14+1Отдельно перебирать не нужно. У нас нет семплирования поэтому АБСОЛЮТНО ВСЕ спаны прилетают в коллекторы. В коллекторе они в любом случае обрабатываются тк их нужно приклеить в один трейс. Внутри просто строятся две гистограммы по длительности спанов от сервера и по спанам от клиента. Потом вычитается одно из другого и получается результат.
chemtech
25.04.2022 18:58Спасибо за пост.
Можно было ли добиться такого же результата используя утилиту https://github.com/strizhechenko/netutils-linux ?
Pono Автор
25.04.2022 20:27Пробежался глазами по ридми — да, утилита может раскидать прерывания лесенкой. Но всё равно нужно будет прокинуть флажки
--banirq
— номера прерываний для которых до SCM ещё нужно как-то доставить. procfs и статистика с сетевой карты в диагностике не сильно помогут, к сожалению.Q: I see that workload is distributed fine, but there is a lot of workload. How to go deeper, how to understand what my system doing right now?
A: Tryperf top
С этим спорить невозможно — в знании того, когда именно следует воспользоваться одним из этих инструментов, и состоит немалая часть работы SRE / сисадмина
sunnybear
25.04.2022 19:10+2Я ставил на дисковые задержки. Но, возможно, это суть следующей статьи :)
Pono Автор
25.04.2022 19:11+3Это, разумеется, была одна из гипотез — но проблема наблюдалась даже у stateless-сервисов, которые не пишут логов.
sunnybear
25.04.2022 19:18Не только из-за логов возникает iowait. Там от trim операций до свопа куча вариантов.
Pono Автор
25.04.2022 19:26+3Пардон, мой ответ неполон без контекста, который я не донёс в статье: речь идёт о машинках без swap, на которых крутятся stateless-сервисы. Единственная disk-related активность этих сервисов — логи в stdout контейнера, которые оседают на диске.
yKafka
25.04.2022 20:39Спасибо за статью. Было очень интересно, даже когда она была ещё тикетом в внутренем таск-трекере. Для наших многослойных сервисов срезало 100-200 мс в q0.99.
ksnovich
26.04.2022 17:31+1Очень интересный материал, про привязку к ядрам всяких JVM видел, а вот про особенности K8S нет. Спасибо.
Попробую усложнить задачку. Было бы очень интересно услышать Ваше мнение.
В большинстве случаев , которые я видел и не могу на них влиять, ваша K8S нода работает внутри VM от VMware или т.п. с share физическими ядрами из пула.
Доступа к гипервизору нет, и увидеть те же настоящие "off-cpu от Грегга" не получится, на мой взгляд. Вернее когда гипервизор не дал самой VM времени поработать CPU. Посадить служебные процессы гостевого kernel можно по такой же методике внутри VM, но они же приземлятся на vCPU и в любом случае будет мешанина из потоков всех виртуалок и самого гипервизора на уровне физ. CPU.
И как замерить шумность облачной среды не понятно имея доступ только во внутрь гостевой ОС (VM)
Pono Автор
26.04.2022 18:50В большинстве случаев, которые я видел и не могу на них влиять, ваша K8S нода работает внутри VM от VMware или т.п. с share физическими ядрами из пула
Я правильно понимаю, что речь про условные 4*50%vCPU-виртуалки? Т.е. четыре виртуальных ядра, но гарантируется только 0.5с процессорного времени на ядро в секунду? Такие виртуалки да, для критичного к задержкам трафика использовать не рекомендуется — и предпочтительнее взять машинку 2*100%vCPU с гарантированными ядрами. Серьёзные cloud-провайдеры не будут запускать на этих ядрах ничего, что не относится к вашей виртуалке. Далее путь уже зависит от сетевого стека конкретного cloud-провайдера.
Яндекс.Облако, например, может вынести сетевой оверхед на отдельные ядра, которые не видны из гостевой системы: https://cloud.yandex.ru/docs/compute/concepts/software-accelerated-network
AWS может прокинуть виртуальную функцию физической сетевой карты: https://docs.aws.amazon.com/AWSEC2/latest/UserGuide/enhanced-networking.htmlСловом, облачные провайдеры максимально прозрачны, и в случае необходимости могут сделать вам быструю сеть.
И как замерить шумность облачной среды не понятно имея доступ только во внутрь гостевой ОС (VM)
В случае VMWare — начать с обновления ядра гостя. В 2020 году Алексей Махалов и Томер Зельцер добавили поддержку steal time:
https://lore.kernel.org/all/202003211432.57Hu5M7W%25lkp@intel.com/T/ksnovich
27.04.2022 09:38Да, все верно понимаете. Про возможность получать steal time от VMware по аналогии с KVM не слышал, спасибо за наводку. Поизучаю.
Шумность облака по CPU я пробовал измерять "сажая" потоки на ядра, периодически включая и выключая их с замером разности (есть похожие проекты), но вот вроде бы в kernel 5.14 появился OSNOISE Tracer с "HW noise" счетчиком, но все руки не доходят поизучать, вернее доступов нет из-за вездесущих облаков :) Интересно как это коррелируется со steal time полученным от VMware... По идее, этот счетчик должен быть легко доступен без всяких дебагов ядра или т.п.
PlatinumThinker
27.04.2022 13:25+2Смотрели ли в сторону TCP Nagle's algorithm? в случае с синтетическими тестами и мелкими сообщениями бывает делает погоду
Pono Автор
27.04.2022 18:21+1Отличный момент!
Нет, не смотрели в силу используемого стека. Да, в Linux алгоритм Нейгла используется по умолчанию и для отключения нужно нужно явно вызывать setsockopt с TCP_NODELAY. В Go, тем не менее, TCP-сокеты по умолчанию создаются с флагом TCP_NODELAY:
https://github.com/golang/go/blob/release-branch.go1.18/src/net/tcpsock.go#L206-L224
https://github.com/golang/go/blob/release-branch.go1.18/src/net/tcpsockopt_posix.go#L15Каноническая имплементация gRPC на C++ также проставляет TCP_NODELAY:
https://github.com/grpc/grpc/blob/master/src/core/lib/iomgr/socket_utils_common_posix.cc#L234-L249
https://github.com/grpc/grpc/blob/136055b043dcf2b15f69f535f659e4090cf25b9f/src/core/lib/iomgr/tcp_server_utils_posix_common.cc#L177
https://github.com/grpc/grpc/blob/136055b043dcf2b15f69f535f659e4090cf25b9f/src/core/lib/iomgr/tcp_client_posix.cc#L79Наверняка пошли бы копать в эту сторону, если бы tcpdump не показал, что каждая из сторон считала, что отсылает свою часть работы вовремя. Но это была бы уже другая статья :)
slysha
Подписываюсь под каждым словом Владимира.
Когда мы в Озоне запиливали поддержку эксклюзивных ядер для виртуалок с Postgresql также столкнулись с проблемой того, что активность от вирт шарила ядра с сетевой активностью и были проблемы. Обнаружили это на одном из сервисов, где транзакции в базке были всего 0.2-0.3 мс, а общая нагрузка на кучу шардов - порядка 2.5 млн tps при сетевом трафике 12 ГБ/c в пике - тут уж совсем не забалуешь с тем на каких ядрах и как запускать виртуалки.