在我们的一项服务中,发现gc偶尔会出现一些很长的STW(长达100ms),我编写了一个随机程序,发现它确实这样做了以及为什么。这个程序有时几千次gc只出现一次几毫米的停顿。 这个程序在我的机器上可以运行长达 100ms STW。
go version go1.21.3 darwin/amd64
package main
import (
"net"
"os"
"os/signal"
"runtime/trace"
)
func write() {
conn, _ := net.DialUDP("udp", nil, &net.UDPAddr{Port: 9104})
buf := make([]byte, 512)
for {
conn.Write(buf)
}
}
var rChan = make(chan []byte, 1000)
func read() {
for x := range rChan {
_ = x
}
}
func main() {
f, _ := os.Create("trace.out")
defer f.Close()
trace.Start(f)
defer trace.Stop()
quit := make(chan os.Signal, 1)
signal.Notify(quit, os.Interrupt)
ln, _ := net.ListenUDP("udp", &net.UDPAddr{Port: 9104})
go write()
go read()
go func() {
buf := make([]byte, 512)
for {
ln.ReadFrom(buf)
rChan <- buf
}
}()
<-quit
}
gc 114 @24.897s 0%: 0.058+0.24+0.030 ms clock, 0.94+0.10/0.43/0+0.49 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
gc 115 @25.118s 0%: 0.043+0.41+0.12 ms clock, 0.69+0.092/0.23/0+2.0 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
gc 116 @25.356s 0%: 0.060+0.44+0.015 ms clock, 0.96+0.067/0.23/0+0.25 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
gc 117 @25.576s 0%: 0.054+0.27+0.033 ms clock, 0.86+0.062/0.28/0+0.53 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
gc 118 @25.797s 0%: 0.062+0.18+0.016 ms clock, 1.0+0.088/0.26/0+0.26 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
gc 119 @26.020s 0%: 4.5+8.3+5.7 ms clock, 72+0.096/0.16/0+92 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
gc 120 @26.269s 0%: 0.060+0.26+0.018 ms clock, 0.96+0.051/0.30/0+0.30 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
gc 121 @26.485s 0%: 0.059+0.26+0.053 ms clock, 0.95+0.088/0.22/0.002+0.86 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
gc 122 @26.721s 0%: 0.060+0.26+0.039 ms clock, 0.96+0.042/0.23/0.001+0.62 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
gc 123 @26.958s 0%: 0.054+0.19+0.029 ms clock, 0.87+0.062/0.15/0+0.47 ms cpu, 3->3->1 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P
STW 暂停应在微秒范围内。 而且 gc 只清理了几 MB 的内存。我不知道为什么它会暂停几毫秒。