为何该Go程序中GC会出现较长时间的STW停顿（数毫秒级）？

我们在某服务中发现GC偶尔会出现长达100ms的STW停顿，为此编写测试程序证实该现象确实存在。该程序有时执行数千次GC才会出现一次数毫秒停顿，本机运行时甚至可达100ms。我们预期STW停顿应处于微秒级，且GC仅清理少量内存，疑惑为何会出现毫秒级停顿。

go version go1.21.3 darwin/amd64

package main

import (
    "log"
    "net"
    "os"
    "runtime/debug"
    "runtime/trace"
    "time"
)

var quit = make(chan struct{})

func printGcStats() {
    s := debug.GCStats{}
    s.PauseQuantiles = make([]time.Duration, 101)

    lastGc := time.Date(0, 0, 0, 0, 0, 0, 0, time.Local)
    maxPause := time.Duration(0)

    for range time.Tick(time.Second) {
        debug.ReadGCStats(&s)
        if s.LastGC.Equal(lastGc) || len(s.Pause) == 0 {
            continue
        }
        for i, t := range s.PauseEnd {
            if t.Compare(lastGc) > 0 {
                if s.Pause[i] > maxPause {
                    maxPause = s.Pause[i]
                }
                if s.Pause[i] > time.Millisecond*50 {
                    log.Printf("GC %d  maxPause: %v", s.NumGC, maxPause)
                    quit <- struct{}{}
                    return
                }
            } else {
                break
            }
        }
        log.Printf("GC %d  maxPause: %v", s.NumGC, maxPause)
        lastGc = s.LastGC
    }
}

func init() {
    go printGcStats()
}

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()

    ln, _ := net.ListenUDP("udp", &net.UDPAddr{Port: 9104})
    go write()
    go read()
    go func() {
        for {
            buf := make([]byte, 512)
            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

内容的提问来源于stack exchange，提问作者Vivaldi