Discovery
Попробуйте другие наши приложения
Как профилировать llama.cpp: три инструмента, которые находят реальный боттлнек
10 июля 2026 г.16 просмотров1

Больше интересного про инференс, AI-инфраструктуру и практику с LLM я публикую в Telegram-канале @fuckup_files.

Я сильно ускорил prefill DeepSeek-V4-Flash на своих 4x RTX 3090, и под тредом с результатами люди чаще всего спрашивали не что именно я поменял, а как вообще найти, что менять. Эта статья и есть ответ на вопрос, как профилировать llama.cpp. Всё практическое: каждая команда ниже реальная и запускается на моём риге.

Дело не в конкретной модели, а в методе. Каждый инструмент отвечает на свой вопрос, и к следующему переходишь исходя из того, что показал предыдущий. Я нашёл три боттлнека тремя разными инструментами, и ни один из них не оказался там, куда показывала интуиция. CUDA-ядра вообще не были первой проблемой.

TL;DR

  1. GGML_SCHED_DEBUG=2 показывает, на каком бэкенде реально выполняется каждая операция. Сначала ловим тихие фолбэки на CPU.
  2. nsys (NVIDIA Nsight Systems) показывает, куда уходит время: столлы в CUDA API и распределение времени по ядрам на GPU.
  3. Отладка replay CUDA-графов показывает, переигрывается ли граф на декоде или перестраивается на каждом токене.
  4. Чинишь одну вещь, профилируешь заново. Боттлнек каждый раз переезжает.

Ментальная модель

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

  1. Работа на неправильном бэкенде. CUDA-ядро может молча ответить, что операция не поддерживается, и планировщик перенесёт её на CPU. Никакой ошибки. GPU простаивает.
  2. Работа реальная, но расточительная. Ядро выполняется на GPU, но делает в 10 раз больше математики, чем нужно, из-за неудачного тайлинга или паддинга.
  3. Работа, которую нельзя переиграть (replay). На декоде граф запусков ядер перестраивается на каждом шаге вместо того, чтобы быть захваченным один раз, и ты платишь оверхед запуска на каждом токене.

Под каждый случай нужен свой инструмент. Токены в секунду по секундомеру говорят, что ты медленный, но никогда не говорят почему.

Инструмент 1: GGML_SCHED_DEBUG=2, работа вообще на GPU?

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

GGML_SCHED_DEBUG=2 ./build-v4-cuda/bin/llama-server <your args> 2>&1 | tee sched.log

Отправь один запрос и читай строки ## SPLIT:

## SPLIT #0: CPU # 0 inputs
node #  0 (  GET_ROWS):  token_embd.weight [ CPU ]   inp_tokens [ CPU ]
## SPLIT #1: CUDA0 # 4 inputs: [embd] [mask] ...
## SPLIT #2: CPU # 1 inputs: ...

Как это читать. Каждый ## SPLIT это непрерывный кусок узлов на одном бэкенде. Здоровый граф почти целиком состоит из CUDA-сплитов. Пара крошечных CPU-сплитов, вроде лукапа эмбеддингов токенов и решейпов, это норма. Охотишься ты за тяжёлой операцией на CPU: attention, matmul, что угодно из горячего цикла. Если видишь FlashAttention или mul_mat в CPU-сплите, вот твой боттлнек, и никакой тюнинг ядер не поможет, пока операция не вернётся на GPU.

Именно так я нашёл баг с attention на CPU. Видеокарты были загружены на 7%, потому что ядро attention требовало ширину KV, кратную 256, наши чанки промпта в это не попадали, ядро отвечало, что конфигурация не поддерживается, и планировщик честно откатывался на CPU. Фикс всегда одной и той же формы: найти, почему CUDA-ядро отказывается (обычно это условие на shape или dtype в диспатче, здесь fattn.cu хотел ширину KV % 256 == 0), и удовлетворить его. В моём случае: допаддить KV до ближайшего кратного 256 и замаскировать хвост, чтобы модель его никогда не видела. Выход остался бит-в-бит идентичным, prefill вырос с 31.6 до 531 t/s.

Инструмент 2: nsys, куда реально уходит время

Когда работа на правильном бэкенде, nsys (NVIDIA Nsight Systems) даёт таймлайн. Не подключайся к работающему серверу. Запускай сервер под nsys с задержкой, чтобы пропустить загрузку модели и профилировать стабильное окно:

nsys profile --delay 200 --duration 40 -o /tmp/prof --force-overwrite true \
  ./build-v4-cuda/bin/llama-server <your args> &
# ждём health, потом отправляем один репрезентативный запрос (реальный длинный промпт)

--delay 200 пропускает первые 200 секунд (загрузка модели плюс прогрев), --duration 40 захватывает окно в 40 секунд. Захват должен попасть на реальный prefill или decode, а не на загрузку.

Дальше читаем два отчёта из .nsys-rep.

Куда уходит время CPU (ловит столлы, аллокации, синхронизации):

nsys stats --report cuda_api_sum /tmp/prof.nsys-rep
 Time (%)   Name
   55.0     cudaMallocHost      <- красный флаг: аллокация pinned host memory в горячем цикле
   21.1     cudaFreeHost
    8.4     cudaMemcpyAsync
    7.0     cudaLaunchKernel

Как это читать. cudaLaunchKernel и cudaMemcpyAsync наверху это норма. cudaMallocHost, cudaFreeHost или жирный cudaStreamSynchronize наверху это столл: что-то аллоцирует или ждёт внутри цикла вместо одного раза на старте. В моём случае эти две строки, в сумме 76%, были отпечатком CPU-фолбэка, который гонял буферы туда-обратно на каждом чанке.

Куда уходит время GPU (ловит расточительные ядра):

nsys stats --report cuda_gpu_kern_sum /tmp/prof.nsys-rep
 Time (%)   Kernel
   30.3     mul_mat_q (type 16)   <- доминирует matmul MoE-экспертов
   25.4     mul_mat_q (type 10)
    5.7     mul_mat_q (type 8)

Как это читать. Это чистое время ядер на GPU, столлы CPU отсюда уже исключены. Что сидит наверху, туда и идёт следующая оптимизация. Здесь отчёт сказал, что matmul-ы MoE в сумме занимают около 61%, значит тюнить attention бессмысленно, цель это тайлинг MoE. Это и есть шаг про перепрофилирование после каждого фикса: победитель меняется каждый раз.

Тот MoE matmul работал примерно в 9 раз выше своего bandwidth-пола, то есть двигал куда меньше данных, чем перемалывал математики. Чтение ядра показало почему: в батче на 512 токенов при 256 экспертах каждому эксперту достаётся около 16 токенов, а ядро тайлилось под безопасный верхний предел в 4096 колонок. Около 87% операций умножения-накопления приходились на паддинг, умножение на ноль. Чтение реального размера корзины на эксперта и тайлинг под него дали +19%.

Дешёвая проверка на здравый смысл, для которой nsys не нужен: смотри nvidia-smi dmon -s u во время прогона. Если загрузка GPU сидит низко там, где должен быть тяжёлый compute, у тебя проблема случая 1 или случая 3 (простой), а не медленное ядро. Похожую детективную историю про невидимую снаружи проблему я разбирал в статье про отладку утечки памяти в vLLM.

Инструмент 3: отладка replay графа, декод переигрывает или перестраивает?

CUDA graphs это главная оптимизация декода: последовательность запусков ядер захватывается один раз, и дальше весь граф переигрывается на каждом токене, так что оверхед запуска платишь один раз вместо сотен. Работает это только если форма графа между шагами не меняется. Если у любого узла меняется shape или указатель, захват инвалидируется, и ты откатываешься к запуску ядер по одному, что тихо съедает большую часть скорости декода.

В моём форке это делает видимым отладочная переменная окружения DSV4_GRAPH_DBG=1. Стоковый llama.cpp такого не печатает, но идея переносится на любой путь с захватом графа: логируй прогрев и каждый перезахват. Запускаем с флагом и читаем stderr:

DSV4_GRAPH_DBG=1 DSV4_CONSTANT_SHAPE=1 ./build-v4-cuda/bin/llama-server <args> 2>&1 | grep DSV4GDBG

Сообщений три, и умение их читать это весь навык:

DSV4GDBG: warmup COMPLETE key=0x.. uid=2079 n=43  first=node_2
DSV4GDBG: warmup RESET    key=0x.. uid=2103 n=129 first=node_926
DSV4GDBG: props changed at node 74/130 op=FLASH_ATTN name=kqv-0
  • warmup COMPLETE: граф этой формы (идентифицируется по key/uid, n узлов) стабилизировался. С этого момента он переигрывается. Это то, что ты хочешь видеть.
  • warmup RESET: у графа, который только что был стабильным, изменилась форма, захват выброшен, и граф исполняется напрямую, пока снова не стабилизируется.
  • props changed at node X/Y op=.. name=..: конкретный узел, который изменился и вызвал сброс. Это самая ценная строка: она называет точную операцию, которая продолжает дрейфовать.

Как читать паттерн:

  • Prefill: будет много разных строк COMPLETE (разные uid), по одной на форму чанка. Это ожидаемо, у prefill несколько разных форм.
  • Decode, здоровый: немного строк COMPLETE в начале, потом тишина. Формы зафиксировались, всё переигрывается. Это цель.
  • Decode, сломанный: warmup RESET стреляет снова и снова по одному и тому же key, или строка props changed повторяется каждые несколько токенов. Граф так и не доходит до replay, ядра запускаются по одному, и декод оставляет большую часть своей скорости на полу.

Фикс: найти операцию из props changed и сделать её форму константной. Именно это здесь делает DSV4_CONSTANT_SHAPE=1: сборка top-512 работает на фиксированной ширине, ширина attention перестаёт меняться, props changed перестаёт стрелять, и декод выходит на стабильный replay. Доказать, что это сработало, можно переключением флага: без него идёт поток строк RESET, с ним они прекращаются.

Когда профилировщик не видит твой вопрос, построй счётчик сам

На некоторые вопросы не отвечает ни один профилировщик. Для sparse attention мне нужно было знать, насколько пересекаются top-512 выборки соседних query-токенов, потому что высокое пересечение означает, что можно собрать данные один раз и переиспользовать. Такого счётчика в профилировщиках нет, поэтому я добавил свой за env-флагом: он печатал статистику пересечений на стороне хоста и показал, что объединение top-k списков 8 токенов всего в 1.5-2.2 раза больше одного списка. Именно это число оправдало постройку общего пути до того, как писать ядро. Прячь такую телеметрию за флагом, чтобы в выключенном состоянии она ничего не стоила, и измеряй ровно ту вещь, на которую собираешься поставить день работы.

Цикл, ещё раз

  1. GGML_SCHED_DEBUG=2: каждая тяжёлая операция на GPU? Сначала чини фолбэки на CPU.
  2. nsys cuda_api_sum + cuda_gpu_kern_sum: куда уходит время? Атакуй верхнюю строку.
  3. Отладка replay графа: декод переигрывает свой граф или перестраивает его на каждом токене?
  4. Почини одну вещь. Вернись к шагу 1. Боттлнек уже переехал.

Две привычки держат процесс честным. Первая: фитируй стоимость на токен прямой и экстраполируй, чтобы знать, какой член квадратичный, до того как оптимизировать. Как вообще честно мерить скорость локальной модели, я разбирал в статье про бенчмарк локальной LLM: TTFT, TPOT и KV cache. Вторая: диффай сырой выход модели против сохранённого референса после каждого изменения, чтобы ускорение, которое тихо поменяло числа, ловилось сразу. Большинство таких оптимизаций дают байт-в-байт идентичный выход, а те две, что сдвигают последний бит, делают это только потому, что меняют порядок суммирования, а это легальный floating point, не баг.

Форк открыт, если хочется почитать сами патчи: github.com/alesha-pro/llama.cpp, ветка ds4-longctx. Всё за env-флагами, дефолтный путь не тронут.

Что ещё почитать


Заинтересовало? Больше практических разборов про LLM, инференс и AI-инфраструктуру — в моём Telegram-канале @fuckup_files.

Мой тг · про факапы@fuckup_files