Профиль CPU в Go: что смотреть первым и где врут цифры

К вам приходит коллега с профилем CPU и говорит: «Смотри, 40% времени в runtime.mallocgc, надо срочно оптимизировать аллокации». Через день выясняется, что горячая функция вообще не та, замеряли под ненагруженным сервисом, а inuse-объекты в CPU-профиле искали не там, потому что это профиль другого типа. Ревью профиля — это не «посмотреть на топ функций», а проверка того, как профиль сняли, что в нём реально измерено и какой вывод из него следует. Разберём, что спрашивать, когда вам приносят CPU-профиль Go (1.21+) и предлагают что-то на его основе менять.

Что вообще измеряет CPU-профиль в Go

Профилировщик CPU в Go работает по прерываниям: рантайм периодически (по умолчанию около 100 раз в секунду, то есть шаг примерно 10 мс) снимает стек всех горутин, которые в этот момент выполнялись на CPU. Результат — не точное время, а статистика: сколько семплов пришлось на каждую функцию. Отсюда первое, что нужно держать в голове при ревью: CPU-профиль показывает только код, который жёг процессор. Всё, что ждало сети, диска, мьютекса или канала, в него почти не попадает.

Из этого следует частая ошибка. Если сервис тормозит, а в CPU-профиле пусто или семплов мало, значит, узкое место не в вычислениях. Оптимизировать по CPU-профилю функцию, которая на самом деле стоит в ожидании ответа базы, — потерянное время. Для таких случаев есть block- и mutex-профили, это отдельная тема, здесь только CPU.

Первый вопрос на ревью профиля — не «какая функция в топе», а «сколько всего семплов собрано и за какое время». Профиль из 200 семплов за 3 секунды не аргумент ни для чего.

flat против cum: половина неверных выводов отсюда

В выводе go tool pprof две колонки времени, и их постоянно путают:

• flat — время, проведённое в самой функции, без вызванных ею функций;
• cum (cumulative) — время в функции и во всём, что она вызвала.

У main или у HTTP-хендлера почти всегда огромный cum и крошечный flat — это нормально, они почти всё делегируют. Если кто-то приносит «main занимает 90%» и предлагает его оптимизировать — это чтение cum как flat. Оптимизировать имеет смысл функции с большим flat: именно там процессор реально что-то считает.

Как снять профиль, чтобы ему можно было верить

Прежде чем обсуждать содержимое, проверьте, как профиль получен. Самый частый способ для сервиса — net/http/pprof:

package main

import (
	"net/http"
	_ "net/http/pprof" // регистрирует хендлеры на /debug/pprof/
)

func main() {
	// В проде вешайте pprof на отдельный внутренний порт,
	// а не на публичный интерфейс приложения.
	go func() {
		_ = http.ListenAndServe("127.0.0.1:6060", nil)
	}()

	// ... основной сервис ...
	select {}
}

Снимаем 30-секундный профиль под нагрузкой:

# Go 1.21+, профиль снимается 30 секунд реальной работы
go tool pprof http://127.0.0.1:6060/debug/pprof/profile?seconds=30

На что смотреть при ревью самого способа снятия:

1. Была ли нагрузка. Профиль, снятый на простаивающем сервисе, покажет рантайм-поллер и планировщик, а не ваш код. Спросите, шёл ли в эти 30 секунд реальный трафик.
2. Длительность. 30 секунд — разумный минимум для сервиса. Секундный профиль ловит случайную выборку и врёт.
3. Прогрет ли процесс. Первые секунды после старта — JIT-подобных штук в Go нет, но кэши, пулы соединений и sync.Pool ещё холодные. Профиль сразу после деплоя нерепрезентативен.
4. Один процесс или агрегат. Профиль с одной реплики из десяти под неравномерным балансировщиком может не отражать общую картину.

Бенчмарк — отдельный случай

Если профиль снят с бенчмарка через go test -cpuprofile, проверьте флаг -benchtime и что бенч не оптимизирован компилятором в пустоту. Классическая ошибка — результат функции не используется, компилятор выкидывает вызов, а профиль показывает шум. Лечится записью результата в пакетную переменную или runtime.KeepAlive.

Что читать в профиле по порядку

Порядок ревью содержимого:

1. top по flat. Команда top20 -cum=false в интерактивном pprof. Смотрите, какие пользовательские функции реально жгут CPU.
2. Флаги рантайма в топе. Много времени в runtime.mallocgc, runtime.gcBgMarkWorker, runtime.scanobject — это давление на сборщик мусора, то есть слишком много аллокаций. Но CPU-профиль тут только сигнал: сами аллокации ищут в heap-профиле /debug/pprof/heap, а не в CPU.
3. runtime.futex, runtime.usleep, runtime.notesleep. Высокий процент здесь часто значит, что горутины постоянно паркуются и будятся — конкуренция за мьютексы или мелкие задачи, дробящие работу. Проверять в mutex-профиле.
4. Graph и flame graph. Команда web или веб-интерфейс go tool pprof -http=:8080 profile.pb.gz. Flame graph показывает, из каких путей вызова набегает время у горячей функции. Одна функция может быть горячей из-за одного пути, а не всех.

Ловушки интерпретации

Что заворачивать на ревью без обсуждения:

• Проценты без базы. «Функция занимает 15%» — 15% от чего? Если сервис CPU-bound на 20%, эти 15% — реальная цель. Если процесс большую часть времени спит, 15% от малого — не приоритет.
• Инлайнинг искажает стек. Мелкие функции инлайнятся, и их время «переезжает» в вызывающую. Если ожидаемая горячая функция не видна — возможно, она заинлайнена. Снять картину помогает сборка с -gcflags="-l" (отключает инлайнинг) — но только для анализа, не для прода.
• Семплирование не ловит редкое-но-дорогое. Функция, которая вызывается раз в минуту и работает 500 мс, в 30-секундном профиле может не появиться вовсе. Отсутствие в профиле не равно отсутствию проблемы.
• cgo и ассемблер. Время в C-коде через cgo профилировщик Go атрибутирует грубо. Если в профиле большой блок в cgo-вызовах, CPU-профиль Go — не тот инструмент.

Таблица: что означает функция в топе

Как оформить вывод из профиля

Хороший вывод из ревью профиля звучит так: «Под 30 секунд боевого трафика функция X даёт flat 22% от общего CPU, набегает в основном через путь Y, причина — аллокация слайса на каждый запрос, подтверждено heap-профилем». Плохой: «В профиле много mallocgc, давайте убирать аллокации везде».

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

Что делать дальше

Если после ревью решили оптимизировать: снимите базовый профиль, зафиксируйте условия нагрузки, внесите одно изменение, снимите профиль в тех же условиях и сравните через go tool pprof -diff_base=old.pb.gz new.pb.gz. Одно изменение за раз — иначе не поймёте, что помогло. Параллельно держите под рукой heap- и mutex-профили: CPU-профиль отвечает только на вопрос «где жгли процессор», а не «почему всё медленно». Начните с официального руководства по pprof и с флага -http для flame graph — глазами по графу проблема видна быстрее, чем по текстовому топу.