【发布时间】：2018-09-12 00:50:08
【问题描述】：
我在使用 Go 调度程序时遇到了一些神秘的行为，我很好奇发生了什么。要点是 runtime.Gosched() 在 Linux 中不能按预期工作，除非它前面有一个 log.Printf() 调用，但它在 OS X 上的两种情况下都按预期工作。这是重现该行为的最小设置：
主 goroutine 休眠 1000 个 1ms 周期，每次休眠后通过通道将虚拟消息推送到另一个 goroutine。第二个 goroutine 监听新消息，每次收到一条消息时，它都会做 10 毫秒的工作。因此，如果没有任何runtime.Gosched() 调用，程序将需要 10 秒才能运行。
当我在第二个 goroutine 中添加定期 runtime.Gosched() 调用时，正如预期的那样，我的 Mac 上的程序运行时间缩短到 1 秒。但是，当我尝试在 Ubuntu 上运行相同的程序时，仍然需要 10 秒。我确保在这两种情况下都设置了runtime.GOMAXPROCS(1)。
真正奇怪的地方在于：如果我只是在 runtime.Gosched() 调用之前添加一个日志语句，那么程序会突然在 Ubuntu 上运行预期的 1 秒。
package main
import (
"time"
"log"
"runtime"
)
func doWork(c chan int) {
for {
<-c
// This outer loop will take ~10ms.
for j := 0; j < 100 ; j++ {
// The following block of CPU work takes ~100 microseconds
for i := 0; i < 300000; i++ {
_ = i * 17
}
// Somehow this print statement saves the day in Ubuntu
log.Printf("donkey")
runtime.Gosched()
}
}
}
func main() {
runtime.GOMAXPROCS(1)
c := make(chan int, 1000)
go doWork(c)
start := time.Now().UnixNano()
for i := 0; i < 1000; i++ {
time.Sleep(1 * time.Millisecond)
// Queue up 10ms of work in the other goroutine, which will backlog
// this goroutine without runtime.Gosched() calls.
c <- 0
}
// Whole program should take about 1 second to run if the Gosched() calls
// work, otherwise 10 seconds.
log.Printf("Finished in %f seconds.", float64(time.Now().UnixNano() - start) / 1e9)
}
附加细节：我正在运行 go1.10 darwin/amd64，并使用以下命令编译 linux 二进制文件
env GOOS=linux GOARCH=amd64 go build ...
我尝试了一些简单的变体：
- 只进行 log.Printf() 调用，没有 Gosched()
- 对 Gosched() 进行两次调用
- 保留 Gosched() 调用，但将 log.Printf() 调用替换为虚拟函数调用
所有这些都比调用 log.Printf() 然后 Gosched() 慢约 10 倍。
任何见解将不胜感激！这个例子当然是非常人为的，但是在编写 websocket 广播服务器时出现了问题，导致性能显着下降。
编辑：我去掉了示例中无关紧要的部分，以使事情更加透明。我发现没有打印语句，runtime.Gosched() 调用仍在运行，只是它们似乎延迟了固定的 5ms，导致在下面的示例中，总运行时间几乎正好是 5 秒，当程序应该立即完成（并且在我的 Mac 上或在带有 print 语句的 Ubuntu 上完成）。
package main
import (
"log"
"runtime"
"time"
)
func doWork() {
for {
// This print call makes the code run 20x faster
log.Printf("donkey")
// Without this line, the program never terminates (as expected). With this line
// and the print call above it, the program takes <300ms as expected, dominated by
// the sleep calls in the main goroutine. But without the print statement, it
// takes almost exactly 5 seconds.
runtime.Gosched()
}
}
func main() {
runtime.GOMAXPROCS(1)
go doWork()
start := time.Now().UnixNano()
for i := 0; i < 1000; i++ {
time.Sleep(10 * time.Microsecond)
runtime.Gosched()
}
log.Printf("Finished in %f seconds.", float64(time.Now().UnixNano() - start) / 1e9)
}
【问题讨论】：
-
您遇到的情况在现实世界中不太可能发生 - 即奇怪的事情正在发生，因为这是一个试图模拟工作的奇怪的人为示例。
-
实际上，这个例子是人为的，因为我想隔离问题，但是在我编写 websocket 广播服务器时出现了这种行为，并且由于这个问题，容量比预期的少了约 10 倍。粗略的类比是主 goroutine 生成消息并推送到广播 goroutine 上，工作就是将消息发送到每个监听客户端。
-
这很奇怪，考虑到任何非内联函数调用都会导致当前例程屈服于调度程序。这是什么版本的 Go？
-
这似乎更适合 Go 问题跟踪器或邮件列表。特定实现中的怪癖或错误不是这里真正的主题。
-
@rampatowl：Gosched 应该让给调度程序。其他事情正在发生。
标签： linux go concurrency scheduling