runtime, internal/poll: darwin: ensure that no thread is consumed, nor a syscall.Read if FD isn't yet ready for I/O

[odeke-em]

Coming here from #32326.
That test was meant to ensure that an (*os.File).Read which is backed by internal/poll would ONLY consume a thread for a read syscall if I/O was ready.

Examining @MichaelTJones' crash dump in reveals in deed that when it crashed

$ grep 'os_test.go' stack | sort | uniq
/Users/mtj/go/src/os/os_test.go:2283 
/Users/mtj/go/src/os/os_test.go:2283 +0x370 
/Users/mtj/go/src/os/os_test.go:2286 +0x84 
/Users/mtj/go/src/os/os_test.go:2286 +0x84 fp=0xc00025afa8 sp=0xc00025af48 
/Users/mtj/go/src/os/os_test.go:2297 +0x3aa 

non of the code had gotten past blocking on a syscall.Read as per

go/src/os/os_test.go

Line 2297 in e87fe0f

<-creading

and also from his execution traces

Somehow the poller is tripping out and not blocking until the file descriptor is ready for I/O.

In that test, our high water mark for the max number of threads was 50 but for regular machines where GOMAXPROCS=2,4,8, the maximum value of threads if every call was doing a syscall.Read would be 10, 18, 34 if we follow

        P := runtime.GOMAXPROCS(0)
        n := threads
        maxThreads := 0
        if n/P-1 >= P {
                maxThreads = 2 + 4*P
        } else {
                maxThreads = 1 + (7 * P / 4) + (n / P)
        }

but in his case, given GOMAXPROCS=32,36, it would be 61, 67.

Hence why his test failed but it went undetected for usually small values of GOMAXPROCS. Let's also examine the behaviors between versions of Go to see when things regressed.

[julieqiu]

/cc @aclements @randall77

[gopherbot]

Change https://golang.org/cl/192342 mentions this issue: os: skip TestPipeThreads on GOOS=darwin

[gopherbot]

Change https://golang.org/cl/192757 mentions this issue: os: skip TestPipeThreads on GOOS=darwin

[odeke-em]

I found the commit that introduced this problem, commit a3b0144#diff-38e21adab3460688e3ce0b71fa9422d0 aka CL https://go-review.googlesource.com/c/141639 which is a part of Go1.12.

This program should be able to run alright with GOMAXPROCS=8 and a max of 8 threads before that commit

package main

import (
	"log"
	"os"
	"runtime/debug"
	"sync"
	"syscall"
	"time"
)

func main() {
	n := 100

	var rl, wl []*os.File
	for i := 0; i < n; i++ {
		prc, pwc, err := os.Pipe()
		if err != nil {
			// Cleanup.
			for j := 0; j < i; j++ {
				wl[i].Close()
				rl[i].Close()
			}
		}
		rl = append(rl, prc)
		wl = append(rl, pwc)
	}

	defer debug.SetMaxThreads(debug.SetMaxThreads(8))

	var wg sync.WaitGroup
	for i := 0; i < n; i++ {
		wg.Add(1)
		go func(i int) {
			bs := make([]byte, 4)
			wg.Done()
			prc := rl[i]
			if _, err := prc.Read(bs); err != nil {
				log.Fatalf("Failed to read %d: %v\n", i, err)
			}
		}(i)
	}

	wg.Wait()
	println("Waiting now")
	for {
		<-time.After(5 * time.Second)
		if true {
			return
		}
		proc, _ := os.FindProcess(os.Getpid())
		proc.Signal(syscall.SIGQUIT)
	}

	for i := 0; i < n; i++ {
		if _, err := wl[i].Write([]byte("Hello")); err != nil {
			log.Fatalf("Write #%d failed: %v", err)
		}
	}
}

Kindly pinging @randall77.
For Go1.13, we've disabled the test on Darwin but after we've fixed the issue, we'll need to backport to Go1.12 and Go1.13 as well.

[odeke-em]

Some great news, @minux's CL https://go-review.googlesource.com/c/go/+/197938 fixed this issue in that change from entersyscallblock() to entersyscall() so we'll need to backport Minux's CL to both Go1.12 and Go1.13 as per https://groups.google.com/d/msg/golang-dev/UYDTDWHJsC8/a1_4KiKnCwAJ.

@gopherbot please backport this issue to Go1.12 and Go1.13.

[gopherbot]

Backport issue(s) opened: #34713 (for 1.12), #34714 (for 1.13).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://golang.org/wiki/MinorReleases.

[gopherbot]

Change https://golang.org/cl/199477 mentions this issue: os: re-enable TestPipeThreads on darwin

[networkimprov]

@odeke-em also need to revert 4c8037b

[odeke-em]

Liam, thanks for pointing that out. Minux already did that just above, but that test as it was has a very high watermark that didn't catch the issue until very late so we'll also need to review and update it.

…

On Sun, Oct 6, 2019 at 12:51 PM Liam ***@***.***> wrote: @odeke-em <https://github.com/odeke-em> also need to revert 4c8037b <4c8037b> — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#33953?email_source=notifications&email_token=ABFL3V3EVAFXAKMBQKD5KYDQNI6VHA5CNFSM4ISFNDR2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEAOSM4I#issuecomment-538781297>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ABFL3V7CRVGGU4NMT7PENX3QNI6VHANCNFSM4ISFNDRQ> .

[networkimprov]

I don't follow you... The commit I referenced dropped the test on the 1.13 branch. The test has been reinstated on tip.

[ianlancetaylor]

We don't need to re-enable the test on the branch. That's not a bug fix.