两个golang goroutine向同一个channel发送消息导致耗时增加10倍？

Question

为什么两个 Goroutine 之间的通道发送和接收数据的时间有如此显着的差异？

golang版本1.18 这是我的代码

package main

import (
    "log"
    "time"
)

type Message struct {
    msgID     int
    timeStamp int64
    timeTime  time.Time
    msgType   int
}

func main() {

    const buffer = 1000

    msgChan := make(chan *Message, buffer)
    timeSumType1 := time.Time{}
    timeSumType2 := time.Time{}

    go func() {

        for i := 1; i <= 100; i++ {
            time.Sleep(time.Millisecond)
            timeT1 := time.Now()
            msgChan <- &Message{msgID: i, msgType: 1}
            timeDiff := time.Now().Sub(timeT1)
            log.Println("type 1, id :", i, " <- timeDelta:", timeDiff)
            timeSumType1 = timeSumType1.Add(timeDiff)

        }

    }()

    go func() {

        for i := 1; i <= 100; i++ {
            time.Sleep(100 * time.Millisecond)
            timeT1 := time.Now()
            msgChan <- &Message{msgID: i, msgType: 2}
            timeDiff := time.Now().Sub(timeT1)
            log.Println("type 2, id :", i, " <- timeDelta:", timeDiff)
            timeSumType2 = timeSumType2.Add(timeDiff)
        }

    }()

    time.Sleep(time.Second * 20)

    log.Println("type 1, timeSum:", timeSumType1)
    log.Println("type 2, timeSum:", timeSumType2)
}

第二个goroutine睡眠100ms，第一个goroutine睡眠1ms，

第一个 goroutine 处理消息类型：1 第二个 goroutine 处理消息类型：2

这是日志：

两个goroutine发送通道时间成本日志

两个goroutine总花费时间

我认为两个 goroutine 应该与发送通道花费几乎相同的时间； 但是为什么第二个 Goroutine 的发送操作时间比第一个 Goroutine 长几倍呢？

造成这种差异的内部因素是什么？

Answer 1

我可以提供一些诊断帮助，尽管我不知道原因。首先，去掉不需要的部分并添加描边：

package main

import (
    "context"
    "log"
    "os"
    "runtime"
    "runtime/trace"
    "time"
)

type Message struct {
    msgID int
}

func main() {
    const buffer = 100

    msgChan1 := make(chan Message, buffer)
    msgChan2 := make(chan Message, buffer)
    var timeSumType1 time.Duration
    var timeSumType2 time.Duration

    t, err := os.Create("trace.out")
    if err != nil {
        log.Fatalln(err)
    }

    ctx := context.Background()

    err = trace.Start(t)
    if err != nil {
        log.Fatalln(err)
    }

    runtime.SetBlockProfileRate(0)

    for i := 0; i < buffer; i++ {
        time.Sleep(time.Millisecond)
        timeT1 := time.Now()
        trace.WithRegion(ctx, "1ms", func() {
            msgChan1 <- Message{msgID: i}
        })
        timeSumType1 += time.Since(timeT1)
    }

    for i := 0; i < buffer; i++ {
        time.Sleep(100 * time.Millisecond)
        timeT1 := time.Now()
        trace.WithRegion(ctx, "100ms", func() {
            msgChan2 <- Message{msgID: i}
        })
        timeSumType2 += time.Since(timeT1)
    }

    trace.Stop()
    t.Close()

    log.Println("type 1, timeSum:", timeSumType1)
    log.Println("type 2, timeSum:", timeSumType2)
}

go run

这个：

2024/08/14 14:16:43 type 1, timeSum: 150.5µs
2024/08/14 14:16:43 type 2, timeSum: 1.007373ms

然后执行

go tool trace trace.out

并单击“用户定义区域”：