ℹ️ В статье речь идёт о Go 1.13.
В Go имеется инструмент для проведения трассировки и получения подробного представления о работе программы во время её выполнения. Он активируется с помощью флага -trace
с тестами из pprof
для проведения трассировки в режиме реального времени или в любом месте кода благодаря пакету trace
. Этот инструмент можно сделать ещё более мощным за счёт включения в него собственных трассировок. Посмотрим, как он работает.
Логика работы
Логика работы инструмента предельно проста. Любое событие, такое как выделение памяти, все фазы сборки мусора, горутины при запуске, паузе и т.д., статически записывается стандартной библиотекой Go и форматируется для дальнейшего отображения. Но прежде чем записывать, Go «останавливает мир» и делает моментальный снимок, фиксируя состояние текущих горутин.
Это даёт возможность Go впоследствии правильно составлять жизненный цикл каждой горутины. Вот последовательность действий на этом этапе:
Затем собранные события добавляются в буфер, который впоследствии по достижении максимальной заполненности переходит в список заполненных буферов. Вот схематичное изображение того, что происходит на этом этапе:
Теперь трассировщику нужно как-то сформировать дамп этих трассировок. Для этого при запуске трассировки Go создаёт горутину. Эта горутина формирует дамп данных по мере готовности и приостанавливается в ожидании следующих трассировок. Вот как всё это выглядит:
Теперь, когда мы разобрались с логикой работы инструмента для проведения трассировок, обратимся к этим самым трассировкам.
Трассировки
После того как трассировка сгенерирована, можно сделать её визуализацию. Для этого используем команду go tool trace my-output.out
. В качестве примера возьмём несколько трассировок:
Большинство из них очень простые. Трассировки, связанные со сборщиком мусора, обозначены синим GC
:
Попробуем в них разобраться:
STW
— это две фазы «остановки мира» в сборщике мусора. Здесь горутины останавливаются;GC (idle)
— это горутины, которые помечают память, когда у них нет работы;MARK ASSIST
— это горутины, которые помогают помечать память во время её выделения;GXX runtime.bgsweep
— это фаза очистки памяти после завершения работы сборщика мусора;GXX runtime.gcBgMarkWorker
— это выделенные фоновые горутины, которые помогают помечать память.
Но есть трассировки, в которых разобраться совсем нелегко. Рассмотрим некоторые из них:
proc start
вызывается, когда процессор связан с потоком. Это происходит при запуске нового потока или при выходе из системного вызова;
proc stop
вызывается, когда поток не связан с текущим процессором. Это происходит при блокировании потока в системном вызове или при завершении потока;
syscall
вызывается, когда горутина выполняет системный вызов;
unblock
вызывается, когда горутина разблокирована от системного вызова — в этом случае от блокированного канала придёт пометка(sysexit)
и т.д.:
Трассировки можно улучшить, благо Go даёт возможность определять и визуализировать свою собственную трассировку, а также трассировки из стандартной библиотеки.
Пользовательские трассировки
Трассировки, которые мы можем определять, имеют два иерархических уровня:
- верхний уровень с задачей, началом и концом;
- подуровень с регионом.
Вот простой пример:
func main() {
ctx, task := trace.NewTask(context.Background(), "main start")
var wg sync.WaitGroup
wg.Add(2)
go func() {
defer wg.Done()
r := trace.StartRegion(ctx, "reading file")
defer r.End()
ioutil.ReadFile(`n1.txt`)
}()
go func() {
defer wg.Done()
r := trace.StartRegion(ctx, "writing file")
defer r.End()
ioutil.WriteFile(`n2.txt`, []byte(`42`), 0644)
}()
wg.Wait()
defer task.End()
}
Эти новые трассировки можно визуализировать прямо из инструмента для проведения трассировки go tool через меню User-defined tasks (задачи, определённые пользователем):
Также в задачу можно записать произвольный лог:
ctx, task := trace.NewTask(context.Background(), "main start")
trace.Log(ctx, "category", "I/O file")
trace.Log(ctx, "goroutine", "2")
Эти логи окажутся в горутине, занимающейся настройкой задачи:
Кроме того, задачи могут быть встроены в другие задачи путём получения контекста из родительской задачи и т.д.
Но трассировка всех этих событий в режиме реального времени из продакшена, которая возможна благодаря pprof
, может немного ухудшить производительность.
Влияние на производительность
Понять влияние трассировок на производительность может помочь простой бенчмарк-тест. Один запустится с флагом -trace
, а другой без флага. Вот какие результаты даёт бенчмарк-тест функции ioutil.ReadFile()
с большим количеством событий:
name time/op
ReadFiles-8 48.1µs ± 0%
name time/op
ReadFiles-8 63.5µs ± 0% // с трассировкой
Здесь влияние составляет приблизительно 35% и может варьироваться в зависимости от приложения. Однако существуют инструменты, такие как StackDriver, которые позволяют проводить непрерывное профилирование на продакшене, сохраняя при этом расход вычислительных ресурсов в приложении на невысоком уровне.
Читайте также:
- Go: как циклы преобразуются в ассемблерную программу?
- На собеседование в Google через челлендж Python #1
- Бинарное дерево на Go для новичка
Перевод статьи Vincent Blanchon: Go: Discovery of the Trace Package