Давайте возьмем следующую программу в качестве примера, сначала используем четыре различных способа, чтобы представить, как наблюдать GC, а затем обсудим, как оптимизировать GC с помощью нескольких подробных примеров в следующих вопросах.
package main
func allocate() {
_ = make([]byte, 1<<20)
}
func main() {
for n := 1; n < 100000; n++ {
allocate()
}
}
Метод 1: Godebug = GCTRace = 1
Сначала мы можем просмотреть команду: godebug = gctrace = 1 ./main, как показано ниже:
$ go build -o main
$ GODEBUG=gctrace=1 ./main
gc 1 @0.000s 2%: 0.009+0.23+0.004 ms clock, 0.11+0.083/0.019/0.14+0.049 ms cpu, 4->6->2 MB, 5 MB goal, 12 P
scvg: 8 KB released
scvg: inuse: 3, idle: 60, sys: 63, released: 57, consumed: 6 (MB)
gc 2 @0.001s 2%: 0.018+1.1+0.029 ms clock, 0.22+0.047/0.074/0.048+0.34 ms cpu, 4->7->3 MB, 5 MB goal, 12 P
scvg: inuse: 3, idle: 60, sys: 63, released: 56, consumed: 7 (MB)
gc 3 @0.003s 2%: 0.018+0.59+0.011 ms clock, 0.22+0.073/0.008/0.042+0.13 ms cpu, 5->6->1 MB, 6 MB goal, 12 P
scvg: 8 KB released
scvg: inuse: 2, idle: 61, sys: 63, released: 56, consumed: 7 (MB)
gc 4 @0.003s 4%: 0.019+0.70+0.054 ms clock, 0.23+0.051/0.047/0.085+0.65 ms cpu, 4->6->2 MB, 5 MB goal, 12 P
scvg: 8 KB released
scvg: inuse: 3, idle: 60, sys: 63, released: 56, consumed: 7 (MB)
scvg: 8 KB released
scvg: inuse: 4, idle: 59, sys: 63, released: 56, consumed: 7 (MB)
gc 5 @0.004s 12%: 0.021+0.26+0.49 ms clock, 0.26+0.046/0.037/0.11+5.8 ms cpu, 4->7->3 MB, 5 MB goal, 12 P
scvg: inuse: 5, idle: 58, sys: 63, released: 56, consumed: 7 (MB)
gc 6 @0.005s 12%: 0.020+0.17+0.004 ms clock, 0.25+0.080/0.070/0.053+0.051 ms cpu, 5->6->1 MB, 6 MB goal, 12 P
scvg: 8 KB released
scvg: inuse: 1, idle: 62, sys: 63, released: 56, consumed: 7 (MB)
В этом журнале можно наблюдать два разных типа информации:
gc 1 @0.000s 2%: 0.009+0.23+0.004 ms clock, 0.11+0.083/0.019/0.14+0.049 ms cpu, 4->6->2 MB, 5 MB goal, 12 P
gc 2 @0.001s 2%: 0.018+1.1+0.029 ms clock, 0.22+0.047/0.074/0.048+0.34 ms cpu, 4->7->3 MB, 5 MB goal, 12 P
...
а также:
scvg: 8 KB released
scvg: inuse: 3, idle: 60, sys: 63, released: 57, consumed: 6 (MB)
scvg: inuse: 3, idle: 60, sys: 63, released: 56, consumed: 7 (MB)
...
Для сборки мусора, сгенерированной пользовательским кодом, запрашивающим память из среды выполнения:
gc 2 @0.001s 2%: 0.018+1.1+0.029 ms clock, 0.22+0.047/0.074/0.048+0.34 ms cpu, 4->7->3 MB, 5 MB goal, 12 P
Значение показано в таблице ниже:
wall clockОтносится к фактическому времени от выполнения до завершения, включая время, затраченное другими программами и этой программой;cpu timeОтносится к тому времени, когда конкретная программа использует ЦП; они имеют следующую связь:
- Настенные часы
- настенные часы ≈ процессорное время: не выполняется параллельно
- настенные часы > процессорное время: преимущество многоядерности неочевидно
Для сборки мусора, созданной путем запроса памяти у операционной системы во время выполнения (возврат избыточной памяти в операционную систему):
scvg: 8 KB released
scvg: inuse: 3, idle: 60, sys: 63, released: 57, consumed: 6 (MB)
Значение показано в таблице ниже:
Способ 2: перейти к трассировке инструмента
Основная функция трассировки инструмента go — визуально отображать статистическую информацию для пользователя. Чтобы использовать этот инструмент, вызовите API трассировки:
package main
func main() {
f, _ := os.Create("trace.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
(...)
}
И запустите визуальный интерфейс, выполнив следующую команду:
$ go tool trace trace.out
2020/12/09 12:50:33 Parsing trace...
2020/12/09 12:50:38 Splitting trace...
2020/12/09 12:50:45 Opening browser. Trace viewer is listening on http://127.0.0.1:51839
Выберите первую ссылку, чтобы получить следующую иллюстрацию:
Знак вопроса в правом верхнем углу может открыть меню справки.Основные способы использования включают в себя:
- Кнопка w/s может использоваться для увеличения или уменьшения масштаба.
- Клавиши a/d можно использовать для перемещения влево и вправо
- Удерживайте Shift, чтобы выбрать несколько событий
Способ 3: отладка.ReadGCStats
Этот метод может напрямую отслеживать интересующие индикаторы через код, например, мы хотим отслеживать состояние GC каждую секунду:
func printGCStats() {
t := time.NewTicker(time.Second)
s := debug.GCStats{}
for {
select {
case <-t.C:
debug.ReadGCStats(&s)
fmt.Printf("gc %d last@%v, PauseTotal %v\n", s.NumGC, s.LastGC, s.PauseTotal)
}
}
}
func main() {
go printGCStats()
(...)
}
Мы можем увидеть следующий вывод:
$ go run main.go
gc 4954 last@2020-12-09 13:19:37.505575 +0100 CET, PauseTotal 29.901171ms
gc 9195 last@2020-12-09 13:19:38.50565 +0100 CET, PauseTotal 77.579622ms
gc 13502 last@2020-12-09 13:19:39.505714 +0100 CET, PauseTotal 128.022307ms
gc 17555 last@2020-12-09 13:19:40.505579 +0100 CET, PauseTotal 182.816528ms
gc 21838 last@2020-12-09 13:19:41.505595 +0100 CET, PauseTotal 246.618502ms
Способ 4: время выполнения.ReadMemStats
В дополнение к использованию методов, предоставляемых пакетом отладки, вы также можете осуществлять мониторинг непосредственно через API-интерфейсы, связанные с памятью во время выполнения:
func printMemStats() {
t := time.NewTicker(time.Second)
s := runtime.MemStats{}
for {
select {
case <-t.C:
runtime.ReadMemStats(&s)
fmt.Printf("gc %d last@%v, next_heap_size@%vMB\n", s.NumGC, time.Unix(int64(time.Duration(s.LastGC).Seconds()), 0), s.NextGC/(1<<20))
}
}
}
func main() {
go printMemStats()
(...)
}
$ go run main.go
gc 4887 last@2020-12-09 13:44:56 +0100 CET, next_heap_size@4MB
gc 10049 last@2020-12-09 13:44:57 +0100 CET, next_heap_size@4MB
gc 15231 last@2020-12-09 13:44:58 +0100 CET, next_heap_size@4MB
gc 20378 last@2020-12-09 13:44:59 +0100 CET, next_heap_size@6MB
Конечно, есть много индикаторов, которые можно отслеживать двумя последними способами, вы можете сами проверить поля debug.GCStats и runtime.MemStats, которые здесь повторяться не будут.
Если вы хотите узнать больше о языке Go, приглашаем вас обратить внимание на публичный аккаунт «Go Keyboard Man», чтобы общаться и учиться вместе.
рекомендуемая статья:
GC (сборка мусора) на языке Go