x/net/http2: HTTP/2 slower than HTTP/1

[BentCoder]

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

$ go version
go version go1.13 darwin/amd64

Does this issue reproduce with the latest release?

Yes

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

macOS 10.12.6 - Darwin 16.7.0

Model Name: MacBook Pro
Processor Name: Intel Core i5-5257U
Processor Speed: 2.7 GHz
Number of Processors: 1
Total Number of Cores: 2
L2 Cache (per Core): 256 KB
L3 Cache: 3 MB
Memory: 16 GB

go env Output

$ go env
GO111MODULE="on"
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/myself/Library/Caches/go-build"
GOENV="/Users/myself/Library/Application Support/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/myself/Server/Go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/Cellar/go/1.13/libexec"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/Cellar/go/1.13/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/dev/null"
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/pr/g7230wl10mnf0fnqd6cc1_f80000gn/T/go-build968934789=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

I created a HTTP/2 client server app. When I use HTTP/1, it is average twice as fast as the HTTP/2 version! I am hoping that it is me (I bet it is me) doing something wrong but cannot be sure because the resources/examples I found seem to be doing things in same way as I do so I've run out of options.

What did you expect to see?

HTTP/2 request/response should be faster than the HTTP/1 version.

What did you see instead?

HTTP/1 request/response is faster than the HTTP/2 version. 702.225996ms vs 1.3265715s

Server app

package main

import (
	"crypto/tls"
	"fmt"
	"io/ioutil"
	"log"
	"net/http"
	"time"
)

func main() {
	server := &http.Server{
		Addr:         ":8443",
		ReadTimeout:  5 * time.Second,
		WriteTimeout: 10 * time.Second,
		TLSConfig:    tlsConfig(),
	}

	//// Having this doesn't change anything and not sure if I should use it either.
	//if err := http2.ConfigureServer(server, nil); err != nil {
	//	log.Fatal(err)
	//}

	http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
		w.Write([]byte(fmt.Sprintf("Protocol: %s", r.Proto)))
	})

	if err := server.ListenAndServeTLS("", ""); err != nil {
		log.Fatal(err)
	}
}

func tlsConfig() *tls.Config {
	crt, err := ioutil.ReadFile("./cert/public.crt")
	if err != nil {
		log.Fatal(err)
	}

	key, err := ioutil.ReadFile("./cert/private.key")
	if err != nil {
		log.Fatal(err)
	}

	cert, err := tls.X509KeyPair(crt, key)
	if err != nil {
		log.Fatal(err)
	}

	return &tls.Config{
		Certificates: []tls.Certificate{cert},
	}
}

Client app

package main

import (
	"crypto/tls"
	"crypto/x509"
	"fmt"
	"golang.org/x/net/http2"
	"io/ioutil"
	"log"
	"net/http"
	"time"
)

func main() {
	now := time.Now()
	defer func() {
		fmt.Println(time.Since(now))
	}()

	client := &http.Client{Transport: transport()}

	for i := 0; i < 1000; i++ {
		res, err := client.Get("https://localhost:8443")
		if err != nil {
			log.Fatal(err)
		}

		body, err := ioutil.ReadAll(res.Body)
		if err != nil {
			log.Fatal(err)
		}

		res.Body.Close()

		fmt.Printf("Body: %s\n", body)
	}
}

func transport() *http2.Transport {
	return &http2.Transport{
		TLSClientConfig:     tlsConfig(),
		DisableCompression:  true,
		AllowHTTP:           false,
	}
}

func tlsConfig() *tls.Config {
	crt, err := ioutil.ReadFile("./cert/public.crt")
	if err != nil {
		log.Fatal(err)
	}

	rootCAs := x509.NewCertPool()
	rootCAs.AppendCertsFromPEM(crt)

	return &tls.Config{
		RootCAs:            rootCAs,
		InsecureSkipVerify: false,
	}
}

I also tried with transport below instead of golang.org/x/net/http2 as shown above but the result is same.

func transport() *http.Transport {
	return &http.Transport{
		DialContext: (&net.Dialer{
			Timeout:   30 * time.Second,
			KeepAlive: 30 * time.Second,
		}).DialContext,
		ForceAttemptHTTP2:     true,
		MaxIdleConns:          100,
		IdleConnTimeout:       90 * time.Second,
		TLSHandshakeTimeout:   10 * time.Second,
		ExpectContinueTimeout: 1 * time.Second, //
		ResponseHeaderTimeout: 10 * time.Second,
		DisableCompression:    true,
		DisableKeepAlives:     false,
		TLSClientConfig:       tlsConfig(),
	}
}

[seankhliao]

the times appear consistent with TLS requiring 1 RTT to negotiate a new stream per request. The speed benefits of HTTP/2 come from parallel streams and bulk data transfers, not the initial connection times.

[BentCoder]

@seankhliao Thanks for the response. So what you are saying is, there is nothing wrong with the example I am using above. Is that correct?

[seankhliao]

yes

[toothrot]

The difference between http1 and http2 clients doing 1000 serial requests on my netbook, using your code, is much less pronounced: ~90ms total for http 1, and ~104ms total for http2. I am not sure what this microbenchmark teaches me, though.

/cc @bradfitz