eBPF в продакшне: bcc-tools и bpftrace показали латентность без ребута

Была задача, которую мы несколько недель откладывали: на одном из managed-хостов периодически росла латентность на запросах к базе, но ни Prometheus, ни логи ничего конкретного не давали. Метрики говорили «что-то не так», но не говорили где именно - на сетевом стеке, в дисковом вводе-выводе, или приложение само притормаживает. Классический вариант: perf-события есть, а источник непонятен.

Именно тогда решили наконец попробовать bcc-tools серьёзно, не как игрушку.

Что такое eBPF и почему сейчас

eBPF - это виртуальная машина внутри ядра Linux, которая позволяет запускать верифицированный байткод в ядерном пространстве без модулей ядра. По-простому: ты пишешь программку, которая прикрепляется к событию ядра (системный вызов, сетевой пакет, функция ядра), и получаешь данные напрямую оттуда. Без патча ядра, без перезапуска, без риска уронить систему - eBPF-верификатор не пропустит потенциально опасный код ещё на этапе загрузки.

В ядре 4.x возможности eBPF выросли существенно: maps для хранения состояния между вызовами, больше точек присоединения (kprobes, uprobes, tracepoints), улучшенный верификатор. Инструментарий вокруг этого тоже подтянулся: BCC (BPF Compiler Collection) даёт питоновый фронтенд к написанию eBPF-программ, а bpftrace - это что-то вроде awk для трассировки ядра, однострочники для быстрых вопросов.

На наших хостах - Ubuntu 16.04 с ядром 4.15 (HWE-стек). Версия подходящая, bcc устанавливается из официальных пакетов.

Диагностика: что реально нашли

Установка bcc-tools - это apt install bcc-tools python-bcc. После этого появляется набор готовых скриптов в /usr/share/bcc/tools/. Первое что запустили - biolatency: показывает гистограмму латентности блочного ввода-вывода.

$ sudo /usr/share/bcc/tools/biolatency -D 10
Tracing block device I/O... Hit Ctrl-C to end.

disk = sdb
     usecs               : count     distribution
         0 -> 1          : 0        |                   |
         2 -> 3          : 0        |                   |
         4 -> 7          : 12       |**                 |
         8 -> 15         : 187      |****               |
        16 -> 31         : 1043     |*********************|
        32 -> 63         : 856      |*****************  |
        64 -> 127        : 312      |******             |
       128 -> 255        : 94       |**                 |
       256 -> 511        : 41       |*                  |
       512 -> 1023       : 18       |                   |
      1024 -> 2047       : 7        |                   |
      2048 -> 4095       : 3        |                   |

Картина нормальная. Диск не виноват. Дальше - tcplife: показывает TCP-сессии с их длительностью и объёмом переданных данных.

Вот тут появился первый интересный хвост: часть соединений к базе закрывалась с заметной задержкой, несимметрично. tcpretrans - счётчик TCP-ретрансмиссий - подтвердил: несколько сетевых потоков периодически теряли пакеты. Не много, но достаточно чтобы TCP-стек начинал ждать.

Дальше runqlat - латентность планировщика, время ожидания процесса в очереди на CPU:

$ sudo /usr/share/bcc/tools/runqlat 10 1
Tracing run queue latency... Hit Ctrl-C to end.

     usecs               : count     distribution
         0 -> 1          : 2814     |********************|
         2 -> 3          : 1983     |**************      |
         4 -> 7          : 891      |******              |
         8 -> 15         : 412      |***                 |
        16 -> 31         : 203      |*                   |
        32 -> 63         : 87       |*                   |
        64 -> 127        : 44       |                    |
       128 -> 255        : 19       |                    |

Хвост на 64-255 мкс - умеренный, но для латентно-чувствительной базы это ощущается. Хост был немного перегружен соседними процессами.

Итого по одной диагностической сессии без ребутов и без установки специальных агентов: нашли комбинацию - сетевые ретрансмиссии плюс contention по CPU. Ни то ни другое в обычных метриках явно не торчало.

bpftrace: быстрые вопросы на лету

bpftrace - отдельный инструмент, ещё в активной разработке, но уже вполне рабочий. Синтаксис похож на awk: событие, фильтр, действие.

Например, посмотреть все системные вызовы read с задержкой больше 1 мс для конкретного процесса:

sudo bpftrace -e '
  kprobe:sys_read / pid == 12345 / { @start[tid] = nsecs; }
  kretprobe:sys_read / @start[tid] / {
    $lat = (nsecs - @start[tid]) / 1000;
    if ($lat > 1000) { printf("read lat %d us\n", $lat); }
    delete(@start[tid]);
  }
'

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

Сетевая фильтрация: XDP

Параллельно с диагностикой смотрели на XDP (eXpress Data Path) - это eBPF-программы, которые обрабатывают пакеты на уровне сетевого драйвера, до того как они попадают в сетевой стек ядра. Скорость обработки - миллионы пакетов в секунду на обычном железе.

Для нас это пока теоретический интерес: XDP требует либо поддержки в драйвере сетевой карты (не все карты умеют), либо работает в generic-режиме (медленнее). На виртуальных машинах картина смешанная. Но потенциально это замена части iptables-логики без userspace-прыжков - интересно с точки зрения нагруженных балансировщиков.

Ограничения которые реально ощутили

Версионная зависимость. bcc жёстко привязан к версии ядра. Установили пакет, а часть скриптов ругается на отсутствие tracepoint - потому что конкретный tracepoint появился в 4.16, а у нас 4.15. Приходится проверять что доступно на конкретном хосте.

Верификатор может отклонить программу. eBPF-верификатор строгий: если в программе есть потенциально небезопасный паттерн (разыменование без проверки, слишком длинный цикл), программа просто не загрузится. Для готовых скриптов это не проблема, а для самописного bpftrace - иногда неожиданное поведение.

Overhead не нулевой. Трассировка syscall на высоконагруженном процессе добавляет накладные расходы. Большинство инструментов из bcc по умолчанию используют агрегацию в ядре (maps) и минимизируют это, но запускать trace на сотнях тысяч вызовов в секунду нужно осторожно.

Что изменилось в подходе

До этого диагностика на продакшн-хосте выглядела примерно так: посмотреть метрики, покопаться в логах, если не помогло - запустить strace на процессе (что само по себе сильно замедляет), или добавить инструментацию в код и перезапустить сервис. Ни то ни другое не радовало.

eBPF меняет это: можно задавать конкретные вопросы к работающей системе и получать ответы здесь и сейчас, не трогая сервисы. biolatency, tcplife, runqlat, opensnoop, ext4slower - это готовые ответы на вопросы которые раньше требовали либо перезапуска с отладкой, либо допиливания кода.

Инструментарий ещё сыроват: документация bpftrace неполная, часть примеров из интернета рассчитана на ядра новее наших, некоторые скрипты из bcc-tools нужно читать перед запуском чтобы понять что именно они трассируют. Но это уже рабочий инструмент для реальных задач, а не лабораторная игрушка.