perf и flame graphs — профилирование на уровне CPU

top показал что CPU 100% на одном процессе. Профайлинг Python — говорит “медленно работает функция do_stuff()”. А что внутри? Какая строчка? Какой syscall? Какая kernel-функция? Для глубокого понимания — perf, профилировщик Linux, встроенный в kernel. Он использует hardware performance counters и kernel tracepoints, может профилировать как user, так и kernel code одинаково. И его выводы можно превратить в flame graphs — визуализацию, по которой за 5 секунд видно “что грязно”.

В этом уроке: основы perf (perf top, perf record, perf report), что такое sampling профайлинг, и как сгенерировать flame graph из live-сервера. Без deep dive — цель чтобы вы могли использовать perf как первый tool для perf-investigation.

Что такое perf и почему он мощный

perf — userspace утилита (из linux-tools) + kernel-side инфраструктура (perf_events). Что она умеет:

1. CPU sampling: каждые N циклов CPU прерывается, kernel записывает stack trace. Это даёт statistical profile — “где ваш код проводит время”.
2. Hardware counters: кэш-промахи (L1/L2/LLC misses), branch mispredictions, instructions per cycle. Hardware integrated.
3. Software events: page faults, context switches, scheduler delay.
4. Tracepoints: predefined kernel events (syscalls, network packets, scheduler decisions).
5. kprobes/uprobes: динамические probes на любую функцию kernel/userspace.

В отличие от strace (показывает каждый syscall, медленно) или top (общая картина), perf даёт детальный sampled profile.

perf top — live profiler

Самая простая команда:

$ sudo perf top
Samples: 12K of event 'cpu-clock:pppH', 4000 Hz, Event count (approx.): 2345678901 lost: 0/0 drop: 0/0
Overhead  Shared Object          Symbol
  12.34%  postgres               [.] heap_check_visible
   8.45%  postgres               [.] hash_search_with_hash_value
   5.67%  [kernel]               [k] mutex_unlock
   4.32%  [kernel]               [k] __schedule
   3.21%  postgres               [.] AllocSetAlloc
   2.45%  libc.so.6              [.] __memcpy_avx_unaligned_erms
   2.12%  [kernel]               [k] do_syscall_64
   1.89%  postgres               [.] standard_qp_callback
   ...

Колонки:

• Overhead — доля от total samples. 12.34% — эта функция была активна 12% времени.
• Shared Object — из какого binary/library/kernel.
• Symbol — имя функции. [.] — userspace, [k] — kernel.

Что это даёт:

12% в heap_check_visible       <-- postgres внутреннее, visibility checks
8% в hash_search                <-- hash table lookups
5% в mutex_unlock (kernel)      <-- много мьютексов
4% в __schedule (kernel)        <-- много контекст-свитчей

Это уже значимая информация о тяжелых функциях.

Установка (если perf нет):

# Ubuntu/Debian:
sudo apt install linux-tools-common linux-tools-$(uname -r)

# RHEL/CentOS/Fedora:
sudo dnf install perf

perf record + perf report

perf top — realtime, но не сохраняет. Для постмортема — record:

# Профилировать весь сервер 30 секунд:
sudo perf record -F 99 -g -a -- sleep 30

# Конкретный процесс:
sudo perf record -F 99 -g -p 1234 -- sleep 30

# Команда от начала до конца:
sudo perf record -F 99 -g -- my-script.sh

Параметры:

• -F 99 — частота 99 Hz (99 samples per second per CPU). Это магическое число чтобы не попадать в гармонику с system-timers. Standard practice.
• -g — записать call stacks (нужно для flame graphs).
• -a — all CPUs (system-wide).
• -p PID — конкретный процесс.
• -- — разделитель, далее команда для запуска и профилирования.

После — файл perf.data в текущей директории (~10-100 МБ).

# Интерактивный анализ:
sudo perf report

# Или текстом:
sudo perf report --stdio | head -30

# В TUI: стрелки навигация, Enter раскрыть callers, / поиск, q выход

Что искать в perf report

Топ функций — какие занимают больше всего времени. Если 50% в одной функции — очевидный hotspot, заняться оптимизацией.

Распределённый профиль (без явного hotspot, много функций по 1-2%) — сложнее: либо много мелкой работы (хорошо), либо нужно профилировать каждую отдельно.

Kernel-bound: если много времени в [k] функциях — bottleneck в kernel. Возможные причины:

• __schedule — слишком много context switching.
• do_softirq, net_rx_action — много network traffic.
• __inode_wait_for_writeback, __filemap_fdatawait_range — IO wait.
• mutex_lock, _raw_spin_lock — contention.

User-bound: видим userspace функции — профилировать сам application.

Flame graphs — визуализация profile

Текстовый perf report трудно читать. Flame graph — интерактивная SVG, где:

• Каждая полоска — функция.
• Ширина — сколько CPU времени тратит (стек включая всех её callees).
• Высота — глубина стека.
• Цвет — random/категория (не значит важности).
• Х-ось — НЕ время, а аггрегированная популяция samples.

Что видно сразу:

• Широкие “плато” наверху — функции, где CPU реально работает.
• Высокие “башни” — глубокие call stacks (часто recursive или GC).
• Несколько широких пиков — несколько hotspots.

Главное правило: смотрите на верхушку. Широкие “плато” наверху — функции, где CPU физически жжёт циклы. Узкие башни — глубокие call paths, но не обязательно много времени.

Сгенерировать flame graph: full workflow

# 1. Клонировать FlameGraph (Brendan Gregg):
git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph

# 2. Записать profile (например, 30 сек all-CPUs):
sudo perf record -F 99 -g -a -- sleep 30

# 3. Конвертировать в текст:
sudo perf script > out.perf

# 4. Свернуть стеки (fold):
./stackcollapse-perf.pl out.perf > out.folded

# 5. Генерировать SVG:
./flamegraph.pl out.folded > flame.svg

# 6. Открыть в браузере (интерактивный SVG):
firefox flame.svg
# или:
xdg-open flame.svg

Готовый SVG — интерактивный:

• Клик на блок — зум в эту функцию.
• Search — найти функцию по имени (highlight’ит все instances).
• Reset Zoom — вернуться к top view.

Профилирование конкретного процесса

# Найти PID (например, postgres):
pgrep -f postgres | head
1234

# Профилировать 60 секунд:
sudo perf record -F 99 -g -p 1234 -- sleep 60

# Сразу flame graph:
sudo perf script | \
    /path/to/FlameGraph/stackcollapse-perf.pl | \
    /path/to/FlameGraph/flamegraph.pl > postgres-flame.svg

Symbols: как сделать чтобы видеть имена функций

perf может показать имена функций только если есть debug symbols в binary. Stripped binaries (release builds) теряют их.

Для системных пакетов:

# Ubuntu/Debian:
sudo apt install linux-image-$(uname -r)-dbgsym   # kernel symbols
sudo apt install python3-dbg                       # Python с symbols

# Для пользовательских билдов -- компилировать с -g:
gcc -g myprog.c -o myprog

Без symbols вы увидите адреса вместо имён — бесполезно для оптимизации.

Для Python специальный workflow — нужен py-spy или austin (профайлеры Python, intercept’ят stack frames из Python interpreter). Чисто perf на Python даст имена C-функций (PyEval_EvalFrame), но не имена ваших Python-функций.

perf stat — counters без sampling

Иногда не нужен профиль, а просто метрики. perf stat:

$ perf stat -- sleep 5
 Performance counter stats for 'sleep 5':

              0.49 msec task-clock                #    0.000 CPUs utilized
                 1      context-switches
                 0      cpu-migrations
                65      page-faults
         1,234,567      cycles                    #    2.523 GHz
           987,654      instructions              #    0.80  insn per cycle
           234,567      branches                  #  478.708 M/sec
             6,789      branch-misses             #    2.89% of all branches

      5.001234567 seconds time elapsed

Что показывает: cycles, instructions, IPC (insn per cycle), context switches, branch mispredictions. Полезно для micro-benchmarks.

# Конкретные counters:
perf stat -e cache-references,cache-misses,L1-dcache-load-misses -- ./my-program

# Cycle attribute (frontend stall? backend stall?):
perf stat -e cycles,stalled-cycles-frontend,stalled-cycles-backend -- ./my-program

Дополнительные perf use cases

# Listing всех доступных events:
perf list | head -30
# Сотни event'ов: hardware, software, tracepoints

# Где syscalls самые частые:
sudo perf trace -p 1234 -- sleep 5

# Sleep / wakeup latency:
sudo perf sched record -- sleep 5
sudo perf sched latency

# Memory allocations:
sudo perf record -e 'kmem:*' -- sleep 5

Когда perf не помогает

• Профилирование Python/Java/Ruby — perf даст имена C-функций, но не ваш код. Нужны language-specific tools (py-spy для Python, async-profiler для JVM).
• IO-bound workload — perf про CPU. Для IO смотрите iostat, iotop, blktrace, eBPF (урок 14.5).
• Distributed system — perf даёт картинку одного хоста. Нужны distributed tracing (Jaeger, Tempo).

Попробуй сам

# 1. Установить perf:
sudo apt install linux-tools-common linux-tools-$(uname -r)
# Или эквивалент для вашей distro

# 2. perf top -- live profile:
sudo perf top
# Подождать несколько секунд. q чтобы выйти

# 3. Профилировать CPU-intensive скрипт (можно бесплатно):
cat > /tmp/burn.py <<'EOF'
import time
def waste():
    x = 0
    for i in range(10_000_000):
        x += i*i
    return x
t = time.time()
while time.time() - t < 30:
    waste()
EOF
python3 /tmp/burn.py &
BURN_PID=$!

sudo perf record -F 99 -g -p $BURN_PID -- sleep 10
kill $BURN_PID

# 4. Посмотреть результат:
sudo perf report --stdio | head -40

# 5. Generate flame graph:
git clone https://github.com/brendangregg/FlameGraph /tmp/FlameGraph
sudo perf script | \
    /tmp/FlameGraph/stackcollapse-perf.pl | \
    /tmp/FlameGraph/flamegraph.pl > /tmp/flame.svg
xdg-open /tmp/flame.svg   # или скачать на свой комп

# 6. perf stat для quick metrics:
perf stat -- python3 -c "print(sum(range(1_000_000)))"

# 7. perf list -- посмотреть available events:
perf list | wc -l
perf list 'cache*' | head