我们首先可以通过

    1. $ go build -o main
    2. $ GODEBUG=gctrace=1 ./main
    4. 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
    5. scvg: 8 KB released
    6. scvg: inuse: 3, idle: 60, sys: 63, released: 57, consumed: 6 (MB)
    7. 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
    8. scvg: inuse: 3, idle: 60, sys: 63, released: 56, consumed: 7 (MB)
    9. 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
    10. scvg: 8 KB released
    11. scvg: inuse: 2, idle: 61, sys: 63, released: 56, consumed: 7 (MB)
    12. 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
    13. scvg: 8 KB released
    14. scvg: inuse: 3, idle: 60, sys: 63, released: 56, consumed: 7 (MB)
    15. scvg: 8 KB released
    16. scvg: inuse: 4, idle: 59, sys: 63, released: 56, consumed: 7 (MB)
    17. 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
    18. scvg: inuse: 5, idle: 58, sys: 63, released: 56, consumed: 7 (MB)
    19. 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
    20. scvg: 8 KB released
    21. scvg: inuse: 1, idle: 62, sys: 63, released: 56, consumed: 7 (MB)

    在这个日志中可以观察到两类不同的信息：

    1. 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
    2. ...

    以及：

    1. scvg: 8 KB released
    2. scvg: inuse: 3, idle: 60, sys: 63, released: 57, consumed: 6 (MB)
    3. scvg: inuse: 3, idle: 60, sys: 63, released: 56, consumed: 7 (MB)
    4. ...

    对于用户代码向运行时申请内存产生的垃圾回收：

    含义由下表所示：

    对于运行时向操作系统申请内存产生的垃圾回收（向操作系统归还多余的内存）：

    1. scvg: 8 KB released
    2. scvg: inuse: 3, idle: 60, sys: 63, released: 57, consumed: 6 (MB)

    含义由下表所示：

    字段 含义
    8 KB released 向操作系统归还了 8 KB 内存
    3 已经分配给用户代码、正在使用的总内存大小 (MB)
    60 空闲以及等待归还给操作系统的总内存大小（MB）
    63 通知操作系统中保留的内存大小（MB）
    57 已经归还给操作系统的（或者说还未正式申请）的内存大小（MB）
    6 已经从操作系统中申请的内存大小（MB）

    go tool trace 的主要功能是将统计而来的信息以一种可视化的方式展示给用户。要使用此工具，可以通过调用 trace API：

    1. package main
    3. func main() {
    4.     f, _ := os.Create("trace.out")
    5.     defer f.Close()
    6.     trace.Start(f)
    7.     defer trace.Stop()
    8.     (...)
    9. }

    并通过 

    1. $ go tool trace trace.out
    2. 2019/12/30 15:50:33 Parsing trace...
    3. 2019/12/30 15:50:38 Splitting trace...
    4. 2019/12/30 15:50:45 Opening browser. Trace viewer is listening on http://127.0.0.1:51839

    命令来启动可视化界面：

    选择第一个链接可以获得如下图示：

    右上角的问号可以打开帮助菜单，主要使用方式包括：

    • w/s 键可以用于放大或者缩小视图
    • a/d 键可以用于左右移动
    • 按住 Shift 可以选取多个事件

    此方式可以通过代码的方式来直接实现对感兴趣指标的监控，例如我们希望每隔一秒钟监控一次 GC 的状态：

    我们能够看到如下输出：

    2. gc 4954 last@2019-12-30 15:19:37.505575 +0100 CET, PauseTotal 29.901171ms
    4. gc 13502 last@2019-12-30 15:19:39.505714 +0100 CET, PauseTotal 128.022307ms
    5. gc 17555 last@2019-12-30 15:19:40.505579 +0100 CET, PauseTotal 182.816528ms
    6. gc 21838 last@2019-12-30 15:19:41.505595 +0100 CET, PauseTotal 246.618502ms
    1. func printMemStats() {
    2.     t := time.NewTicker(time.Second)
    3.     s := runtime.MemStats{}
    5.     for {
    6.         select {
    7.         case <-t.C:
    8.             runtime.ReadMemStats(&s)
    9.             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))
    10.         }
    11.     }
    12. }
    13. func main() {
    14.     go printMemStats()
    15.     (...)
    16. }
    1. $ go run main.go
    3. gc 4887 last@2019-12-30 15:44:56 +0100 CET, next_heap_size@4MB
    4. gc 10049 last@2019-12-30 15:44:57 +0100 CET, next_heap_size@4MB
    5. gc 20378 last@2019-12-30 15:44:59 +0100 CET, next_heap_size@6MB

    当然，后两种方式能够监控的指标很多，读者可以自行查看 [2] 和runtime.MemStats [3] 的字段，这里不再赘述。