Golang time.Ticker 阻塞一段时间后触发两次

Golang time.Ticker triggers twice after blocking a while

我正在使用 time.Ticker 和一些阻塞代码,发现一个奇怪的行为:

func main() {
    ticker := time.NewTicker(1 * time.Second)

    i := 0
    for {
        select {
        case <-ticker.C:
            log.Println(i)
            if i == 0 {
                time.Sleep(5 * time.Second) // simulate the blocking
            }
            i++
        }
    }
}

示例输出:

2022/02/20 10:49:45 0
2022/02/20 10:49:50 1 <- shows at same time
2022/02/20 10:49:50 2 <- shows at same time
2022/02/20 10:49:51 3
2022/02/20 10:49:52 4
2022/02/20 10:49:53 5
...

“1”和“2”总是同时显示,这是为什么?

time.Ticker中,有一个chan Time。在NewTicker(d Duration) *Ticker函数中,它创建了tickers Time channel作为一个容量为1的buffered channel。在函数中,如下所述。

// Give the channel a 1-element time buffer.
// If the client falls behind while reading, we drop ticks
// on the floor until the client catches up.

在您的情况下,时间每秒滴答作响并写入频道。休眠时,自动收报机向通道写入一次,循环继续后立即由 select 案例接收并打印。在另外 4 秒内,通道被阻塞并且滴答声被丢弃。立即循环继续它被解锁并接受更多的通道报价。

通过通道打印时间,您可以轻松了解行为。更新代码如下。

func main() {
    ticker := time.NewTicker(1 * time.Second)

    i := 0
    for {
        select {
        case t := <-ticker.C:
            log.Println(i, t)
            if i == 0 {
                time.Sleep(5 * time.Second) // simulate the blocking
            }
            i++
        }
    }
}

输出:

2022/02/20 08:47:58 0 2022-02-20 08:47:58.773375 +0530 +0530 m=+1.004241004
2022/02/20 08:48:03 1 2022-02-20 08:47:59.772787 +0530 +0530 m=+2.003666993
2022/02/20 08:48:03 2 2022-02-20 08:48:03.774272 +0530 +0530 m=+6.005207433 // printing time is same, but channel's received time has 4 sec difference.
2022/02/20 08:48:04 3 2022-02-20 08:48:04.774203 +0530 +0530 m=+7.005151715

运行 在 Playground.

自动收报机创建容量为 1 的 buffered channel。当频道已满时,自动收报机会降低时间值。

这是问题中跟踪的时间线。同一时间列出的事件按列出的顺序依次发生。

1s - ticker sends value
1s - main goroutine receives first value
1s - main goroutine starts sleep for 5s
2s - ticker sends value (channel has capacity 1).
3s - ticker fails to send value because channel is full
4s - ticker fails to send value because channel is full
5s - ticker fails to send value because channel is full
6s - main goroutine exits sleep and receives buffered value
6s - ticker sends value
6s - main goroutine receives buffered value

自动收报机和主 goroutine 争先恐后地跑到 6 秒标记,因为睡眠时间是自动收报机周期的倍数。在您的跟踪中,主要的 goroutine 赢得了比赛。在我的机器上,自动收报机赢得了比赛,我得到了你期望的时间。这是它在我的机器上的样子。

...
5s - ticker fails to send value because channel is full
6s - ticker fails to send value because channel is full
6s - main goroutine receives buffered value
7s - ticker sends value
7s - main goroutine receives value

自动收报机赢得了操场上 6 秒标记的比赛。 Run it here。 当睡眠时间减少 1µs 时,主 goroutine 赢得比赛。 Run it here.

当睡眠持续时间不是行情周期的倍数时,这很容易看出。这是睡眠持续时间为 2.5 秒时发生的情况:

1s - ticker sends value
1s - main goroutine receives first value
1s - main goroutine starts sleep for 2.5s
2s - ticker sends value
3s - ticker fails to send value because channel is full
3.5s - main goroutine exits sleep and receives buffered value
4s - ticker sends value
4s - main goroutine receives value

Run the last example on the playground.