go: runtime: setevent failed; errno=6, fatal error: runtime.semawakeup

While trying to reproduce #42637 locally and ran into crashes, I was running os tests on Windows with:

go test -run . -count 100000  -failfast

Using e125ccd10ea191101dbc31f0dd39a98f9d3ab929:

AMD Ryzen Threadripper 2950X 16-Core Processor    3.50 GHz
Windows 10 Pro
OS build	19042.746

The tests failed with:

c:\Go.tip\src\os>go test -run . -count 100000  -failfast
runtime: setevent failed; errno=6
fatal error: runtime.semawakeup

runtime stack:
runtime.throw(0xb02470, 0x12)
        C:/Go.tip/src/runtime/panic.go:1112 +0x79
runtime.semawakeup.func1()
        C:/Go.tip/src/runtime/os_windows.go:796 +0x85
runtime.semawakeup(0xc0003d6000)
        C:/Go.tip/src/runtime/os_windows.go:794 +0x51
runtime.notewakeup(0xc0003d6120)
        C:/Go.tip/src/runtime/lock_sema.go:161 +0x65
runtime.startm(0xc000022000, 0x959000)
        C:/Go.tip/src/runtime/proc.go:2318 +0x1d9
runtime.handoffp(0xc000022000)
        C:/Go.tip/src/runtime/proc.go:2338 +0x305
runtime.retake(0x125d81032f0, 0xc8)
        C:/Go.tip/src/runtime/proc.go:5287 +0x17d
runtime.sysmon()
        C:/Go.tip/src/runtime/proc.go:5195 +0x1a5
runtime.mstart1()
        C:/Go.tip/src/runtime/proc.go:1275 +0xda
runtime.mstart()
        C:/Go.tip/src/runtime/proc.go:1240 +0x6d

goroutine 1 [chan receive]:
testing.(*T).Run(0xc0000f3500, 0xaff734, 0xb, 0xb0f9c0, 0x9ab001)
        C:/Go.tip/src/testing/testing.go:1240 +0x2da
testing.runTests.func1(0xc000505680)
        C:/Go.tip/src/testing/testing.go:1512 +0x7f
testing.tRunner(0xc000505680, 0xc0002f9de0)
        C:/Go.tip/src/testing/testing.go:1194 +0xef
testing.runTests(0xc000004078, 0xc2c020, 0x8f, 0x8f, 0xbff87bdac4307fc4, 0x8bb2f1ec11, 0xc2f520, 0xb0056c)
        C:/Go.tip/src/testing/testing.go:1510 +0x310
testing.(*M).Run(0xc0000c2080, 0x0)
        C:/Go.tip/src/testing/testing.go:1418 +0x1f5
main.main()
        _testmain.go:361 +0x145

goroutine 1028 [chan receive]:
testing.(*T).Parallel(0xc0000cd680)
        C:/Go.tip/src/testing/testing.go:1060 +0x119
os_test.TestOpenFileKeepsPermissions(0xc0000cd680)
        C:/Go.tip/src/os/os_test.go:2661 +0x47
testing.tRunner(0xc0000cd680, 0xb0fbc0)
        C:/Go.tip/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go.tip/src/testing/testing.go:1239 +0x2b3

goroutine 1481 [sleep]:
time.Sleep(0x4c4b40)
        C:/Go.tip/src/runtime/time.go:193 +0xe5
os.(*Process).wait(0xc00028d1a0, 0xc000500000, 0x0, 0x0)
        C:/Go.tip/src/os/exec_windows.go:45 +0x41b
os.(*Process).Wait(...)
        C:/Go.tip/src/os/exec.go:129
os/exec.(*Cmd).Wait(0xc0005cedc0, 0x0, 0x0)
        C:/Go.tip/src/os/exec/exec.go:507 +0x6a
os/exec.(*Cmd).Run(0xc0005cedc0, 0xc0000aca50, 0xc0005cedc0)
        C:/Go.tip/src/os/exec/exec.go:341 +0x66
os/exec.(*Cmd).CombinedOutput(0xc0005cedc0, 0x26, 0xc00008b390, 0x3, 0x3, 0xc0005cedc0)
        C:/Go.tip/src/os/exec/exec.go:567 +0x9b
os_test.TestCmdArgs(0xc0000f3500)
        C:/Go.tip/src/os/os_windows_test.go:896 +0x76d
testing.tRunner(0xc0000f3500, 0xb0f9c0)
        C:/Go.tip/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go.tip/src/testing/testing.go:1239 +0x2b3

goroutine 1522 [runnable]:
os/exec.(*Cmd).Start.func1(0xc0005cedc0, 0xc00044e020)
        C:/Go.tip/src/os/exec/exec.go:440
created by os/exec.(*Cmd).Start
        C:/Go.tip/src/os/exec/exec.go:440 +0x6b0
exit status 2
FAIL    os      7.459s

It seems to take some time before it fails, here are two additional traces:

runtime: setevent failed; errno=6
fatal error: runtime.semawakeup

runtime stack:
runtime.throw(0x1162470, 0x12)
        C:/Go.tip/src/runtime/panic.go:1112 +0x79
runtime.semawakeup.func1()
        C:/Go.tip/src/runtime/os_windows.go:796 +0x85
runtime.semawakeup(0xc0008af800)
        C:/Go.tip/src/runtime/os_windows.go:794 +0x51
runtime.notewakeup(0xc0008af920)
        C:/Go.tip/src/runtime/lock_sema.go:161 +0x65
runtime.startm(0x0, 0xc000020001)
        C:/Go.tip/src/runtime/proc.go:2318 +0x1d9
runtime.wakep()
        C:/Go.tip/src/runtime/proc.go:2398 +0x6d
runtime.resetspinning()
        C:/Go.tip/src/runtime/proc.go:2941 +0x69
runtime.schedule()
        C:/Go.tip/src/runtime/proc.go:3097 +0x2b9
runtime.park_m(0xc000485500)
        C:/Go.tip/src/runtime/proc.go:3239 +0xb2
runtime.mcall(0x0)
        C:/Go.tip/src/runtime/asm_amd64.s:323 +0x5e

goroutine 1 [chan receive]:
testing.(*T).Run(0xc00063c780, 0x115f734, 0xb, 0x116f9c0, 0x100b001)
        C:/Go.tip/src/testing/testing.go:1240 +0x2da
testing.runTests.func1(0xc00068a180)
        C:/Go.tip/src/testing/testing.go:1512 +0x7f
testing.tRunner(0xc00068a180, 0xc0005a5de0)
        C:/Go.tip/src/testing/testing.go:1194 +0xef
testing.runTests(0xc000004078, 0x128c020, 0x8f, 0x8f, 0xbff87be3e8de6b4c, 0x8bb2f15161, 0x128f520, 0x116056c)
        C:/Go.tip/src/testing/testing.go:1510 +0x310
testing.(*M).Run(0xc0000c2080, 0x0)
        C:/Go.tip/src/testing/testing.go:1418 +0x1f5
main.main()
        _testmain.go:361 +0x145

goroutine 10836 [chan receive]:
testing.(*T).Parallel(0xc00088d980)
        C:/Go.tip/src/testing/testing.go:1060 +0x119
os_test.TestOpenFileKeepsPermissions(0xc00088d980)
        C:/Go.tip/src/os/os_test.go:2661 +0x47
testing.tRunner(0xc00088d980, 0x116fbc0)
        C:/Go.tip/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go.tip/src/testing/testing.go:1239 +0x2b3

goroutine 11301 [sleep]:
time.Sleep(0x4c4b40)
        C:/Go.tip/src/runtime/time.go:193 +0xe5
os.(*Process).wait(0xc0009e4000, 0xc000596000, 0x0, 0x0)
        C:/Go.tip/src/os/exec_windows.go:45 +0x41b
os.(*Process).Wait(...)
        C:/Go.tip/src/os/exec.go:129
os/exec.(*Cmd).Wait(0xc000106b00, 0x0, 0x0)
        C:/Go.tip/src/os/exec/exec.go:507 +0x6a
os/exec.(*Cmd).Run(0xc000106b00, 0xc00087a390, 0xc000106b00)
        C:/Go.tip/src/os/exec/exec.go:341 +0x66
os/exec.(*Cmd).CombinedOutput(0xc000106b00, 0x26, 0xc000270d50, 0x3, 0x3, 0xc000106b00)
        C:/Go.tip/src/os/exec/exec.go:567 +0x9b
os_test.TestCmdArgs(0xc00063c780)
        C:/Go.tip/src/os/os_windows_test.go:896 +0x76d
testing.tRunner(0xc00063c780, 0x116f9c0)
        C:/Go.tip/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go.tip/src/testing/testing.go:1239 +0x2b3

goroutine 11330 [runnable]:
os/exec.(*Cmd).Start.func1(0xc000106b00, 0xc000280bc0)
        C:/Go.tip/src/os/exec/exec.go:440
created by os/exec.(*Cmd).Start
        C:/Go.tip/src/os/exec/exec.go:440 +0x6b0
exit status 2
FAIL    os      65.757s

runtime: setevent failed; errno=6
fatal error: runtime.semawakeup
runtime: waitforsingleobject wait_failed; errno=6
fatal error: runtime.semasleep wait_failed
runtime: waitforsingleobject wait_failed; errno=6
fatal error: runtime.semasleep wait_failed
panic during panic

runtime stack:
runtime.throw(0x387328, 0x1d)
        C:/Go.tip/src/runtime/panic.go:1112 +0x79
runtime.semasleep.func2()
        C:/Go.tip/src/runtime/os_windows.go:778 +0x85
runtime.semasleep(0xffffffffffffffff, 0x0)
        C:/Go.tip/src/runtime/os_windows.go:776 +0x1ec
runtime.lock2(0x4f4310)
        C:/Go.tip/src/runtime/lock_sema.go:89 +0x145
runtime.lockWithRank(0x4f4310, 0x0)
        C:/Go.tip/src/runtime/lockrank_off.go:22 +0x32
runtime.lock(0x4f4310)
        C:/Go.tip/src/runtime/lock_sema.go:36 +0x3b
runtime.startpanic_m(0x1)
        C:/Go.tip/src/runtime/panic.go:1256 +0x145
runtime.fatalthrow.func1()
        C:/Go.tip/src/runtime/panic.go:1165 +0x45
runtime.fatalthrow()
        C:/Go.tip/src/runtime/panic.go:1164 +0x5e
runtime.throw(0x387328, 0x1d)
        C:/Go.tip/src/runtime/panic.go:1112 +0x79
runtime.semasleep.func2()
        C:/Go.tip/src/runtime/os_windows.go:778 +0x85
runtime.semasleep(0xffffffffffffffff, 0xffffffff)
        C:/Go.tip/src/runtime/os_windows.go:776 +0x1ec
runtime.notetsleep_internal(0x4af7b8, 0x186a0, 0xc000429500, 0x173d2e0e394, 0x1b4a65b0598)
        C:/Go.tip/src/runtime/lock_sema.go:266 +0x1c5
runtime.notetsleep(0x4af7b8, 0x186a0, 0x0)
        C:/Go.tip/src/runtime/lock_sema.go:283 +0x66
runtime.forEachP(0x390190)
        C:/Go.tip/src/runtime/proc.go:1493 +0x332
runtime.gcMarkTermination.func4()
        C:/Go.tip/src/runtime/mgc.go:1765 +0x34
runtime.systemstack(0x0)
        C:/Go.tip/src/runtime/asm_amd64.s:375 +0x6b
runtime.mstart()
        C:/Go.tip/src/runtime/proc.go:1219

goroutine 117 [running]:
runtime.systemstack_switch()
        C:/Go.tip/src/runtime/asm_amd64.s:335 fp=0xc000599d50 sp=0xc000599d48 pc=0x200d20
runtime.gcMarkTermination(0x3ff8cb29ca5050fc)
        C:/Go.tip/src/runtime/mgc.go:1764 +0x436 fp=0xc000599f08 sp=0xc000599d50 pc=0x1ada36
runtime.gcMarkDone()
        C:/Go.tip/src/runtime/mgc.go:1623 +0x285 fp=0xc000599f60 sp=0xc000599f08 pc=0x1ad545
runtime.gcBgMarkWorker()
        C:/Go.tip/src/runtime/mgc.go:2045 +0x2e5 fp=0xc000599fe0 sp=0xc000599f60 pc=0x1ae6a5
runtime.goexit()
        C:/Go.tip/src/runtime/asm_amd64.s:1367 +0x1 fp=0xc000599fe8 sp=0xc000599fe0 pc=0x202bc1
created by runtime.gcBgMarkStartWorkers
        C:/Go.tip/src/runtime/mgc.go:1835 +0x3e

goroutine 1 [chan receive]:

runtime stack:
runtime: waitforsingleobject wait_failed; errno=6
fatal error: runtime.semasleep wait_failedruntime: setevent failed; errno=6
fatal error: runtime.semawakeup
panic during panic

runtime stack:

stack trace unavailable
exit status 4
FAIL    os      119.629s

CC: @alexbrainman, @zx2c4

About this issue

Original URL
State: closed
Created 3 years ago
Comments: 46 (41 by maintainers)

Commits related to this issue

runtime: detect errors in DuplicateHandle These functions rely on DuplicateHandle succeeding, but they don't check the return value, which might be masking subtle bugs that cause other problems down ... — committed to golang/go by zx2c4 3 years ago
runtime: free Windows event handles after last lock is dropped Calls to lock may need to use global members of mOS that also need to be cleaned up before the thread exits. Before this commit, these r... — committed to golang/go by zx2c4 3 years ago

Most upvoted comments

I think I see the bug… syscall.Stdin winds up being closed, and never reassigned. I’ll send a fix.

zx2c4 on Jan 18, 2021

I can reproduce the problem even with this:

diff --git a/src/runtime/os_windows.go b/src/runtime/os_windows.go
index d66e30ee3c..30bc978f95 100644
--- a/src/runtime/os_windows.go
+++ b/src/runtime/os_windows.go
@@ -942,6 +942,7 @@ func minit() {
 // Called from dropm to undo the effect of an minit.
 //go:nosplit
 func unminit() {
+       return
        mp := getg().m
        lock(&mp.threadLock)
        stdcall1(_CloseHandle, mp.thread)

So I don’t think it’s related to unminit.

zx2c4 on Jan 15, 2021

Got it.

)
=== RUN   TestRemoveAllLarge
runtime: setevent failed; errno=6, mp.waitsema=864
fatal error: runtime.semawakeup

runtime stack:
runtime.throw(0xa0251e, 0x12)
        C:/Go/src/runtime/panic.go:1112 +0x79
runtime.semawakeup.func1()
        C:/Go/src/runtime/os_windows.go:796 +0xc8
runtime.semawakeup(0xc000055000)
        C:/Go/src/runtime/os_windows.go:794 +0x6d
runtime.notewakeup(0xc000055120)
        C:/Go/src/runtime/lock_sema.go:161 +0x65
runtime.startm(0x0, 0xc000020001)
        C:/Go/src/runtime/proc.go:2318 +0x1d9
runtime.wakep()
        C:/Go/src/runtime/proc.go:2398 +0x6d
runtime.resetspinning()
        C:/Go/src/runtime/proc.go:2941 +0x69
runtime.schedule()
        C:/Go/src/runtime/proc.go:3097 +0x2b9
runtime.park_m(0xc0003ef800)
        C:/Go/src/runtime/proc.go:3239 +0xb2
runtime.mcall(0x0)
        C:/Go/src/runtime/asm_amd64.s:323 +0x5e

goroutine 1 [chan receive]:
testing.(*T).Run(0xc000590d80, 0xa02338, 0x12, 0xa0fda0, 0x8ab001)
        C:/Go/src/testing/testing.go:1240 +0x2da
testing.runTests.func1(0xc00038a000)
        C:/Go/src/testing/testing.go:1512 +0x7f
testing.tRunner(0xc00038a000, 0xc0004f7de0)
        C:/Go/src/testing/testing.go:1194 +0xef
testing.runTests(0xc00009c060, 0xb2c020, 0x8f, 0x8f, 0xbff87e2d1fcbf22c, 0x8bb2fe0c5d, 0xb2f520, 0xa0060c)
        C:/Go/src/testing/testing.go:1510 +0x310
testing.(*M).Run(0xc0000d6080, 0x0)
        C:/Go/src/testing/testing.go:1418 +0x1f5
main.main()
        _testmain.go:361 +0x145

goroutine 3416 [chan receive]:
testing.(*T).Parallel(0xc000590480)
        C:/Go/src/testing/testing.go:1060 +0x119
os_test.TestOpenFileKeepsPermissions(0xc000590480)
        C:/Go/src/os/os_test.go:2660 +0x47
testing.tRunner(0xc000590480, 0xa0fc68)
        C:/Go/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go/src/testing/testing.go:1239 +0x2b3

goroutine 4098 [chan receive]:
testing.(*T).Parallel(0xc000590180)
        C:/Go/src/testing/testing.go:1060 +0x119
os_test.TestFdReadRace(0xc000590180)
        C:/Go/src/os/pipe_test.go:435 +0x59
testing.tRunner(0xc000590180, 0xa0fb50)
        C:/Go/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go/src/testing/testing.go:1239 +0x2b3

goroutine 3953 [chan receive]:
testing.(*T).Parallel(0xc0001a6300)
        C:/Go/src/testing/testing.go:1060 +0x119
os_test.TestSymlinkCreation(0xc0001a6300)
        C:/Go/src/os/os_windows_test.go:971 +0x79
testing.tRunner(0xc0001a6300, 0xa0fec0)
        C:/Go/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go/src/testing/testing.go:1239 +0x2b3

goroutine 3970 [chan receive]:
testing.(*T).Parallel(0xc0001a6480)
        C:/Go/src/testing/testing.go:1060 +0x119
os_test.TestRootRelativeDirSymlink(0xc0001a6480)
        C:/Go/src/os/os_windows_test.go:1015 +0x7f
testing.tRunner(0xc0001a6480, 0xa0fe18)
        C:/Go/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go/src/testing/testing.go:1239 +0x2b3

goroutine 4099 [chan receive]:
testing.(*T).Parallel(0xc000590300)
        C:/Go/src/testing/testing.go:1060 +0x119
os_test.TestRawConnReadWrite(0xc000590300)
        C:/Go/src/os/rawconn_test.go:17 +0x5f
testing.tRunner(0xc000590300, 0xa0fce0)
        C:/Go/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go/src/testing/testing.go:1239 +0x2b3

goroutine 4105 [runnable]:
os.removeAll(0xc000800000, 0x3f, 0x37, 0xa3c83c)
        C:/Go/src/os/removeall_noat.go:15 +0x945
os.RemoveAll(...)
        C:/Go/src/os/path.go:67
os.removeAll(0xc000262300, 0x37, 0x0, 0x1b6)
        C:/Go/src/os/removeall_noat.go:69 +0x7e5
os.RemoveAll(...)
        C:/Go/src/os/path.go:67
os_test.TestRemoveAllLarge(0xc000590d80)
        C:/Go/src/os/removeall_test.go:151 +0x41d
testing.tRunner(0xc000590d80, 0xa0fda0)
        C:/Go/src/testing/testing.go:1194 +0xef
created by testing.(*T).Run
        C:/Go/src/testing/testing.go:1239 +0x2b3
FAIL    os      38.545s
FAIL

zx2c4 on Jan 15, 2021

I can’t reproduce this so far. If you’re able to trigger it easily, would you mind pasting the output for:

diff --git a/src/runtime/os_windows.go b/src/runtime/os_windows.go
index d389d38ab9..ad4e744759 100644
--- a/src/runtime/os_windows.go
+++ b/src/runtime/os_windows.go
@@ -792,7 +792,7 @@ func semasleep(ns int64) int32 {
 func semawakeup(mp *m) {
 	if stdcall1(_SetEvent, mp.waitsema) == 0 {
 		systemstack(func() {
-			print("runtime: setevent failed; errno=", getlasterror(), "\n")
+			print("runtime: setevent failed; errno=", getlasterror(), ", mp.waitsema=", mp.waitsema, "\n")
 			throw("runtime.semawakeup")
 		})
 	}

zx2c4 on Jan 15, 2021