сеньорчикОткрыть в Telegram
← вся теориятеория к собесу · Ошибки и рантайм Go

Профилирование Go: pprof

pprof и трассировка

Запустил 2000 горутин, каждая ждёт на канале, в который никто не пишет. runtime.NumGoroutine() показывает 2001, профиль goroutine - 2001 запись, и все на одной строке кода. Вот так утечка горутин выглядит в инструментах. Спрашивают, какие профили бывают, чем alloc отличается от inuse и почему pprof нельзя вешать наружу.

Стержень: профиль отвечает на вопрос «где жжётся ресурс», трассировка - на вопрос «где мы ждали».

// Формулировки: «как найти утечку?», «чем alloc_space отличается от inuse_space?», «безопасно ли включать pprof в проде?»

Какие профили и что в них смотреть

Попросил рантайм перечислить встроенные профили, вышло шесть: allocs, block, goroutine, heap, mutex, threadcreate. Первый и четвёртый про память, goroutine - стеки всех живых горутин, block и mutex - про ожидание на синхронизации, threadcreate - сколько потоков рантайм завёл за жизнь процесса.

Утечку горутин видно с первого экрана: мои 2000 висельников собрались в одну запись со стеком, упирающимся в приём из канала. Никаких раскопок, число прямо там.

В профиле кучи две метрики, которые путают чаще всего. alloc_space - выделено за всё время работы, счётчик только растёт. inuse_space - занято живыми объектами прямо сейчас. На моём прогоне это 338 МиБ против 84,5 МиБ: почти всё выделенное давно собрано.

// Отсюда трактовка. Растёт inuse при ровной нагрузке - ищи утечку. Большой alloc при ровном inuse - утечки нет, есть поток временных объектов, и это вопрос нагрузки на сборщик, а не пропажи памяти.

alloc_space
выделено за всё время, счётчик только растёт
inuse_space
занято живыми объектами прямо сейчас

Когда профиль молчит, а проблема есть

Картинка из жизни: задержка ответа 800 мс, процессор загружен на 5%. CPU-профиль в такой ситуации покажет ерунду - он берёт срезы стеков работающих горутин, а твои ничего не делают, они ждут.

Тут нужен go tool trace. Он рисует временную шкалу: когда горутина стартовала, где заблокировалась и на чём, сколько простаивали логические процессоры, когда работал сборщик. Ожидание на сети, на мьютексе, на канале видно глазами, без догадок.

// Разделение простое, и его хорошо произнести вслух на собеседовании. Профиль отвечает «где жгутся такты», трассировка - «почему мы ждали». Большая задержка при недогруженном процессоре это всегда второй вопрос.

go tool trace
временная шкала блокировок, сборок и простоя P
сэмплирование
профиль берёт срезы стеков, а не пишет всё подряд

pprof в проде: цена и безопасность

Строка импорта net/http/pprof делает больше, чем выглядит: она регистрирует обработчики в http.DefaultServeMux. Публичный сервер слушает на том же муксе - и наружу открылись стеки всех горутин, аргументы командной строки и переменные окружения процесса, где обычно лежат пароли к базе.

Лечится отдельным слушателем на внутреннем порту, куда из интернета не попасть, а ходят туда через туннель. Это пять строк: свой ServeMux, свой http.Server, отдельный адрес.

// Про цену. Постоянной нагрузки профилирование не создаёт, профиль снимается по запросу и только на время снятия. Профиль кучи вообще сэмплируется всегда: runtime.MemProfileRate у меня показал 524288, то есть один срез на каждые 512 КиБ выделенного. А вот детектор гонок -race замедляет в разы и жрёт память, ему в проде не место.

DefaultServeMux
общий маршрутизатор, куда pprof лезет сам
внутренний порт
отдельный слушатель для отладочных обработчиков

Как отвечать: «Как искать утечку памяти или горутин в работающем сервисе?»

Начинаю с метрик, а не с профиля. Для горутин это runtime.NumGoroutine: при ровной нагрузке число колеблется вокруг постоянного уровня, монотонный рост - сигнал утечки. Для памяти смотрю inuse_space, объём живых объектов сейчас; растёт при ровной нагрузке, значит что-то не отпускается. Здесь важно не перепутать метрики: alloc_space считает выделенное за всё время, и большой alloc при ровном inuse означает просто поток временных объектов - это про нагрузку на сборщик, а не про утечку. У меня на прогоне было 338 МиБ выделено против 84,5 МиБ живых, и это нормальная картина. Дальше иду в pprof. Профиль goroutine показывает стеки всех живых горутин, и утечка видна сразу: я проверял на двух тысячах горутин, заблокированных на пустом канале, они собираются в одну запись с числом рядом. Если же процессор недогружен, а задержки большие, беру не профиль, а go tool trace - он показывает, где ждали, чего CPU-профиль в принципе не видит. И держу pprof на отдельном внутреннем порту: импорт net/http/pprof регистрируется в DefaultServeMux без всякой защиты и выдаёт наружу стеки и переменные окружения.

Сильный ответ: методика идёт от метрик к профилю, а не наоборот, разведены alloc и inuse с правильной трактовкой обеих, назван случай, когда нужна трассировка вместо профиля, и добавлено требование безопасности. Последнее сразу показывает человека, который это эксплуатировал, а не читал.

На чём валят

  • Путают alloc_space и inuse_space и ищут утечку не в той метрике.
  • Импортируют net/http/pprof в публичный сервер и отдают наружу стеки с переменными окружения.
  • Берут CPU-профиль там, где проблема в ожидании, и ничего не находят.
  • Ищут утечку горутин детектором гонок. Он про одновременный доступ к памяти, а не про застрявшие горутины.
  • Считают, что включённый pprof постоянно нагружает сервис.

Проверьте себя

Пять вопросов из банка по этой подтеме. Всего их 6, остальные разбираются в тренажёре.

  1. #go_pprof1 / 5
    Как pprof помогает подтвердить утечку горутин?
    A)Goroutine-профиль покажет рост числа горутин и где именно они стоят
    B)Heap-профиль печатает список незакрытых каналов
    C)CPU-профиль выявит горутины, что зависли вообще без нагрузки на процессор
    D)Block-профиль автоматически перезапустит зависшие горутины
    показать ответ и разбор
    +A)Goroutine-профиль покажет рост числа горутин и где именно они стоят

    // разбор: Утечку горутин ловят goroutine-профилем: он показывает общее число горутин и стеки — где именно они стоят (например, все висят на приёме из канала). Если между снимками под нагрузкой число монотонно растёт и не спадает, а стеки одинаковы — это утечка. CPU/heap для этого не годятся: заблокированная горутина не жжёт CPU и почти не аллоцирует.

  2. #go_pprof2 / 5
    Как в Go снять профиль CPU для куска работы без внешних сервисов?
    A)Вставить таймеры time.Now() вручную вокруг каждого вызова
    B)Профилирование доступно только через сторонние платные сервисы
    C)Запустить программу с GODEBUG=cpu — рантайм сам напишет профиль
    D)runtime/pprof: StartCPUProfile/StopCPUProfile, затем go tool pprof
    показать ответ и разбор
    +D)runtime/pprof: StartCPUProfile/StopCPUProfile, затем go tool pprof

    // разбор: Для CPU-профиля куска кода используют runtime/pprof: pprof.StartCPUProfile(f) в начале, defer pprof.StopCPUProfile() — рантайм пишет сэмплированный профиль в файл, который открывают go tool pprof. В бенчмарках проще: go test -cpuprofile. Ручные time.Now() дают лишь грубые тайминги, не показывая, ГДЕ горит время по функциям.

  3. #go_pprof3 / 5
    Чем в профиле кучи отличаются alloc_space и inuse_space?
    A)alloc_space — выделено за всё время, inuse_space — занято живыми объектами сейчас
    B)alloc_space считает стек, inuse_space — только кучу процесса
    C)alloc_space измеряется в объектах, а inuse_space — в байтах
    D)alloc_space показывает запрошенное у системы, inuse_space — фактически отданное
    показать ответ и разбор
    +A)alloc_space — выделено за всё время, inuse_space — занято живыми объектами сейчас

    // разбор: Это разные вопросы к одному профилю. Ищете утечку — смотрите inuse: что живо прямо сейчас и не отпускается. Оптимизируете нагрузку на сборщик — смотрите alloc: где создаётся мусор, пусть он и умирает сразу. Метрика, растущая в inuse при стабильной нагрузке, — характерный признак утечки; большой alloc при ровном inuse означает просто много временных объектов.

  4. #go_pprof4 / 5
    Что показывает трассировка выполнения (go tool trace), чего не видно в профиле CPU?
    A)Разбивку процессорного времени по функциям с точностью до строки
    B)События планировщика и сборщика: где горутины ждали и что их блокировало
    C)Полный список аллокаций с указанием размера каждого объекта
    D)Покрытие кода тестами во время работы под нагрузкой
    показать ответ и разбор
    +B)События планировщика и сборщика: где горутины ждали и что их блокировало

    // разбор: Профиль CPU отвечает «где жгутся такты» и молчит про ожидание. Трассировка показывает временную шкалу: старты и блокировки горутин, паузы сборщика, сколько времени P простаивали, где встали на системном вызове. Именно её берут, когда процессор недогружен, а задержка большая, — то есть когда проблема не в вычислениях, а в ожидании.

  5. #go_pprof5 / 5
    Что произойдёт, если импортировать net/http/pprof в сервисе, открытом в интернет?
    A)Ничего: обработчики профилирования требуют отдельной аутентификации
    B)Сервис откажется стартовать без явного включения профилирования
    C)Профили и стеки станут доступны любому, кто знает путь /debug/pprof
    D)Производительность упадёт вдвое из-за постоянного сбора профилей
    показать ответ и разбор
    +C)Профили и стеки станут доступны любому, кто знает путь /debug/pprof

    // разбор: Импорт с пустым идентификатором регистрирует обработчики в http.DefaultServeMux — без всякой защиты. Наружу утекают стеки всех горутин, аргументы командной строки и переменные окружения, а запрос профиля CPU ещё и нагружает сервис: получается и утечка внутренностей, и способ его придушить. Правильно — вешать pprof на отдельный внутренний порт.

дальше

Теорию прочитали. Навык ставится повторением

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