Can you use the net/http/pprof package and collect CPU profiles from both versions? Thanks.

CC @bradfitz

cpuprofile.zip

Attached on both versions.

Thanks. Unfortunately I don't see the problem.

I'll mark this as a release blocker for now. I hope that somebody will be able to find what changed.

Can you share the code that you are using for benchmarking? Thanks.

Sure, the following example:

package main

import (
    "fmt"
    "net/http"
//  "runtime"
     _ "net/http/pprof"
)

func hello(w http.ResponseWriter, req *http.Request) {
        fmt.Fprintf(w, "hello world!\n")
}

func main() {
//      runtime.GOMAXPROCS(1)
        http.HandleFunc("/hello", hello)
        http.ListenAndServe(":8090", nil)
}

@neild

I can confirm that I see a difference in 1.14 vs. 1.15beta1. Linux, amd64, GOMAXPROCS(1), the above test program and ten runs each of wrk -c100 -d5.

$ grep ^Request bench.go1.14
Requests/sec:  43433.19
Requests/sec:  43201.69
Requests/sec:  44116.82
Requests/sec:  43029.81
Requests/sec:  43827.57
Requests/sec:  42289.91
Requests/sec:  43815.39
Requests/sec:  44036.54
Requests/sec:  43955.58
Requests/sec:  43393.49

$ grep ^Request bench.go1.15
Requests/sec:  40063.74
Requests/sec:  40559.97
Requests/sec:  41783.38
Requests/sec:  41255.86
Requests/sec:  41534.14
Requests/sec:  40796.73
Requests/sec:  41519.93
Requests/sec:  39966.21
Requests/sec:  41283.03
Requests/sec:  41853.80

With default GOMAXPROCS, the difference was less pronounced. Nothing obvious to me in profiles. Will look further.

I took a stab at reproducing this just now, 1.14 vs 1.15tip, Linux, amd64, 12 processor box but GOMAXPROCS=1. 30 repetitions of 10 seconds of work:

( for i in {1..30} ; do wrk -c100 -d10 http://localhost:8114/hello; done; )  >& b114.log ; ( for i in {1..30} ; do wrk -c100 -d10 http://localhost:8115/hello; done; )  >& b115.log ;

Comparing averages, tip is 0.3% slower, comparing medians, 0.1% slower.

Got curious about what had changed since beta1, and noticed:

* 8b98498a58 net/http: make Transport.RoundTrip preserve Requests
* f84bbd52b0 cmd/compile: mark block control instruction unsafe in "all unsafe" functions

Benchmarked again at f84bbd5 (just before the change to net/http), and now it's 4% slower.

I will try the same experiment later today on a Mac laptop, once I am done using it for meetings.

I tried the comparison on a Mac laptop, Chrome and IDE shut down, but the numbers (30 repetitions of 10-second runs) were too noisy to be useful. I need to try again, very carefully, but I it would be nice if the bug filer could try tip and see if things look better, since (once!) they seemed better for me on Linux.

Thanks for looking @dr2chase. I can try reproducing this on a Mac laptop too.

it would be nice if the bug filer could try tip and see if things look better

@proyb6 Are you able to try again with the latest tip commit? (The gotip command may be convenient for this.)

FYI, I ran a second experiment on Linux (same machine, but this time using "perflock" for the benchmarked server).

perflock ./114 >& 114-run.log &
for j in {1..5} ; do ( for i in {1..25} ; do wrk -c100 -d5 http://localhost:8114/hello; done; )  >& b114-${j}.log ; done;
kill %1

perflock ./115 >& 115-run.log &
for j in {1..5} ; do ( for i in {1..25} ; do wrk -c100 -d5 http://localhost:8115/hello; done; )  >& b115-${j}.log ; done;
kill %1

perflock ./115-tip >& tip-run.log &
for j in {1..5}
kill %1

First, it looks like the bug is indeed reproducible against f84bbd5. Notice how there's not much difference among either group of 5, max/min is under 1%.

It also looks like the bug is fixed at tip, and also that there's more noise among the runs at tip (same numbers for 114). Note that I am taking maxs and mins of numbers that are already medians or averages, and I was using perflock, so this is a little interesting, maybe some service process woke up during the benchmarks.

That is, I believe the bug is consistently reproducible on my pretty-quiet (office-quarantined) deskside box, and it has also been fixed, most likely by the first commit after f84bbd5 but perhaps by a later one.

I reproduced this with results similar to what's posted above on a macOS laptop, and I don't have much new information to add. The difference between 1.14.4 and tip (3b2f67a) is very small compared to the variance of the micro benchmark, especially without artificial restrictions such as GOMAXPROCS=1, and I wasn't able to narrow it down further.

It seems to correlate to the various changes to net/http between 1.14 and tip (https://github.com/golang/go/commits/master/src/net/http), most of which were minor strictness/correctness improvements, and none were optimizations.

Perhaps someone else can narrow it down further or more conclusively, but I did not find an actionable issue here.

Any reason not to close this?

Closing for now. If there are still issues please feel free to comment and/or re-open.