当前位置：首页 > news >正文

go gc信息如何查看

news 来源：原创 2024/9/20 12:31:40

1.几种常见方法

1.1.设置环境变量 GODEBUG打印GC日志

通过设置 GODEBUG 环境变量来启用GC的详细日志。
具体来说，设置 GODEBUG=gctrace=1 可以打印GC的详细信息。

示例
在运行Go程序时，设置环境变量：

GODEBUG=gctrace=1 go run your_program.go

或者在代码中设置环境变量：

package mainimport ("os""runtime"
)func main() {// 设置环境变量os.Setenv("GODEBUG", "gctrace=1")// 触发GC以查看日志runtime.GC()// 你的程序逻辑
}

1.2.使用 debug.ReadGCStats

可以使用 runtime/debug 包中的 SetGCPercent 函数来调整GC的频率，并通过 PrintGCStats 函数打印GC的统计信息。
示例

package mainimport ("fmt""runtime/debug""time"
)func main() {// 设置GC的频率debug.SetGCPercent(100)// 启动一个goroutine定期打印GC统计信息go func() {var stats debug.GCStatsfor {time.Sleep(10 * time.Second)debug.ReadGCStats(&stats)fmt.Printf("GC Stats: %+v\n", stats)}}()// 模拟一些内存分配for i := 0; i < 10; i++ {_ = make([]byte, 10<<20) // 10 MBtime.Sleep(1 * time.Second)}
}

output:

GC Stats: {
LastGC:2024-08-24 11:41:57.930373 +0800 CST 
NumGC:10 
PauseTotal:657.732µs 
Pause:[38.41µs 79.84µs 41.56µs 44.338µs 45.675µs 75.914µs 98.979µs 94.937µs 107.504µs 30.575µs] PauseEnd:[2024-08-24 11:41:57.930373 +0800 CST 2024-08-24 11:41:56.928724 +0800 CST 2024-08-24 11:41:55.926835 +0800 CST 2024-08-24 11:41:54.924951 +0800 CST 2024-08-24 11:41:53.922546 +0800 CST 2024-08-24 11:41:52.920353 +0800 CST 2024-08-24 11:41:51.917256 +0800 CST 2024-08-24 11:41:50.914207 +0800 CST 2024-08-24 11:41:49.912043 +0800 CST 2024-08-24 11:41:48.90515 +0800 CST] 
PauseQuantiles:[]}

1.3.使用 runtime.ReadMemStats

可以使用 runtime 包中的 ReadMemStats 函数来获取GC的统计信息，并手动打印这些信息。
示例

package mainimport ("fmt""runtime""time"
)func main() {// 启动一个goroutine定期打印GC统计信息go func() {var m runtime.MemStatsfor {time.Sleep(10 * time.Second)runtime.ReadMemStats(&m)fmt.Printf("Alloc = %v MiB", m.Alloc/1024/1024)fmt.Printf("\tTotalAlloc = %v MiB", m.TotalAlloc/1024/1024)fmt.Printf("\tSys = %v MiB", m.Sys/1024/1024)fmt.Printf("\tNumGC = %v\n", m.NumGC)}}()// 模拟一些内存分配for i := 0; i < 10; i++ {_ = make([]byte, 10<<20) // 10 MBtime.Sleep(1 * time.Second)}
}

output:

Alloc = 0 MiB	TotalAlloc = 100 MiB	Sys = 20 MiB	NumGC = 10

小结

设置环境变量 GODEBUG：通过设置 GODEBUG=gctrace=1 可以启用GC的详细日志。
使用 runtime/debug 包：可以使用 SetGCPercent 和 ReadGCStats 函数来调整GC频率和打印GC统计信息。
使用 runtime 包：可以使用 ReadMemStats 函数来获取和打印GC的统计信息。

通过这些方法，你可以方便地获取和打印GC的日志信息，以便进行性能调优和问题排查。

2.GC日志打印示例

以下是一个完整的示例，展示了如何在运行Go程序时通过设置环境变量来打印垃圾回收（GC）日志。这个示例程序还会模拟一些内存分配，以便触发垃圾回收。

示例代码
首先，创建一个Go程序文件，例如 main.go，并将以下代码粘贴到文件中：

package mainimport ("fmt""runtime""time"
)func main() {// 启动一个goroutine定期打印GC统计信息go func() {var m runtime.MemStatsfor {time.Sleep(10 * time.Second)runtime.ReadMemStats(&m)fmt.Printf("Alloc = %v MiB", m.Alloc/1024/1024)fmt.Printf("\tTotalAlloc = %v MiB", m.TotalAlloc/1024/1024)fmt.Printf("\tSys = %v MiB", m.Sys/1024/1024)fmt.Printf("\tNumGC = %v\n", m.NumGC)}}()// 模拟一些内存分配以触发GCfor i := 0; i < 10; i++ {_ = make([]byte, 10<<20) // 10 MBtime.Sleep(1 * time.Second)}
}

运行示例
在终端中运行以下命令来设置环境变量并运行Go程序：

GODEBUG=gctrace=1 go run main.go

解释

设置环境变量：通过在运行程序时设置 GODEBUG=gctrace=1 环境变量，启用GC的详细日志。
定期打印GC统计信息：程序启动一个goroutine，每10秒钟打印一次GC的统计信息，包括已分配的内存、总分配的内存、系统内存和GC的次数。
模拟内存分配：在主goroutine中，每秒钟分配10MB的内存，共分配10次，以触发垃圾回收。

GC日志示例
运行程序后，会在终端中看到类似以下的GC日志输出：


gc 1 @0.065s 0%: 0.010+2.7+0.003 ms clock, 0.10+0.16/2.9/2.1+0.034 ms cpu, 4->4->0 MB, 5 MB goal, 10 P
gc 2 @0.125s 0%: 0.027+0.47+0.003 ms clock, 0.27+0.097/1.0/0.43+0.033 ms cpu, 4->4->0 MB, 5 MB goal, 10 P
gc 3 @0.180s 0%: 0.031+1.0+0.10 ms clock, 0.31+0.75/0.80/1.0+1.0 ms cpu, 4->4->0 MB, 5 MB goal, 10 P
gc 4 @0.399s 1%: 0.76+2.6+4.3 ms clock, 7.6+2.0/1.8/0+43 ms cpu, 4->4->1 MB, 5 MB goal, 10 P
gc 5 @0.477s 1%: 0.25+2.6+0.004 ms clock, 2.5+0.38/1.0/2.0+0.042 ms cpu, 4->4->1 MB, 5 MB goal, 10 P
gc 6 @0.491s 1%: 0.092+9.8+0.003 ms clock, 0.92+0/10/1.9+0.033 ms cpu, 4->4->0 MB, 5 MB goal, 10 P
gc 7 @0.518s 1%: 0.093+0.62+0.004 ms clock, 0.93+0.19/1.0/0.23+0.049 ms cpu, 4->4->0 MB, 5 MB goal, 10 P
gc 8 @0.528s 1%: 0.043+0.98+0.004 ms clock, 0.43+0.13/0.95/0.62+0.047 ms cpu, 4->4->1 MB, 5 MB goal, 10 P
# command-line-arguments
gc 1 @0.018s 1%: 0.008+1.8+0.025 ms clock, 0.083+0.13/2.6/1.9+0.25 ms cpu, 4->4->2 MB, 5 MB goal, 10 P
gc 2 @0.033s 1%: 0.011+1.0+0.046 ms clock, 0.11+0.58/1.7/2.6+0.46 ms cpu, 5->5->4 MB, 6 MB goal, 10 P
# command-line-arguments
gc 1 @0.003s 8%: 0.028+4.2+0.059 ms clock, 0.28+0.16/5.9/2.8+0.59 ms cpu, 4->6->5 MB, 5 MB goal, 10 P
gc 2 @0.024s 4%: 0.007+3.0+0.069 ms clock, 0.076+0.042/3.1/1.9+0.69 ms cpu, 9->9->8 MB, 10 MB goal, 10 P
gc 3 @0.134s 1%: 0.019+1.7+0.065 ms clock, 0.19+0.98/2.3/2.0+0.65 ms cpu, 16->16->9 MB, 17 MB goal, 10 P
gc 9 @1.225s 0%: 0.26+1.0+0.19 ms clock, 2.6+0.40/1.2/1.0+1.9 ms cpu, 4->4->0 MB, 5 MB goal, 10 P
gc 1 @0.001s 6%: 0.036+1.3+0.064 ms clock, 0.36+0/0.77/1.1+0.64 ms cpu, 10->10->10 MB, 11 MB goal, 10 P
gc 2 @1.004s 0%: 0.072+1.2+0.023 ms clock, 0.72+0/1.3/0+0.23 ms cpu, 20->20->0 MB, 21 MB goal, 10 P
gc 3 @2.011s 0%: 0.036+0.12+0.003 ms clock, 0.36+0/0.19/0.031+0.035 ms cpu, 10->10->0 MB, 11 MB goal, 10 P
gc 4 @3.015s 0%: 0.11+0.78+0.010 ms clock, 1.1+0/1.0/0.007+0.10 ms cpu, 10->10->0 MB, 11 MB goal, 10 P
gc 5 @4.020s 0%: 0.13+1.1+0.031 ms clock, 1.3+0/0.38/0+0.31 ms cpu, 10->10->0 MB, 11 MB goal, 10 P
gc 6 @5.022s 0%: 0.10+0.54+0.007 ms clock, 1.0+0/0.65/0+0.079 ms cpu, 10->10->0 MB, 11 MB goal, 10 P
gc 7 @6.024s 0%: 0.13+0.65+0.008 ms clock, 1.3+0/0.75/0+0.081 ms cpu, 10->10->0 MB, 11 MB goal, 10 P
gc 8 @7.027s 0%: 0.094+0.73+0.008 ms clock, 0.94+0/0.83/0+0.082 ms cpu, 10->10->0 MB, 11 MB goal, 10 P
gc 9 @8.029s 0%: 0.14+0.68+0.008 ms clock, 1.4+0/0.84/0+0.081 ms cpu, 10->10->0 MB, 11 MB goal, 10 P
gc 10 @9.031s 0%: 0.076+0.43+0.008 ms clock, 0.76+0/0.59/0+0.084 ms cpu, 10->10->0 MB, 11 MB goal, 10 P
Alloc = 0 MiB	TotalAlloc = 100 MiB	Sys = 32 MiB	NumGC = 10

这些GC日志是Go运行时在垃圾回收过程中生成的详细信息。每一行日志记录了一个GC周期的相关信息。

以下是对这些日志的详细解释：
每一行GC日志的格式如下：

gc N @T S%: M1+M2+M3 ms clock, C1+C2/C3/C4+C5 ms cpu, A->B->C MB, D MB goal, P P

字段解释

gc N：表示这是第N次垃圾回收。
@T：表示垃圾回收发生的时间点，单位是秒（s），从程序启动开始计算。
S%：表示垃圾回收器在总CPU时间中所占的百分比。
M1+M2+M3 ms clock：表示垃圾回收的三个阶段（标记、清理、其他）所花费的总时间，单位是毫秒（ms）。
- C1+C2/C3/C4+C5 ms cpu：表示垃圾回收的各个阶段在CPU上所花费的时间，单位是毫秒（ms）。
- C1：STW（Stop-The-World）标记开始时间。
- C2：并发标记时间。
- C3：并发清理时间。
- C4：并发清理结束时间。
- C5：STW标记结束时间。
A->B->C MB：表示垃圾回收前、垃圾回收后和垃圾回收过程中分配的内存量，单位是MB。
D MB goal：表示垃圾回收的目标内存量，单位是MB。
P P：表示参与垃圾回收的处理器数量。

示例解释
以下是对示例日志的详细解释：

gc 1 @0.065s 0%: 0.010+2.7+0.003 ms clock, 0.10+0.16/2.9/2.1+0.034 ms cpu, 4->4->0 MB, 5 MB goal, 10 P
* gc 1：这是第1次垃圾回收。
* @0.065s：垃圾回收发生在程序启动后的0.065秒。
* **0%**：垃圾回收器在总CPU时间中所占的百分比为0%。
* 0.010+2.7+0.003 ms clock：垃圾回收的三个阶段（标记、清理、其他）所花费的总时间分别是0.010ms、2.7ms和0.003ms。
* 0.10+0.16/2.9/2.1+0.034 ms cpu：垃圾回收的各个阶段在CPU上所花费的时间分别是0.10ms、0.16ms、2.9ms、2.1ms和0.034ms。
* 4->4->0 MB：垃圾回收前、垃圾回收后和垃圾回收过程中分配的内存量分别是4MB、4MB和0MB。
* 5 MB goal：垃圾回收的目标内存量是5MB。
* 10 P：参与垃圾回收的处理器数量是10个。