os: TestPipeIOCloseRace timeout on Windows blocked in syscall.CancelIoEx

[gopherbot]

#!watchflakes
post <- goos == "windows" && pkg == "os" && ((log ~ `panic: test timed out` && log ~ `^\s*syscall\.CancelIoEx`) || status == "ABORT" )

Issue created automatically to collect these failures.

Example (log):

panic: test timed out after 3m0s
running tests:
	TestPipeIOCloseRace (2m59s)

goroutine 879 gp=0x4000174340 m=10 mp=0x4000180708 [running]:
panic({0x7ff7b437a3a0?, 0x4000400040?})
	C:/workdir/go/src/runtime/panic.go:779 +0x140 fp=0x400017bf00 sp=0x400017be50 pc=0x7ff7b4229d10
testing.(*M).startAlarm.func1()
	C:/workdir/go/src/testing/testing.go:2366 +0x30c fp=0x400017bfd0 sp=0x400017bf00 pc=0x7ff7b42f001c
runtime.goexit({})
...

goroutine 273 gp=0x4000443860 m=nil [GC worker (idle), 2 minutes]:
runtime.gopark(0x8501acdde81b4?, 0x0?, 0x0?, 0x0?, 0x0?)
	C:/workdir/go/src/runtime/proc.go:402 +0xc8 fp=0x400034bf30 sp=0x400034bf10 pc=0x7ff7b422d398
runtime.gcBgMarkWorker()
	C:/workdir/go/src/runtime/mgc.go:1310 +0xd8 fp=0x400034bfd0 sp=0x400034bf30 pc=0x7ff7b420c1c8
runtime.goexit({})
	C:/workdir/go/src/runtime/asm_arm64.s:1222 +0x4 fp=0x400034bfd0 sp=0x400034bfd0 pc=0x7ff7b4263734
created by runtime.gcBgMarkStartWorkers in goroutine 308
	C:/workdir/go/src/runtime/mgc.go:1234 +0x28

— watchflakes

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "os" && test == ""

2023-11-30 18:35 windows-arm64-11 go@bda1ef13 os (log)

panic: test timed out after 3m0s
running tests:
	TestPipeIOCloseRace (2m59s)

goroutine 879 gp=0x4000174340 m=10 mp=0x4000180708 [running]:
panic({0x7ff7b437a3a0?, 0x4000400040?})
	C:/workdir/go/src/runtime/panic.go:779 +0x140 fp=0x400017bf00 sp=0x400017be50 pc=0x7ff7b4229d10
testing.(*M).startAlarm.func1()
	C:/workdir/go/src/testing/testing.go:2366 +0x30c fp=0x400017bfd0 sp=0x400017bf00 pc=0x7ff7b42f001c
runtime.goexit({})
...

goroutine 273 gp=0x4000443860 m=nil [GC worker (idle), 2 minutes]:
runtime.gopark(0x8501acdde81b4?, 0x0?, 0x0?, 0x0?, 0x0?)
	C:/workdir/go/src/runtime/proc.go:402 +0xc8 fp=0x400034bf30 sp=0x400034bf10 pc=0x7ff7b422d398
runtime.gcBgMarkWorker()
	C:/workdir/go/src/runtime/mgc.go:1310 +0xd8 fp=0x400034bfd0 sp=0x400034bf30 pc=0x7ff7b420c1c8
runtime.goexit({})
	C:/workdir/go/src/runtime/asm_arm64.s:1222 +0x4 fp=0x400034bfd0 sp=0x400034bfd0 pc=0x7ff7b4263734
created by runtime.gcBgMarkStartWorkers in goroutine 308
	C:/workdir/go/src/runtime/mgc.go:1234 +0x28

— watchflakes

[bcmills]

@golang/windows, any idea why CancelIoEx would block for over 2 minutes?

[alexbrainman]

@golang/windows, any idea why CancelIoEx would block for over 2 minutes?

No idea. According to https://learn.microsoft.com/en-us/windows/win32/fileio/cancelioex-func

The CancelIoEx function does not wait for all canceled operations to complete.

Alex

[gopherbot]

Found new dashboard test flakes for:

#!watchflakes
post <- goos == "windows" && pkg == "os" && ((log ~ `panic: test timed out` && log ~ `^\s*syscall\.CancelIoEx`) || status == "ABORT" )

2024-03-07 05:26 gotip-windows-386 go@a0624701 os.TestPipeIOCloseRace [ABORT] (log)

=== RUN   TestPipeIOCloseRace
=== PAUSE TestPipeIOCloseRace
=== CONT  TestPipeIOCloseRace

— watchflakes