CPU profile показывает, где процессор тратится. Он не отвечает, почему запрос медленный: часть времени уходит на сеть, диск, мьютексы и ожидание планировщика.

Снимок

go tool pprof -http=:8081 "http://localhost:6060/debug/pprof/profile?seconds=30"

Профиль включают на репрезентативной нагрузке. На пустом сервере видна инициализация, а не бизнес-работа.

flat - время в самой функции без потомков, cum - вместе с вызовами ниже. Большая flat показывает горячую строку, большая cum - ветку, которая привела к затратам.

CPU profile flat сама функция cum функция и потомки

Flat ведет к горячей строке, cum - к ветке вызовов, которая к ней привела. Сетевое ожидание в CPU-профиле не считается работой процессора.

Что искать

  • широкие полосы бизнес-кода;
  • runtime.mallocgc и runtime.gcBgMarkWorker - аллокации и сборку;
  • sync.(*Mutex).Lock и runtime.futex - ожидание блокировок;
  • syscall и netpoll - ожидание ввода-вывода;
  • сериализацию, рефлексию и регулярные выражения.

Если основная доля уходит на сеть, оптимизация CPU-кода не поможет. Нужны таймауты, пулы, меньше запросов или более быстрая зависимость.

Блокировки

/debug/pprof/mutex показывает удержание мьютексов, /debug/pprof/block - ожидание каналов и других примитивов. Включают их на время расследования, потому что профилирование влияет на работу.

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

Проверка

После изменения снимают профиль снова при той же нагрузке. Смотрят не только итоговую задержку, но и исчезновение полосы причины. Затем сравнивают latency и пропускную способность: оптимизация одной метрики не должна сломать остальные.

Коротко

  • flat ищет горячую функцию, cum - путь к ней.
  • CPU, GC, блокировки и сеть различают по профилю.
  • Блокировки исследуют отдельными mutex/block профилями.
  • Результат подтверждают повторным профилем и нагрузочным замером.