Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

x/net/http2: TestTransportFlowControl takes 31 seconds on OpenBSD #18273

Open
bradfitz opened this issue Dec 10, 2016 · 3 comments
Open

x/net/http2: TestTransportFlowControl takes 31 seconds on OpenBSD #18273

bradfitz opened this issue Dec 10, 2016 · 3 comments
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-OpenBSD Performance
Milestone

Comments

@bradfitz
Copy link
Contributor

TestTransportFlowControl takes 31 seconds on OpenBSD, but 1.8 seconds on the same hardware on Linux.

Why?

/cc @tombergan who suspects relation to #15899
/cc @mdempsky @4a6f656c

@bradfitz bradfitz added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-OpenBSD Performance labels Dec 10, 2016
@bradfitz bradfitz added this to the Unreleased milestone Dec 10, 2016
gopherbot pushed a commit to golang/net that referenced this issue Dec 10, 2016
Updates golang/go#18273

Change-Id: I2e7589d070a2953972bc8456d572edd616525266
Reviewed-on: https://go-review.googlesource.com/34271
Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Tom Bergan <tombergan@google.com>
@bradfitz
Copy link
Contributor Author

Also, maybe on plan9?

https://build.golang.org/log/56ad9ce8572775821da69056b2af5765af029c5b

Unsure.

@gopherbot
Copy link
Contributor

CL https://golang.org/cl/34495 mentions this issue.

gopherbot pushed a commit that referenced this issue Dec 15, 2016
Updates bundled x/net/http2 to git rev 1195a05d for:

    http2: fix incorrect panic
    https://golang.org/cl/34498

    http2: fix race in writePushPromise
    https://golang.org/cl/34493

    http2: speed up TestTransportFlowControl in short mode
    https://golang.org/cl/33241

    http2: don't flush a stream's write queue in sc.resetStream
    https://golang.org/cl/34238

    http2: allow Transport to connect to https://[v6literal]/ without port
    https://golang.org/cl/34143

    http2: log Framer reads and writes when a server test fails
    https://golang.org/cl/34130

Updates #18326
Updates #18273
Updates #18111
Updates #18248
Updates #18235

Change-Id: I18c7a297fc94d6a843284efcfc43e0fdab9b5f41
Reviewed-on: https://go-review.googlesource.com/34495
Run-TryBot: Chris Broadfoot <cbro@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
@FrankReh
Copy link

FrankReh commented Feb 8, 2018

The lost time is in the call to sleep in the read loop.

TL;DR; Ask OpenBSD (at least an amd64 6.2 OpenBSD) to sleep for 1 millisecond, and it will sleep for 20 times that. So tests that use a 1ms sleep in each iteration will take a lot longer on OpenBSD.

I tried this on Debian Linux, FreeBSD and OpenBSD. All amd64 virtual machines.

Each reads and writes in 65536 byte chunks. Each iterates the write loop 1600 times. Linux needs 1600 iterations for the read loop, and the two BSDs need 1601 iterations.

The request for a 1 ms sleep in each iteration of the read loop is actually taking 18 to 22 ms on OpenBSD. The same call takes just over a ms on a similarly setup FreeBSD machine and even closer to a single ms on a similarly setup Debian machine.

Since the resolution seems to be around 20ms for OpenBSD, and it is the worst offender of the three I tested, I added logic around the call to sleep so it would only be called once every 20 times through the loop, and changed the request to sleep from 1ms to 20ms. This improved the results for OpenBSD without making things worse for FreeBSD or Linux. The TestTransportFlowControl test can be made to succeed in about 2 seconds. Here are the three values I got.

Linux: 1.7s
FreeBSD: 2.0s
OpenBSD: 2.5s

The accuracy of the Linux sleep is much higher than the BSDs' sleep. The Linux sleep for 20ms averaged taking 20.3ms, FreeBSD averaged 24ms and OpenBSD averaged 30ms.

That's not a typo. The call time.Sleep(20 * time.Millisecond),
with two calls to time.Now before and after, takes on average 30 milliseconds on OpenBSD. They just don't want to give you an accurate timer for security reasons I think. If you ask to sleep for one millisecond, they make you sleep about 20 milliseconds on average. But ask for 20, and you get between 24 and 40, with the average being 30.

Any golang tests that try to use a 1 millisecond timer on OpenBSD are not going to compare well with results from the other OSes.

To convince myself this wasn't some other fault of golang, I wrote a trivial c program to call nanosleep 1000 times for 1ms each. Sure enough, on Linux and FreeBSD, the program took just over a second to run. On OpenBSD, it took just over 20 seconds to run. Even a C program can't expect to sleep for 1ms at a time on OpenBSD.

c3mb0 pushed a commit to c3mb0/net that referenced this issue Apr 2, 2018
Updates golang/go#18273

Change-Id: I2e7589d070a2953972bc8456d572edd616525266
Reviewed-on: https://go-review.googlesource.com/34271
Run-TryBot: Brad Fitzpatrick <bradfitz@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Tom Bergan <tombergan@google.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-OpenBSD Performance
Projects
None yet
Development

No branches or pull requests

3 participants