为什么Go GC在这个程序中有一些长时间的停顿STW(几毫秒)?

问题描述 投票:0回答:1

在我们的一项服务中,发现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 跟踪调试

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

go trace

STW 暂停应在微秒范围内。 而且 gc 只清理了几 MB 的内存。我不知道为什么它会暂停几毫秒。

go garbage-collection
1个回答
0
投票

Go 中 GC 长时间暂停的主要原因之一是例程在 GC 要求时没有停止。 (形象地说)

在上面的代码中,

write
函数一直在旋转。它不会停止,甚至不会休息。 GC 将等待例程暂停并最终强制其休息一下。这种“等待”可能会导致 GC 暂停持续更长时间。


也就是说,我在这台机器上运行了你的程序

go version go1.21.3 darwin/arm64
,在整个 GC 运行中获得几毫秒左右的 GC 暂停的唯一方法是将 GOMAXPROCS 设置为 1 或 2。不设置 GOMAXPROCS 我们正在谈论 ~250 微秒整个运行过程。

是否是Mac正忙于其他事情或因过热而节流?

© www.soinside.com 2019 - 2024. All rights reserved.