net: tests using timer fail on macOS High Sierra 10.13 / iOS 11 #22062

pavlo-v-chernykh · 2017-09-27T08:48:04Z

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

go version go1.9 darwin/amd64

Does this issue reproduce with the latest release?

yes

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

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/pavel/Projects/go"
GORACE=""
GOROOT="/usr/local/Cellar/go/1.9/libexec"
GOTOOLDIR="/usr/local/Cellar/go/1.9/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/jr/3_2b1w35179bs1tn3q7_n90c0000gn/T/go-build741533368=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"

What did you do?

Run

$ cd go/src
$ ./all.bash

What did you expect to see?

"ALL TESTS PASSED".

What did you see instead?

$ ./all.bash
...
--- FAIL: TestDialerDualStackFDLeak (0.20s)
	dial_test.go:90: got 100.514503ms; want <= 95ms
FAIL
FAIL	net	4.328s
...
2017/09/27 10:43:48 Failed: exit status 1

The text was updated successfully, but these errors were encountered:

mikioh · 2017-09-27T09:05:08Z

See https://github.com/golang/go/wiki/Darwin and #22037. I guess that "go test -v -short=false" shows more test failures.

ianlancetaylor · 2017-09-27T14:01:46Z

How repeatable is this problem?

pavlo-v-chernykh · 2017-09-27T14:53:12Z

Not a single success for this test since the update to High Sierra.
Have run it ten times in a row recently, no success.

P/g/s/g/go/src (master) $ for i in (seq 10); go tool dist test  -run=go_test:net\$; end


##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (1.11s)
	dial_test.go:90: got 100.711025ms; want <= 95ms
FAIL
FAIL	net	3.857s
2017/09/27 17:46:06 Failed: exit status 1

##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (0.20s)
	dial_test.go:90: got 100.658145ms; want <= 95ms
FAIL
FAIL	net	2.339s
2017/09/27 17:46:12 Failed: exit status 1

##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (0.20s)
	dial_test.go:90: got 100.309476ms; want <= 95ms
FAIL
FAIL	net	3.941s
2017/09/27 17:46:19 Failed: exit status 1

##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (0.20s)
	dial_test.go:90: got 101.246644ms; want <= 95ms
FAIL
FAIL	net	4.513s
2017/09/27 17:46:27 Failed: exit status 1

##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (0.20s)
	dial_test.go:90: got 101.112404ms; want <= 95ms
FAIL
FAIL	net	4.176s
2017/09/27 17:46:35 Failed: exit status 1

##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (2.01s)
	dial_test.go:90: got 1.004516011s; want <= 95ms
FAIL
FAIL	net	5.929s
2017/09/27 17:46:45 Failed: exit status 1

##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (0.20s)
	dial_test.go:90: got 100.524832ms; want <= 95ms
FAIL
FAIL	net	3.946s
2017/09/27 17:46:52 Failed: exit status 1

##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (2.01s)
	dial_test.go:90: got 1.001501156s; want <= 95ms
FAIL
FAIL	net	5.953s
2017/09/27 17:47:02 Failed: exit status 1

##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (0.20s)
	dial_test.go:90: got 100.817715ms; want <= 95ms
FAIL
FAIL	net	2.171s
2017/09/27 17:47:08 Failed: exit status 1

##### Testing packages.
--- FAIL: TestDialerDualStackFDLeak (0.20s)
	dial_test.go:90: got 101.123833ms; want <= 95ms
FAIL
FAIL	net	4.018s
2017/09/27 17:47:15 Failed: exit status 1

Kernel info

$ uname -a
Darwin mbp 17.0.0 Darwin Kernel Version 17.0.0: Thu Aug 24 21:48:19 PDT 2017; root:xnu-4570.1.46~2/RELEASE_X86_64 x86_64

mikioh · 2017-09-28T03:30:54Z

Okay, my friend kindly sent me the result of "cd $GOROOT/src/net; go test -short=false -count=10" on macOS High Sierra 10.13.

--- FAIL: TestDialerDualStackFDLeak (0.42s)
	dial_test.go:90: got 211.099986ms; want <= 95ms
--- FAIL: TestDialParallel (1.83s)
	dial_test.go:201: got 211.118921ms; want <= 95ms
	dial_test.go:323: #6: got 101.872119ms; want >= 116.118921ms
	dial_test.go:323: #7: got 300.99846ms; want >= 316.118921ms
	dial_test.go:323: #9: got 101.785746ms; want >= 105ms
--- FAIL: TestDialerDualStackFDLeak (0.21s)
	dial_test.go:90: got 101.101089ms; want <= 95ms
--- FAIL: TestDialParallel (1.31s)
	dial_test.go:201: got 101.007812ms; want <= 95ms
--- FAIL: TestDialerDualStackFDLeak (0.21s)
	dial_test.go:90: got 100.969161ms; want <= 95ms
--- FAIL: TestDialParallel (1.30s)
	dial_test.go:201: got 100.228108ms; want <= 95ms
--- FAIL: TestDialerDualStackFDLeak (0.21s)
	dial_test.go:90: got 100.699773ms; want <= 95ms
--- FAIL: TestDialParallel (1.31s)
	dial_test.go:201: got 101.268161ms; want <= 95ms
--- FAIL: TestDialTimeout (1.20s)
	timeout_test.go:81: #7: Dial didn't return in an expected time
--- FAIL: TestDialerDualStackFDLeak (0.21s)
	dial_test.go:90: got 100.159207ms; want <= 95ms
--- FAIL: TestDialParallel (1.31s)
	dial_test.go:201: got 101.191819ms; want <= 95ms
--- FAIL: TestDialParallel (0.80s)
	dial_test.go:325: #6: got 102.484699ms; want <= 95.122372ms
	dial_test.go:325: #7: got 303.135013ms; want <= 295.122372ms
	dial_test.go:325: #9: got 101.71373ms; want <= 95.122372ms
--- FAIL: TestDialParallel (0.81s)
	dial_test.go:325: #6: got 102.653457ms; want <= 95.06071ms
	dial_test.go:325: #7: got 305.540876ms; want <= 295.06071ms
	dial_test.go:325: #9: got 103.048016ms; want <= 95.06071ms

(snip)

FAIL
exit status 1
FAIL	net	313.890s

onehr · 2017-09-28T03:57:43Z

got the same problem, using macOS High Sierra.

ianlancetaylor · 2017-09-28T17:04:42Z

As @mikioh suggested, I bet this is a dup of #22037. I don't think we need spend time investigating this until #22037 is fixed.

pavlo-v-chernykh · 2017-09-28T19:33:14Z

Look like on iOS there was the same issue 90fdc45

rasky · 2017-09-30T16:21:40Z

FWIW, my patch for #22037 doesn't fix this bug. Also, if my understanding of that bug is correct, High Sierra only broke Go's real timer, not monotonic timer; the failures in these tests look like results of measures that are computed using the monotonic timer (time.Now + time.Sub or time.Since).

bmerrill42 · 2017-09-30T20:00:07Z

the dial_test.go looks like it's not detecting the right architecture

	if runtime.GOOS == "windows" {
		expected = 1500 * time.Millisecond
	} else if runtime.GOOS == "darwin" && (runtime.GOARCH == "arm" || runtime.GOARCH == "arm64") {
		expected = 150 * time.Millisecond
	} else {
		expected = 95 * time.Millisecond
	}

when I add amd64 to the else if it works just fine since the response is never below 95ms

gopherbot · 2017-09-30T21:18:01Z

Change https://golang.org/cl/67350 mentions this issue: net: inside dial_test.go added amd64 architecture to the 150ms expected dialing closed port

ianlancetaylor · 2017-10-03T14:41:40Z

I guess everyone else is up to speed on this, but I'll note that we bumped the timeout on iOS in https://golang.org/cl/66491 because the test started failing on iOS 11. These failures do look very similar, so it appears that new versions of Darwin have introduced some sort of 100ms or 50ms timeout for some reason.

ianlancetaylor · 2017-10-13T19:26:29Z

Reopening to consider backporting CL 67350 to 1.9.2 to avoid unhelpful test failures on MacOS High Sierra.

CC @rsc

rsc · 2017-10-13T20:19:03Z

CL 66491 OK for Go 1.9.2.
CL 67350 OK for Go 1.9.2.
Does this also need fixing in Go 1.8.5?

ianlancetaylor · 2017-10-13T20:38:06Z

High Sierra hasn't been released yet, so I'm OK with telling people using an unreleased OS that they need to be using the newest Go release. And if we get Go 1.10 out before High Sierra is officially released then 1.8 will no longer be supported.

But the fix is simple and safe so it's fine with me if we put it into 1.8.5.

rsc · 2017-10-15T02:06:52Z

The CL pair appears to apply to Go 1.8.4 cleanly and is restricted to the tests, so I will include it while we have the fix paged in.

gopherbot · 2017-10-15T02:32:27Z

Change https://golang.org/cl/70988 mentions this issue: [release-branch.go1.9] net: increase expected time to dial a closed port on all Darwin ports

gopherbot · 2017-10-17T16:38:02Z

Change https://golang.org/cl/71331 mentions this issue: [release-branch.go1.8] net: increase expected time to dial a closed port on all Darwin ports

…ort on all Darwin ports All current darwin architectures seem to take at least 100ms to dial a closed port, and that was making the all.bash script fail. Fixes #22062 Change-Id: Ib79c4b7a5db2373c95ce5d993cdcbee55cc0667f Reviewed-on: https://go-review.googlesource.com/67350 Reviewed-by: Ian Lance Taylor <iant@golang.org> Reviewed-on: https://go-review.googlesource.com/71331 Run-TryBot: Russ Cox <rsc@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org>

…ort on all Darwin ports All current darwin architectures seem to take at least 100ms to dial a closed port, and that was making the all.bash script fail. Fixes #22062 Change-Id: Ib79c4b7a5db2373c95ce5d993cdcbee55cc0667f Reviewed-on: https://go-review.googlesource.com/67350 Reviewed-by: Ian Lance Taylor <iant@golang.org> Reviewed-on: https://go-review.googlesource.com/70988 Run-TryBot: Russ Cox <rsc@golang.org> TryBot-Result: Gobot Gobot <gobot@golang.org>

rsc · 2017-10-26T21:09:19Z

go1.9.2 has been packaged and includes:

The release is posted at golang.org/dl.

— golang.org/x/build/cmd/releasebot, Oct 26 21:09:19 UTC

mikioh changed the title ~~TestDialerDualStackFDLeak fails on macOS High Sierra~~ net: TestDialerDualStackFDLeak fails on macOS High Sierra Sep 27, 2017

mikioh added the OS-Darwin label Sep 27, 2017

ianlancetaylor added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Sep 27, 2017

ianlancetaylor added this to the Go1.10 milestone Sep 27, 2017

mikioh changed the title ~~net: TestDialerDualStackFDLeak fails on macOS High Sierra~~ net: tests using timer fail on macOS High Sierra Sep 28, 2017

ianlancetaylor added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Sep 28, 2017

mikioh changed the title ~~net: tests using timer fail on macOS High Sierra~~ net: tests using timer fail on macOS High Sierra 10.13 / iOS 11 Sep 29, 2017

gopherbot closed this as completed in 5f83b2d Oct 4, 2017

ianlancetaylor mentioned this issue Oct 13, 2017

High Sierra TestDialerDualStackFDLeak Compile Error #22255

Closed

ianlancetaylor reopened this Oct 13, 2017

ianlancetaylor modified the milestones: Go1.10, Go1.9.2 Oct 13, 2017

ianlancetaylor added Testing An issue that has been verified to require only test changes, not just a test failure. and removed NeedsFix The path to resolution is known, but the work has not been done. labels Oct 13, 2017

rsc added the release-blocker label Oct 13, 2017

rsc mentioned this issue Oct 14, 2017

net: tests using timer fail on macOS High Sierra 10.13 / iOS 11 [Go 1.8] #22262

Closed

rsc added the CherryPickApproved Used during the release process for point releases label Oct 14, 2017

rsc mentioned this issue Oct 15, 2017

all: Go 1.9.2 release status #22277

Closed

rsc mentioned this issue Oct 15, 2017

net: tests using timer fail on macOS High Sierra 10.13 / iOS 11 [Go 1.8] #22279

Closed

rsc closed this as completed Oct 26, 2017

golang locked and limited conversation to collaborators Oct 26, 2018

gopherbot added the FrozenDueToAge label Oct 26, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

net: tests using timer fail on macOS High Sierra 10.13 / iOS 11 #22062

net: tests using timer fail on macOS High Sierra 10.13 / iOS 11 #22062

pavlo-v-chernykh commented Sep 27, 2017

mikioh commented Sep 27, 2017

ianlancetaylor commented Sep 27, 2017

pavlo-v-chernykh commented Sep 27, 2017

mikioh commented Sep 28, 2017

onehr commented Sep 28, 2017

ianlancetaylor commented Sep 28, 2017

pavlo-v-chernykh commented Sep 28, 2017

rasky commented Sep 30, 2017

bmerrill42 commented Sep 30, 2017

gopherbot commented Sep 30, 2017

ianlancetaylor commented Oct 3, 2017

ianlancetaylor commented Oct 13, 2017

rsc commented Oct 13, 2017 •

edited

ianlancetaylor commented Oct 13, 2017

rsc commented Oct 15, 2017

gopherbot commented Oct 15, 2017

gopherbot commented Oct 17, 2017

rsc commented Oct 26, 2017

net: tests using timer fail on macOS High Sierra 10.13 / iOS 11 #22062

net: tests using timer fail on macOS High Sierra 10.13 / iOS 11 #22062

Comments

pavlo-v-chernykh commented Sep 27, 2017

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

Does this issue reproduce with the latest release?

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

What did you do?

What did you expect to see?

What did you see instead?

mikioh commented Sep 27, 2017

ianlancetaylor commented Sep 27, 2017

pavlo-v-chernykh commented Sep 27, 2017

mikioh commented Sep 28, 2017

onehr commented Sep 28, 2017

ianlancetaylor commented Sep 28, 2017

pavlo-v-chernykh commented Sep 28, 2017

rasky commented Sep 30, 2017

bmerrill42 commented Sep 30, 2017

gopherbot commented Sep 30, 2017

ianlancetaylor commented Oct 3, 2017

ianlancetaylor commented Oct 13, 2017

rsc commented Oct 13, 2017 • edited

ianlancetaylor commented Oct 13, 2017

rsc commented Oct 15, 2017

gopherbot commented Oct 15, 2017

gopherbot commented Oct 17, 2017

rsc commented Oct 26, 2017

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

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

rsc commented Oct 13, 2017 •

edited