go x/tools/cmd/fiximports:自2021-11-12起，plan9-arm上频繁出现TestDryRun和TestFixImports超时问题,

8ehkhllq 于 4个月前发布在 Go

关注(0)|答案(8)|浏览(41)

#!watchflakes
post <- builder ~ `^plan9` && pkg == "golang.org/x/tools/cmd/fiximports" && (test == "TestDryRun" || test == "TestFixImports")

来源：https://github.com/golang/go/issues/50775

8条答案

按热度按时间

brc7rcf01#

https://golang.org/cl/380495提到了这个问题：cmd/fiximports: skip TestDryRun on plan9-arm

赞(0）回复(0）举报 4个月前

1yjd4xko2#

这个测试在我Linux工作站上运行大约需要500毫秒，而在plan9-arm上运行时，它在10分钟后超时。我一直在当前计划9-arm构建器(带有1GB RAM的Pi 3B+)上循环运行TestDryRun。每次大约需要21秒。整个fiximports.test运行大约需要145秒。因此，导致超时的原因不太可重复。需要调查。

赞(0）回复(0）举报 4个月前

jmp7cifd3#

我无法单独通过运行fiximports测试来复现这个问题 - 它从不会超过25秒。问题肯定是与其他并行运行的测试之间的交互。
我刚刚尝试运行go test x/tools/cmd/...,发现在那个上下文中，fiximports.test花了425秒。大部分时间它都是与guru.test(487420K虚拟内存大小)并行运行的，以及stringer.test(一个更正常的276804K虚拟内存)。物理内存紧张但没有交换。guru.test的完成消息从未出现，过了一会儿，很明显所有子命令都已终止，但go test命令陷入了死锁。我向它发送了一个kill信号以获取堆栈跟踪，如下所示：

goroutine 0 [idle]:
runtime.plan9_semacquire()
	/sys/lib/go1.17/src/runtime/sys_plan9_arm.s:120 +0x8
runtime.semasleep(0xffffffffffffffff)
	/sys/lib/go1.17/src/runtime/os_plan9.go:484 +0x68
runtime.notesleep(0x112ac0b4)
	/sys/lib/go1.17/src/runtime/lock_sema.go:182 +0x88
runtime.mPark()
	/sys/lib/go1.17/src/runtime/proc.go:1441 +0x20
runtime.stopm()
	/sys/lib/go1.17/src/runtime/proc.go:2408 +0x78
runtime.findrunnable()
	/sys/lib/go1.17/src/runtime/proc.go:2984 +0x9e4
runtime.schedule()
	/sys/lib/go1.17/src/runtime/proc.go:3367 +0x2ac
runtime.park_m(0x10c00780)
	/sys/lib/go1.17/src/runtime/proc.go:3516 +0x18c
runtime.mcall()
	/sys/lib/go1.17/src/runtime/asm_arm.s:266 +0x48

goroutine 1 [semacquire, 15 minutes]:
sync.runtime_Semacquire(0x111a8f48)
	/sys/lib/go1.17/src/runtime/sema.go:56 +0x34
sync.(*WaitGroup).Wait(0x111a8f40)
	/sys/lib/go1.17/src/sync/waitgroup.go:130 +0x94
cmd/go/internal/work.(*Builder).Do(0x10dacae0, {0x5dd1bc, 0x10c28394}, 0x111a2630)
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:208 +0x3c4
cmd/go/internal/test.runTest({0x5dd1bc, 0x10c28394}, 0x829068, {0x10c20070, 0x1, 0x1})
	/sys/lib/go1.17/src/cmd/go/internal/test/test.go:828 +0x2384
main.invoke(0x829068, {0x10c20068, 0x2, 0x2})
	/sys/lib/go1.17/src/cmd/go/main.go:216 +0x2f0
main.main()
	/sys/lib/go1.17/src/cmd/go/main.go:173 +0x914

goroutine 2894 [select, 7 minutes]:
cmd/go/internal/work.(*Builder).Do.func3(0x110f4a48, 0x111a8f40, 0x10dacae0, 0x111f86d0)
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:189 +0xf4
created by cmd/go/internal/work.(*Builder).Do
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:185 +0x3a4

goroutine 3281 [chan receive, 15 minutes]:
cmd/go/internal/base.processSignals.func1(0x1130ea80)
	/sys/lib/go1.17/src/cmd/go/internal/base/signal.go:21 +0x24
created by cmd/go/internal/base.processSignals
	/sys/lib/go1.17/src/cmd/go/internal/base/signal.go:20 +0x74

goroutine 3264 [syscall, 15 minutes]:
os/signal.signal_recv()
	/sys/lib/go1.17/src/runtime/sigqueue_plan9.go:116 +0x74
os/signal.loop()
	/sys/lib/go1.17/src/os/signal/signal_plan9.go:27 +0x14
created by os/signal.Notify.func1.1
	/sys/lib/go1.17/src/os/signal/signal.go:151 +0x30

goroutine 2892 [runnable]:
syscall.Syscall(0x2a, 0x10ecb080, 0x13a48000, 0x73)
	/sys/lib/go1.17/src/syscall/asm_plan9_arm.s:16 +0x8
syscall.stat({0x10ecb020, 0x21}, {0x13a48000, 0x73, 0x73})
	/sys/lib/go1.17/src/syscall/zsyscall_plan9_arm.go:115 +0xfc
syscall.Stat({0x10ecb020, 0x21}, {0x13a48000, 0x73, 0x73})
	/sys/lib/go1.17/src/syscall/syscall_plan9.go:400 +0x74
os.dirstat({0x4b4ef8, 0x10ded804})
	/sys/lib/go1.17/src/os/stat_plan9.go:62 +0x140
os.statNolog({0x10ecb020, 0x21})
	/sys/lib/go1.17/src/os/stat_plan9.go:95 +0x34
os.lstatNolog(...)
	/sys/lib/go1.17/src/os/stat_plan9.go:104
os.Lstat({0x10ecb020, 0x21})
	/sys/lib/go1.17/src/os/stat.go:22 +0x38
path/filepath.walkSymlinks({0x10c30380, 0x30})
	/sys/lib/go1.17/src/path/filepath/symlink.go:84 +0x168
path/filepath.evalSymlinks(...)
	/sys/lib/go1.17/src/path/filepath/symlink_unix.go:7
path/filepath.EvalSymlinks({0x10c30380, 0x30})
	/sys/lib/go1.17/src/path/filepath/path.go:235 +0x24
cmd/go/internal/search.InDir({0x11096feb, 0x4}, {0x10c30380, 0x30})
	/sys/lib/go1.17/src/cmd/go/internal/search/search.go:587 +0x120
cmd/go/internal/test.computeTestInputsID(0x10c938c0, {0x11a68000, 0xd71589, 0xd7158a})
	/sys/lib/go1.17/src/cmd/go/internal/test/test.go:1519 +0x630
cmd/go/internal/test.(*runCache).saveOutput(0x111c8730, 0x10c938c0)
	/sys/lib/go1.17/src/cmd/go/internal/test/test.go:1642 +0x2f0
cmd/go/internal/test.(*runCache).builderRunTest(0x111c8730, 0x10dacae0, {0x5dd1bc, 0x10c28394}, 0x10c938c0)
	/sys/lib/go1.17/src/cmd/go/internal/test/test.go:1282 +0x1334
cmd/go/internal/work.(*Builder).Do.func2({0x5dd1bc, 0x10c28394}, 0x10c938c0)
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:137 +0x4fc
cmd/go/internal/work.(*Builder).Do.func3(0x110f4a48, 0x111a8f40, 0x10dacae0, 0x111f86d0)
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:199 +0x9c
created by cmd/go/internal/work.(*Builder).Do
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:185 +0x3a4

goroutine 2893 [select, 7 minutes]:
cmd/go/internal/work.(*Builder).Do.func3(0x110f4a48, 0x111a8f40, 0x10dacae0, 0x111f86d0)
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:189 +0xf4
created by cmd/go/internal/work.(*Builder).Do
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:185 +0x3a4

goroutine 2974 [select, 7 minutes]:
cmd/go/internal/work.(*Builder).Do.func3(0x110f4a48, 0x111a8f40, 0x10dacae0, 0x111f86d0)
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:189 +0xf4
created by cmd/go/internal/work.(*Builder).Do
	/sys/lib/go1.17/src/cmd/go/internal/work/exec.go:185 +0x3a4

症状可能是fiximports中的超时，但我认为根本问题是其他地方的死锁。

赞(0）回复(0）举报 4个月前

wxclj1h54#

在上面的测试中，guru.test耗时较长的原因是我没有使用-short标志。我认为go test并没有陷入死锁：它只是忙于尝试缓存测试输入和结果。计算TestInputsID需要非常长的时间，因为它要经过一个testlog.txt,该列表包含357000个文件名，每个文件名在被filepath.EvalSymlinks扩展后都需要一个stat调用(而filepath.EvalSymlinks本身对每个文件名组件都需要一个stat调用)。实际上，testlog.txt中只有5841条唯一的行，因此对列表进行排序并消除重复项将大大提高速度。此外，在Plan 9(还有没有其他没有符号链接的操作系统？)上，将EvalSymlinks实现为对filepath.Clean的简单调用，而不是在每个组件上无意义地调用stat,也会有所帮助。
不幸的是，这并没有更接近解释为什么fiximports.test在构建器上超时。

赞(0）回复(0）举报 4个月前

lskq00tm5#

实际上，testlog.txt文件中只有5841条唯一的记录，因此对列表进行排序并消除重复项可以大大提高速度。
哦，这是一个非常有用的观察结果！
在Plan 9(还有没有其他没有符号链接的操作系统？)上实现EvalSymlinks作为简单地调用filepath.Clean而不是在每个组件上无意义地调用stat也会有所帮助。
据我所知，Go支持的其他操作系统完全不支持符号链接。(Windows从Vista开始就支持它们，而在Windows 10中，它们在build 14972中被标记为已启用。)
如果您想为plan9提交CL,我很乐意在Go 1.19的树开放时审查它。我认为它应该像添加src/path/filepath/symlink_plan9.go一样简单，并更新symlink_unix.go的构建约束：
https://cs.opensource.google/go/go/+/master:src/path/filepath/symlink_unix.go;l=1;drc=f229e7031a6efb2f23241b5da000c3b3203081d6