runtime: proc_test timed out on TestPreemptionAfterSyscall on windows/386

[toothrot]

What version of Go are you using (go version)?

$ go version
go version go1.13.1 windows/386 # http://golang.org/cl/201060 

Does this issue reproduce with the latest release?

This failure is specifically on release-branch.go1.13, from this cl: http://golang.org/cl/201060

What operating system and processor architecture are you using (go env)?

go env Output

$ go env
"GOBUILDEXIT=1"
"=C:=C:\\golang"
"ALLUSERSPROFILE=C:\\ProgramData"
"APPDATA=C:\\Users\\gopher\\AppData\\Roaming"
"CommonProgramFiles=C:\\Program Files\\Common Files"
"CommonProgramFiles(x86)=C:\\Program Files (x86)\\Common Files"
"CommonProgramW6432=C:\\Program Files\\Common Files"
"COMPUTERNAME=SERVER-2008R2-V"
"ComSpec=C:\\Windows\\system32\\cmd.exe"
"FP_NO_HOST_CHECK=NO"
"GooGetRoot=C:\\ProgramData\\GooGet"
"GOROOT_BOOTSTRAP=C:\\workdir\\go1.4"
"HOMEDRIVE=C:"
"HOMEPATH=\\Users\\gopher"
"LOCALAPPDATA=C:\\Users\\gopher\\AppData\\Local"
"LOGONSERVER=\\\\SERVER-2008R2-V"
"NUMBER_OF_PROCESSORS=4"
"OS=Windows_NT"
"PATH=C:\\Windows\\system32;C:\\Windows;C:\\Windows\\System32\\Wbem;C:\\Windows\\System32\\WindowsPowerShell\\v1.0\\;C:\\Windows\\System32\\WindowsPowerShell\\v1.0\\;C:\\ProgramData\\GooGet;C:\\Program Files\\Google\\Compute Engine\\metadata_scripts;C:\\Program Files (x86)\\Google\\Cloud SDK\\google-cloud-sdk\\bin;C:\\Windows\\System32\\WindowsPowerShell\\v1.0\\;C:\\Program Files\\Google\\Compute Engine\\sysprep;C:\\godep\\gcc32\\bin"
"PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC"
"PROCESSOR_ARCHITECTURE=AMD64"
"PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 63 Stepping 0, GenuineIntel"
"PROCESSOR_LEVEL=6"
"PROCESSOR_REVISION=3f00"
"ProgramData=C:\\ProgramData"
"ProgramFiles=C:\\Program Files"
"ProgramFiles(x86)=C:\\Program Files (x86)"
"ProgramW6432=C:\\Program Files"
"PROMPT=$P$G"
"PSModulePath=C:\\Windows\\system32\\WindowsPowerShell\\v1.0\\Modules\\;C:\\Program Files (x86)\\Google\\Cloud SDK\\google-cloud-sdk\\platform\\PowerShell"
"PUBLIC=C:\\Users\\Public"
"SESSIONNAME=Console"
"SystemDrive=C:"
"SystemRoot=C:\\Windows"
"TEMP=C:\\Users\\gopher\\AppData\\Local\\Temp"
"TMP=C:\\Users\\gopher\\AppData\\Local\\Temp"
"USERDOMAIN=SERVER-2008R2-V"
"USERDOMAIN_ROAMINGPROFILE=SERVER-2008R2-V"
"USERNAME=gopher"
"USERPROFILE=C:\\Users\\gopher"
"windir=C:\\Windows"
"windows_tracing_flags=3"
"windows_tracing_logfile=C:\\BVTBin\\Tests\\installpackage\\csilogfile.log"
"GO_STAGE0_NET_DELAY=21.3s"
"GO_STAGE0_DL_DELAY=200ms"
"WORKDIR=C:\\workdir"
"GO_BUILDER_NAME=windows-386-2008"
"GOARCH=386"
"GOHOSTARCH=386"
"GOBIN="

What did you do?

Ran trybots for http://golang.org/cl/201060

The CL updates prove.go to correct an issue with negative indexes on slices.

What did you expect to see?

Success

What did you see instead?

The trybot run failed on a test for goroutine premption in tight loops around system calls. I don't feel like this test is related to the change.

A subsequent trybot run passed.

##### GOMAXPROCS=2 runtime -cpu=1,2,4 -quick
--- FAIL: TestPreemptionAfterSyscall (3.23s)
    --- FAIL: TestPreemptionAfterSyscall/1ms (3.10s)
        proc_test.go:967: timeout exceeded: 3.0976562s (3s)
FAIL
FAIL	runtime	58.635s
FAIL
2019/10/14 17:34:34 Failed: exit status 1
2019/10/14 17:34:34 FAILED

Full Trybot log:
https://storage.googleapis.com/go-build-log/def5eb7b/windows-386-2008_29aaa38e.log

[toothrot]

Test was implemented as part of #10958

/cc @avagin

[bcmills]

Another one on windows-386-2008: https://storage.googleapis.com/go-build-log/be5773d4/windows-386-2008_7e1a2722.log

Also lots of these on the plan9 builder:
2019-11-06T19:48:05-0054723/plan9-amd64-9front
2019-11-06T17:02:19-4cb9260/plan9-amd64-9front
2019-11-06T02:49:10-de70de6/plan9-amd64-9front
2019-11-05T18:58:41-f07cbc7/plan9-amd64-9front
2019-11-05T18:02:45-9514914/plan9-amd64-9front
2019-11-05T14:34:56-79a00a3/plan9-amd64-9front
2019-11-05T05:22:07-3c0fbee/plan9-amd64-9front
2019-11-05T03:50:54-979d65d/plan9-amd64-9front
2019-11-05T03:42:29-9a0a824/plan9-amd64-9front
2019-11-05T00:26:30-b3bd7ab/plan9-amd64-9front
2019-11-05T00:17:34-04e80fb/plan9-amd64-9front
2019-11-04T23:41:34-383b447/plan9-amd64-9front
2019-11-04T17:19:36-1da575a/plan9-amd64-9front
2019-11-04T15:18:34-d3660e8/plan9-amd64-9front
2019-11-01T00:04:51-4a09a9b/plan9-amd64-9front
2019-10-29T19:20:52-07b72d9/plan9-amd64-9front

[bcmills]

CC @aclements @mknyszek @cherrymui @ianlancetaylor

[ianlancetaylor]

We haven't seen any failures in the last five days, but we used to see multiple failures per day. I'm not sure what fixed this, but it is almost certainly fixed.