Go-сервис падает по OOM раз в сутки, а мониторинг честно рисует график растущей памяти и молчит о причине. Знакомая картина? В другой экосистеме на этом месте началась бы установка тяжёлого агента и перезапуск процесса с потерей состояния. В Go профилировщик встроен в сам рантайм: снимки делаются у живого продакшен-процесса по HTTP, без изменения логики и без остановки. pprof показывает точные стеки, в которых сгорает процессорное время, и точные строки кода, где рождаются объекты, съедающие память. Ниже разобран полный цикл диагностики: подключение к сервису, чтение процессорных снимков, работа с пламенными графами и поиск утечек по разнице двух дампов кучи.
Что умеет встроенный профилировщик Go без внешних инструментов
Инструментарий живёт в двух пакетах. Пакет runtime/pprof подходит программам, которые запускаются и завершаются: скрипты, батч-задачи, бенчмарки. Пакет net/http/pprof добавляет HTTP-эндпоинты к долгоживущему сервису и снимает те же данные через обычный GET-запрос. Оба выдают сжатый protobuf с расширением .pb.gz, оба читаются штатной командой go tool pprof, которая идёт вместе с компилятором. Продвинутая сборка того же инструмента развивается в проекте google/pprof и ставится командой go install github.com/google/pprof@latest, но для большинства задач хватает встроенной версии.
Рантайм собирает профили шести видов:
1. cpu фиксирует стеки горутин, активно исполняющихся в момент выборки;
2. heap отражает статистическую выборку аллокаций и текущий состав кучи;
3. goroutine выводит стеки всех живых горутин вместе с их состояниями;
4. threadcreate показывает, где программа порождает потоки операционной системы;
5. block вскрывает места ожидания на каналах и примитивах синхронизации;
6. mutex указывает конкретные точки конкуренции за блокировки.
Профили block и mutex по умолчанию выключены, их включают вызовами runtime.SetBlockProfileRate и runtime.SetMutexProfileFraction. Остальные доступны сразу после импорта пакета. Эндпоинт /debug/pprof/trace отдаёт трассировку исполнения, но это отдельный инструмент: трасса отвечает на вопросы планировщика, профили отвечают на вопросы стоимости. Есть и кастомные профили через pprof.NewProfile, когда команде нужно считать события собственной природы, например обращения к стороннему кэшу.
Безопасное подключение pprof к живому сервису в продакшене
Код подключения умещается в несколько строк:
package main
import (
"log"
"net/http"
_ "net/http/pprof"
)
func main() {
go func() {
log.Println(http.ListenAndServe("127.0.0.1:6060", nil))
}()
if err := run(); err != nil {
log.Fatal(err)
}
}Пустой импорт со знаком подчёркивания регистрирует обработчики на DefaultServeMux, отдельный роутинг писать не нужно. Порт 6060 слушают на локальном или внутреннем интерфейсе: эндпоинт отдаёт стеки вызовов, значения меток и сведения об объектах в памяти. Выносить его в публичную сеть нельзя, на практике порт закрывают фаерволом или шлюзом с проверкой источника запроса.
Батч-задачам HTTP ни к чему, там применяют флаги командной строки:
var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to file")
func main() {
flag.Parse()
if *cpuprofile != "" {
f, err := os.Create(*cpuprofile)
if err != nil {
log.Fatal(err)
}
pprof.StartCPUProfile(f)
defer pprof.StopCPUProfile()
}
run()
}Вызов StopCPUProfile обязателен: без него буфер профилировщика не сбрасывается на диск, и файл останется пустым. defer в main закрывает задачу при любом исходе.
Снимок процессорного времени и чтение топа функций
Процессорный профиль снимается одной командой:
go tool pprof -seconds 30 http://127.0.0.1:6060/debug/pprof/profileЧерез 30 секунд откроется интерактивная оболочка pprof. Рантайм делает примерно 100 выборок в секунду, каждая выборка - это стек горутины, работавшей в тот миг. За полминуты набегает около 3000 сэмплов, и функция, съедающая десятую часть процессорного времени, наберёт около 300 сэмплов. Точность пропорциональна окну измерения: пятисекундный снимок покажет только шум.
Команда top10 перечисляет главных потребителей:
(pprof) top10
Total: 2984 samples
312 10.4% 10.4% 312 10.4% runtime.mapaccess1_fast64
268 9.0% 19.4% 2124 71.2% main.FindLoops
201 6.7% 26.1% 445 14.9% runtime.mallocgc
188 6.3% 32.4% 188 6.3% runtime.memmove
172 5.8% 38.2% 990 33.2% main.DFSПервые две колонки называют плоский (flat) вклад: сколько сэмплов функция провела на вершине стека. Колонки четвёртая и пятая показывают кумулятивный (cum) вклад: сколько сэмплов функция встретила в стеке на любой глубине, включая работу вызванных детей. main.FindLoops сама исполнялась 9% времени, а её поддерево съело 71.2%. Виновник почти всегда прячется в cum, локальный вклад ищут во flat. Ключ -cum пересортировывает топ по кумулятивному столбцу и находит точки ветвления, команда list main.DFS разворачивает профиль вплоть до строк исходника с процентами у каждой, peek подсказывает, кто зовёт функцию и кого зовёт она.
Есть тонкость, экономящая часы работы. Процессорный профиль видит только активный код. Если сервис тормозит, а процессор загружен на 15%, искать горячие функции бессмысленно: время утекает в ожидание, и инструментом становится профиль блокировок или трасса, но никак не CPU.
Flame graph и веб-интерфейс go tool pprof
Текстовый топ отвечает на вопрос "кто виноват", но не показывает форму дерева вызовов. Ключ -http поднимает локальный веб-интерфейс:
go tool pprof -http=:8080 cpu.pb.gzИнтерфейс открывает виды TOP, GRAPH, FLAME GRAPH, PEEK и SOURCE. Пламенный граф читается так: каждая полоса - функция, ширина полосы - доля сэмплов, стек растёт снизу вверх, родитель внизу, дети сверху. Широкое плато из полос одинаковой ширины означает горячий цикл, который уже не дробится на вызовы: функций-детей внутри нет, всё сгорает в самих строках цикла. Клик по полосе приближает поддерево, поиск по имени подсвечивает вхождения по всему графу.
Классическая картина выглядит так: обработчик HTTP зовёт сериализацию ответа, сериализация уходит в encoding/json, половину стека занимают вызовы рефлексии из пакета reflect, а львиная доля сэмплов падает на runtime.mallocgc. Каждое превращение структуры в JSON через рефлексию аллоцирует промежуточные интерфейсы и слайсы байтов. Дальше варианты: сгенерированный сериализатор без рефлексии, кэш готовых ответов, пересмотр схемы данных. Главное - по графу понятно, что чинить, ещё до первой строчки изменений.
Поиск утечек памяти по профилям кучи и разнице снимков
Профиль кучи - выборочный. По умолчанию рантайм регистрирует примерно одну аллокацию на каждые 512 КиБ выделенной памяти, за это отвечает runtime.MemProfileRate со значением 524288 байт. Для рутинной диагностики этого достаточно. Точность растёт с уменьшением порога вплоть до единицы, когда профилировщик видит каждую аллокацию, но каждая единица замедляет программу, поэтому детальный режим включают короткими окнами.
Индексов четыре, и они отвечают на разные вопросы. inuse_space показывает байты, живущие в куче прямо сейчас, он главный инструмент при поиске утечек. inuse_objects считает живые объекты. alloc_space копит все аллокации с момента старта и после сборки мусора не убывает, alloc_objects делает то же для штук. Для снижения давления на GC смотрят alloc_space, для забытых ссылок ищут inuse_space. Переключение выполняется ключом -sample_index=alloc_space.
Классическая диагностика строится на разнице двух снимков:
curl -s "http://127.0.0.1:6060/debug/pprof/heap?gc=1" -o /tmp/heap_t1.pb.gz
sleep 3600
curl -s "http://127.0.0.1:6060/debug/pprof/heap?gc=1" -o /tmp/heap_t2.pb.gz
go tool pprof -base /tmp/heap_t1.pb.gz /tmp/heap_t2.pb.gzПараметр gc=1 заставляет рантайм пройти полный цикл сборки мусора перед снимком, чтобы в дамп не попали объекты-однодневки. Ключ -base строит разницу: pprof показывает только то, что прибавилось за час, сортировка по cum моментально выводит на виновника. Есть и серверный вариант: параметр seconds=3600 на эндпоинте heap отдаёт дельту за час одним запросом.
Типовые находки знакомы каждому, кто хоть раз гонял дифф. За час куча прибавила 400 МБ, весь прирост сидит в map[string]*sessionCache: ключи добавляются в обработчике входа, удаления по таймауту нет, вытеснения устаревших записей никто не завёл. Второй паттерн - горутина, навсегда повисшая на пустом канале и держащая слайс на сотню мегабайт: в диффе кучи она видна как bytes.Buffer, в профиле горутин - как вечное ожидание. Утечка горутин и утечка памяти часто одна история, рассказанная дважды.
Диагностика зависших горутин и конкуренции за мьютексы
Эндпоинт goroutine работает в двух режимах. debug=1 группирует одинаковые стеки и печатает счётчики:
curl -s "http://127.0.0.1:6060/debug/pprof/goroutine?debug=1" | head -3
goroutine profile: total 15234Пятнадцать тысяч горутин у сервиса, которому хватает пары сотен, - приговор, подписанный самим рантаймом. Режим debug=2 печатает полные стеки с временем ожидания. Ищут строки вида chan receive, 142 minutes: горутина, ждущая полтора часа на пустом канале, почти наверняка не дождётся никогда. Причина в девяти случаях из десяти - родитель создал контекст с отменой и забыл вызвать cancel, либо обработчик вышел по таймауту, а фоновая горутина осталась держать буфер.
Профиль блокировок включается двумя строками в main:
func main() {
runtime.SetBlockProfileRate(1_000_000) // одна выборка на 1 мс ожидания
runtime.SetMutexProfileFraction(1) // фиксировать каждый конфликт
// ...
}Читаются снимки с тех же эндпоинтов:
go tool pprof http://127.0.0.1:6060/debug/pprof/block
go tool pprof http://127.0.0.1:6060/debug/pprof/mutexПрофиль mutex показывает, кто держит блокировку и кто на ней выстроился в очередь. Под ростом нагрузки это единственный способ отличить честное ожидание от затяжной конкуренции на горячем мьютексе.
Точности добавляют метки, появившиеся в Go 1.9. Запрос помечают перед входом в обработчик:
pprof.Do(ctx, pprof.Labels("endpoint", "/api/v1/upload"), func(ctx context.Context) {
processUpload(ctx)
})После этого в веб-интерфейсе pprof расходы фильтруются по метке: сразу видно, какой эндпоинт сжигает процессор или аллоцирует больше прочих, без слепого перебора по стекам.
Цена профилирования и регулярные снимки в эксплуатационной практике
Профилирование небесплатно. Постоянно включённый CPU-профиль снижает пропускную способность, детальная запись аллокаций замедляет сервис, а одновременный съём нескольких профилей искажает картину: точный профиль памяти портит процессорный, профиль блокировок мешает трассировке планировщика. Правила простые: снимать один профиль за раз, тяжёлые режимы включать короткими окнами, штраф замерять заранее на стенде, а не выяснять по просадке метрик в продакшене.
Рабочая схема для фермы однотипных реплик выглядит так: раз в час выбирать случайную реплику и снимать 30 секунд процессорного профиля, раз в сутки забирать пару дампов кучи, складывать файлы .pb.gz в объектное хранилище и автоматически сравнивать со вчерашним. Утечка, которая копится неделю, ловится по суточному диффу ещё до срабатывания аларма по памяти. Бенчмарки живут по тем же правилам:
go test -bench=Serialize -memprofile mem.pb.gz -cpuprofile cpu.pb.gz ./...Флаги -blockprofile и -mutexprofile у go test включают соответствующие снимки в бенчмарках, а переменная окружения GODEBUG=gctrace=1 печатает сводку каждой сборки мусора в stderr и помогает увидеть частоту GC ещё до всякого профилирования.
pprof не экстренное спасение, а приборная панель сервиса. Метрики мониторинга говорят "стало хуже", стек из профиля называет строку кода. Сервис, у которого снимают профили еженедельно, деградирует медленнее и чинится быстрее: каждая находка ложится в копилку команды, а разница двух дампов кучи превращает спор о гипотезах в одну команду go tool pprof -base. В конечном счёте ценят именно это: не обещание быстрого кода, а способ найти конкретное место, за которое платят процессор и память.