Суть Читай реальный вывод pprof, схлопнутый flame graph, allocation profile и конфиг профайлера — предскажи поведение и выбери диагноз с наибольшим рычагом.
Высота — путь к senior
НольJuniorMiddleSenior
Ты на senior-высоте — в орбите
◷ 14 min
Профили и конфиги — это место, где проблемы профайлинга реально диагностируются. Прочитай вывод и настройку, затем выбери прочтение, на котором остановится senior-инженер, прежде чем трогать что-либо ещё.
Цель
Отработай петлю, которую запускаешь в каждом инциденте профайлинга: читаешь профиль или конфиг, выводишь, что делает рантайм, и приходишь к верному диагнозу, а не к правдоподобному-но-неверному.
Сниппет 1 — схлопнутый список стеков flame graph
Многие инструменты (stackcollapse Брендана Грегга, импорт в speedscope) представляют flame graph как строки stack;frames count. Вот верхние строки 30-секундного CPU-профиля HTTP-сервиса:
Всего сэмплов ~3125. Что говорит этот CPU-профиль и где фикс?
Heads-up queryDB здесь лишь ~210 сэмплов (~7%). К тому же CPU-профиль показывает время БД только пока поток on-CPU; само ожидание запроса off-CPU и невидимо. CPU-hotspot — это сериализация.
Heads-up Позиция и алфавитный порядок ничего не говорят о стоимости; говорит ширина (число сэмплов). 95 из ~3125 — это ~3%, ничтожно рядом с ~70% под serializeResponse.
Heads-up Счётчики сэмплов — это доля CPU-времени, а не число вызовов. 2180 из ~3125 сэмплов в одном поддереве — доминирующий hotspot, который стоит чинить.
Сниппет 2 — CPU против wall-clock для одного медленного спана
trace span: GET /report wall = 612 ms cpu profile (this span, by trace-id): on-CPU = 38 ms off-cpu profile (this span): waiting = 561 ms -> sql.(*DB).QueryContext 540 ms -> sync.(*Mutex).Lock 18 ms
Викторина
Completed
Читая эти два профиля вместе, какой верный диагноз и следующий шаг?
Heads-up Срезать 38 мс вычислений, когда 561 мс уходит на ожидание, — погрешность округления. Отношение CPU/wall ниже ~30% — сигнал оставить CPU-код в покое и гнаться за off-CPU ожиданием.
Heads-up 18 мс — это ~3% wall-времени. Доминирующее ожидание — запрос к БД на 540 мс; мьютекс вторичен.
Heads-up Они согласованы: on-CPU (38) + off-CPU (561) ≈ wall (612). Именно так два типа профилей разбивают wall-clock время запроса.
Сниппет 3 — diff allocation (heap) профиля
go tool pprof -base baseline.heap current.heap (45 min apart, same load) flat flat% cum cum% 410MB 61.2% 410MB 61.2% (*logEntry).format -> strings.Join in hot log path 95MB 14.1% 95MB 14.1% json.Marshal 42MB 6.3% 42MB 6.3% bytes.growSlice
Викторина
Completed
Это base-diff heap-профиля под стабильной нагрузкой. На что это вероятнее всего указывает и какой фикс с наибольшим рычагом?
Heads-up Base-diff изолирует рост. 410MB роста в лог-пути — это ~3x следующей записи и очевидный главный подозреваемый; json.Marshal вторичен.
Heads-up Base-diff двух heap-профилей под стабильной нагрузкой — стандартная техника обнаружения утечек: функции, чья живая аллокация выросла, и есть место накопления памяти.
Heads-up GOGC меняет, когда запускается GC, а не удерживает ли лог-путь память. Если это настоящая утечка удержания, никакой тюнинг GC не освободит ещё достижимые объекты — чини аллокацию/удержание.
Сниппет 4 — конфиг агента continuous profiler
profiler: cpu: enabled: true sample_rate_hz: 1000 # default for this service is 100 symbolize: synchronous # resolve symbols on the sampling thread max_stack_depth: 256 upload_interval: 1s
Викторина
Completed
Команда сообщает, что этот агент добавляет ~12% CPU вместо ожидаемых 2-5%. Читая конфиг, какие две правки вернут его в бюджет?
Heads-up CPU-профайлинг на дефолте 100 Hz с асинхронной символизацией идёт на 2-5%. Overhead здесь — это конфиг: 10x sample rate и синхронная символизация в потоке, а не сама фича.
Heads-up Обрезка до 8 фреймов испортит глубокие стеки и потеряет контекст hot-пути. Доминирующие здесь стоимости — 10x rate и синхронная символизация, а не лимит в 256 фреймов.
Heads-up Сжатые аплоады дёшевы и редки. CPU-стоимость в сэмплинге и синхронной символизации на потоке приложения, а не в каденции сетевых аплоадов.
Итог
Каждый инцидент профайлинга читается в профилях и конфигах: доминирующее поддерево CPU flame graph (здесь — JSON через reflection) — это on-CPU hotspot; отношение CPU/wall решает, гнаться ли за on-CPU кодом или off-CPU ожиданием; base-diff heap-профиля под стабильной нагрузкой локализует утечку до функции, чья живая память выросла; а агент сверх бюджета — почти всегда завышенный sample rate плюс синхронная символизация в потоке. Диагностируй по профилю, чини доминирующую причину, затем перепрофилируй для подтверждения.