go: net: 1.14 performance regression on mac

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

$ go version
go version go1.13.5 darwin/amd64

and

$ go version
go version go1.14beta1 darwin/amd64

Does this issue reproduce with the latest release?

Yes, the issue started with the latest beta release.

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

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/erik/Library/Caches/go-build"
GOENV="/Users/erik/Library/Application Support/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/erik"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/s6/xkrsszq51hb0vrnmn08jsr140000gn/T/go-build119700800=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

I wrote a simple program that uses the net package to use 9000 connections and 9000*2 goroutines (*2 for both sides of the connection) to send requests and responses every 200 milliseconds. Then I measure the average delay it takes for the response to arrive (so a little bit over 200ms expected). Program: https://gist.github.com/erikdubbelboer/d925c6e271aa0c5c8bb20a6ec16455c5

What did you expect to see?

On go1.13.5 the average response time is around 206ms. So 6ms more than the expected delay.

What did you see instead?

On go1.14beta1 the average response time is 300ms. That’s 94ms extra delay just for upgrading Go.

The program only consumes about half of the CPU’s I have so it’s not a CPU bottleneck.

I have tested the exact same thing on an Ubuntu machine and here the average response time is 200ms (rounded down, it’s only a couple of microseconds of delay) for both versions of Go.

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Reactions: 4
  • Comments: 24 (22 by maintainers)

Most upvoted comments

I don’t think there is anything to do here. Tip is a bit better for me, but times do still increase at some point. I think this is inevitable, and I think that without calling time.Sleep the program will run more smoothly.

Closing. Please comment if you disagree.

One more comment: if I change goroutineReady in runtime/time.go to

	ready(arg.(*g), 0, false)

the program can run a few more connections before collapsing. The difference is that the current version queues up the goroutine whose sleep time has expired to be the next goroutine that the P runs. That is normally the desired behavior. But when a bunch of sleep timers expire in the same run of checkTimers, the effect is to run the goroutines in reverse order of timer expiration.

I’ve convinced myself that this is due to timer synchronization. With the original program I see delays increase at around 7000 connections on my GNU/Linux laptop. Modifying handler to add an offset of (rand.Int() % 32) - 16 milliseconds to the time.Sleep I can run up to 15000 connections without seeing any delays.

I’m retargeting this for 1.15, but happy to hear counter-arguments.

Thank you for this report @erikdubbelboer. Unfortunately, I don’t have a mac, so I can’t test this. Would you be open to running a git bisect to exactly pin point this issue to the offending commit ? That would help a lot in the investigation.