运行时:某些运行时会抛出异常,默认情况下打印所有goroutine的堆栈转储,

ogq8wdun  于 6个月前  发布在  Go
关注(0)|答案(8)|浏览(45)

我将在这里使用 go version devel go1.17-d19a53338f Wed Jun 30 02:00:49 2021 +0000 linux/amd64 作为示例,但这也适用于 1.16.5。
https://golang.org/pkg/runtime/ 中,强调我的部分:
GOTRACEBACK 变量控制了当 Go 程序因未恢复的恐慌或意外运行时条件而失败时生成的输出量。默认情况下,失败会为当前 goroutine 打印堆栈跟踪,省略运行时系统内部的函数,然后以退出代码 2 退出。
所以看起来,默认情况下,panic 应该只打印发生 panic 的 goroutine 的堆栈跟踪,其他什么也不用。
然而,在某些情况下,这似乎并不正确:https://play.golang.org/p/zWw2TUS4YzZ

$ go run -trimpath f.go
fatal error: concurrent map writes

goroutine 7 [running]:
runtime.throw({0x467980, 0x0})
	runtime/panic.go:1198 +0x71 fp=0xc00003cf78 sp=0xc00003cf48 pc=0x42cb91
runtime.mapassign_fast64(0x45f100, 0xc000072060, 0x2)
	runtime/map_fast64.go:176 +0x2b4 fp=0xc00003cfb0 sp=0xc00003cf78 pc=0x40dcb4
main.main.func3()
	./f.go:12 +0x2e fp=0xc00003cfe0 sp=0xc00003cfb0 pc=0x45814e
runtime.goexit()
	runtime/asm_amd64.s:1581 +0x1 fp=0xc00003cfe8 sp=0xc00003cfe0 pc=0x453dc1
created by main.main
	./f.go:10 +0x85

goroutine 1 [sleep]:
time.Sleep(0x3b9aca00)
	runtime/time.go:193 +0x12e
main.main()
	./f.go:21 +0xd1

goroutine 5 [sleep]:
time.Sleep(0xdf8475800)
	runtime/time.go:193 +0x12e
main.main.func1()
	./f.go:6 +0x25
created by main.main
	./f.go:6 +0x26

goroutine 6 [sleep]:
time.Sleep(0xdf8475800)
	runtime/time.go:193 +0x12e
main.main.func2()
	./f.go:7 +0x25
created by main.main
	./f.go:7 +0x34

goroutine 8 [runnable]:
main.main.func4()
	./f.go:17 +0x2e
created by main.main
	./f.go:15 +0xc7
exit status 2

根据文档,我本应该只看到一个 goroutine 堆栈转储 - 通过 runtime.mapassign_fast64 触发的 "运行" goroutine,但我得到了所有的堆栈转储。
这似乎是代码故意这样设计的:
go/src/runtime/panic.go
d19a533 中的第 1385 行到第 1399 行
| | ifgp!=gp.m.curg { |
| | all=true |
| | } |
| | ifgp!=gp.m.g0 { |
| | print("
") |
| | goroutineheader(gp) |
| | traceback(pc, sp, 0, gp) |
| | } elseiflevel>=2||g.m.throwing>0 { |
| | print("
runtime stack:
") |
| | traceback(pc, sp, 0, gp) |
| | } |
| | if!didothers&&all { |
| | didothers=true |
| | tracebackothers(gp) |
| | } |
这有两个问题:
A:令人困惑。当我查看 Go 进程崩溃输出和运行时文档时,这让我感到困惑。
B:它可能导致大量的 panic 输出,具体取决于运行哪种 panic。在工作中,有人非常惊讶地发现一个 panic 导出了约 50MiB 的 goroutine 堆栈,而大多数其他 panic 只导出一个 goroutine 堆栈。实际上导致了基础设施问题,因为我们的日志摄取似乎不太喜欢这种突然的输出大量,我们从未找到过原因,因为大多数 panics 不这样做。
我对这个问题有三个可能的解决方案:
1.代码按预期工作。我们应该更新文档以澄清默认情况下会在某些情况下打印所有 goroutine 堆栈跟踪的细微差别,以及这些情况是什么。
1.我们应该修改实现以匹配文档。并发Map写入应导致仅打印一个堆栈跟踪的 panic,即上面的 "运行" goroutine。
1.介于两者之间,例如 "打印涉及要查询的Map的所有 goroutines 的堆栈跟踪"。我可以想象当前行为存在调试目的:如果您遇到并发Map写入,您可能想知道那些两个或更多的 goroutine 在做什么,而不仅仅是其中一个。然而,您可能不需要 所有 goroutines;只需要涉及竞争的那些。

bqucvtff

bqucvtff1#

为了完整性,这里是一个按照文档记录工作的“默认情况下仅打印当前goroutine”的示例:

$ cat f.go
package main

import "time"

func main() {
	go func() { time.Sleep(time.Minute) }()
	go func() { time.Sleep(time.Minute) }()

	go func() {
		time.Sleep(time.Second)
		panic("foo")
	}()

	time.Sleep(time.Minute)
}
$ go run -trimpath f.go
panic: foo

goroutine 7 [running]:
main.main.func3()
	./f.go:11 +0x31
created by main.main
	./f.go:9 +0x45
exit status 2
zed5wv10

zed5wv102#

我认为这里的区分是 panicthrow 之间的区别。一个 panic 只打印相关的问题goroutine。一个 throw 打印所有的它们。
通常情况下,throw 只在运行时发现自己的错误时使用,在这种情况下,打印所有内容是可以的,实际上是有帮助的,因为它对于关于运行时的错误报告可能是有用的。
当运行时发现用户程序中的错误,例如并发Map写入检测器,我们也使用 throw。也许我们不应该这样做,或者也许我们应该使用只打印当前goroutine的变体。

js4nwp54

js4nwp543#

我明白了;我没有理解恐慌和抛出之间的区别。请注意,文档只是提到“未恢复的恐慌或意外的运行时条件”,我认为这应该涵盖两者。因此,如果我们想保持这种区别,也许在godoc中也需要澄清这一点。
无论如何,我同意并发Map写入不应该导致所有goroutines被终止——它们并不是运行时包本身的错误。我认为由于用户代码中的错误而导致的任何此类运行时故障都应该导致类似于当前恐慌的情况,而不是当前抛出的情况。

pdtvr36n

pdtvr36n4#

在过去,这是由于"用户错误"(解锁未锁定的互斥锁、并发Map写入等)和"运行时错误"(大多数抛出异常)在分析崩溃时出现的。也许我们应该为这些致命的用户错误设置一个 userThrow ,这也可以更接近正确的 GOTRACEBACK 设置。

8wtpewkr

8wtpewkr5#

我同意我们应该区分运行时内部致命错误和用户引起的致命错误,但“并发Map写入”实际上是不是少数情况下有用的看到其他goroutines,这样你就有机会捕获正在写入Map的其他goroutine?

wlsrxk51

wlsrxk516#

我认为实际上不太可能抓住特定的写操作本身。当运行时停止该goroutine时,它已经完成了写操作并继续执行。(写-写冲突可能会捕获两个违规者,但对于读-写冲突,我们只捕获读侧。)
然而,在写操作之后不久就有可能捕获另一个goroutine,这仍然可能是有用的(例如,仍在同一个父函数中,或者它在一个循环中进行大量的写操作等)。

zyfwsgd6

zyfwsgd67#

"并发Map写入"实际上是不是少数情况下,查看其他goroutine是有用的,这样你就有机会捕获正在写入Map的其他goroutine?

也许吧,但请注意,转储所有的goroutine是完全不同的问题。请参阅我上面提到的生产环境中遇到的问题:到那时为止我们看到的所有的恐慌都只有1KB,因为它们只包含一个堆栈跟踪。然后有一天我们遇到了一个并发的Map写入,突然间几十兆字节的转储导致了日志系统卡住了。

你可以说这是我们应该解决的问题,但令人惊讶的是,一小部分用户引起的恐慌竟然可以意外地转储所有goroutine,这真是令人惊讶!

我不反对如果这个Map恐慌打印出所有参与数据竞争的goroutine的堆栈跟踪,我认为这几乎永远不会超过一两个。如果不可能的话,那么我认为它应该只使用正在运行的goroutine。

3pmvbmvn

3pmvbmvn8#

(用户体验报告)
昨天在工作中遇到了这个问题。由于concurrent map writes,我们的生产服务崩溃了。我们的调试速度稍有减慢,因为我们的进程为数十万个goroutine打印了堆栈跟踪。由于长度原因,我们的日志查看器"kubectl logs"只显示堆栈跟踪的尾部,这使得很难理解原因,直到我们弄清楚如何获取所有日志。

相关问题