net/http: (*http2pipe).closeWithError” Crashed

[wgplt]

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

$ go version 
1.15.4-1.15.7

Does this issue reproduce with the latest release?

1.15.7

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

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/test/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/test/go/"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/lib/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-I/home/db2inst2/sqllib/include"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-L/home/db2inst2/sqllib/lib"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build439006933=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I used a common "http.Transport" object for every “http.Client”，bug after running for a while ，the program crashes and the output error message is as follows。

panic: runtime error: invalid memory address or nil pointer dereference
        panic: err must be non-nil
[signal SIGSEGV: segmentation violation code=0x1 addr=0x28 pc=0x6ae0ea]

goroutine 4011 [running]:
net/http.(*http2pipe).closeWithError(0xc00084fe68, 0xc00084fec0, 0x0, 0x0, 0x0)
        /usr/lib/go/src/net/http/h2_bundle.go:3558 +0x247
net/http.(*http2pipe).CloseWithError(...)
        /usr/lib/go/src/net/http/h2_bundle.go:3545
net/http.(*http2clientConnReadLoop).cleanup(0xc000a8cfa8)
        /usr/lib/go/src/net/http/h2_bundle.go:8233 +0x294
panic(0x80de40, 0xd4f050)
        /usr/lib/go/src/runtime/panic.go:969 +0x1b9
net/http.(*http2pipe).Write(0xc000a80028, 0xc000a18300, 0x1c, 0x55, 0x0, 0x0, 0x0)
        /usr/lib/go/src/net/http/h2_bundle.go:3537 +0x10a
net/http.(*http2clientConnReadLoop).processData(0xc001199fa8, 0xc000634720, 0xc000634720, 0x0)
        /usr/lib/go/src/net/http/h2_bundle.go:8706 +0x325
net/http.(*http2clientConnReadLoop).run(0xc001199fa8, 0xc0010f67b0, 0x6ddaa5)
        /usr/lib/go/src/net/http/h2_bundle.go:8286 +0x52a
net/http.(*http2ClientConn).readLoop(0xc000b54780)
        /usr/lib/go/src/net/http/h2_bundle.go:8179 +0x6f
created by net/http.(*http2Transport).newClientConn
        /usr/lib/go/src/net/http/h2_bundle.go:7175 +0x685

my codes like this:

common.HttpTransport = &http.Transport{
TLSClientConfig: &tls.Config{InsecureSkipVerify: true},
MaxIdleConns: 100,
MaxIdleConnsPerHost: 100,
IdleConnTimeout: 60 * time.Second,
DisableKeepAlives: false,

Dial: func(netw, addr string) (net.Conn, error) {
	deadline := time.Now().Add(90 * time.Second)
	c, err := net.DialTimeout(netw, addr, time.Second*45)
	if err != nil {
		return nil, err
	}
	c.SetDeadline(deadline) 
	return c, nil
}, 
ForceAttemptHTTP2:     true,
TLSHandshakeTimeout:   12 * time.Second,
ResponseHeaderTimeout: 12 * time.Second, 
ExpectContinueTimeout: 1 * time.Second,
DisableCompression:    true, 
}

var (
	client      *http.Client
)
client = &http.Client{
	Transport: common.HttpTransport,
}
client.Timeout = time.Duration(50) * time.Second
req, err := http.NewRequest("GET", URL, nil)
if err != nil {
	return false
}
req.Header.Add("Accept", "text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8")
resp, err := client.Do(req)
if err != nil {
	if resp != nil {
		if resp.Body != nil {
			io.Copy(ioutil.Discard, resp.Body) 
			resp.Body.Close()
		}
	}
	return false
}
defer func() {
	io.Copy(ioutil.Discard, resp.Body)
	resp.Body.Close()
}()

What did you expect to see?

What did you see instead?

panic: runtime error: invalid memory address or nil pointer dereference
        panic: err must be non-nil
[signal SIGSEGV: segmentation violation code=0x1 addr=0x28 pc=0x6ae0ea]

goroutine 4011 [running]:
net/http.(*http2pipe).closeWithError(0xc00084fe68, 0xc00084fec0, 0x0, 0x0, 0x0)
        /usr/lib/go/src/net/http/h2_bundle.go:3558 +0x247
net/http.(*http2pipe).CloseWithError(...)
        /usr/lib/go/src/net/http/h2_bundle.go:3545
net/http.(*http2clientConnReadLoop).cleanup(0xc000a8cfa8)
        /usr/lib/go/src/net/http/h2_bundle.go:8233 +0x294
panic(0x80de40, 0xd4f050)
        /usr/lib/go/src/runtime/panic.go:969 +0x1b9
net/http.(*http2pipe).Write(0xc000a80028, 0xc000a18300, 0x1c, 0x55, 0x0, 0x0, 0x0)
        /usr/lib/go/src/net/http/h2_bundle.go:3537 +0x10a
net/http.(*http2clientConnReadLoop).processData(0xc001199fa8, 0xc000634720, 0xc000634720, 0x0)
        /usr/lib/go/src/net/http/h2_bundle.go:8706 +0x325
net/http.(*http2clientConnReadLoop).run(0xc001199fa8, 0xc0010f67b0, 0x6ddaa5)
        /usr/lib/go/src/net/http/h2_bundle.go:8286 +0x52a
net/http.(*http2ClientConn).readLoop(0xc000b54780)
        /usr/lib/go/src/net/http/h2_bundle.go:8179 +0x6f
created by net/http.(*http2Transport).newClientConn
        /usr/lib/go/src/net/http/h2_bundle.go:7175 +0x685

[bcmills]

The err must be non-nil panic is on this line:

go/src/net/http/h2_bundle.go

Line 3558 in 2117ea9

panic("err must be non-nil")

The question is, where does the panic: runtime error: invalid memory address or nil pointer dereference come from? I think that's the one at `h2_bundle.go:3537':

go/src/net/http/h2_bundle.go

Line 3537 in 2117ea9

return p.b.Write(d)

At that point we know that p is non-nil, or else p.mu.Lock() would have panicked at line 3524. So it must be the case that p.b is nil.

The comment for that field says:

go/src/net/http/h2_bundle.go

Line 3469 in 2117ea9

b http2pipeBuffer // nil when done reading

That behavior is implemented here:

go/src/net/http/h2_bundle.go

Lines 3507 to 3514 in 2117ea9

	if p.err != nil {
	if p.readFn != nil {
	p.readFn() // e.g. copy trailers
	p.readFn = nil // not sticky like p.err
	}
	p.b = nil
	return 0, p.err
	}

So the question is: what is calling Read on the *http2pipe, and how is that intended to synchronize with the Write call?

(CC @bradfitz @tombergan @neild @empijei @fraenkel)

[fraenkel]

@bcmills Why does it matter? There are only 2 places where p.b = nil occurs. In Read(), but the guarantee is p.err is non nil or during closeWithError() which will set p.breakErr non nil.
In either case a Write() will never reach p.b.Write() if either err or breakErr is set.
Unless there is memory corruption, I don't see how this is possible. Or am I missing something more obvious?

@wgplt Have you run your program with race detection enabled?

[wgplt]

@bcmills Why does it matter? There are only 2 places where p.b = nil occurs. In Read(), but the guarantee is p.err is non nil or during closeWithError() which will set p.breakErr non nil.
In either case a Write() will never reach p.b.Write() if either err or breakErr is set.
Unless there is memory corruption, I don't see how this is possible. Or am I missing something more obvious?

@wgplt Have you run your program with race detection enabled?

I run my program with race detection enabled，sometimes it can reappear, sometimes it can't!

[davecheney]

@wgplt can you provide more details?

[wgplt]

@wgplt can you provide more details?

@davecheney @fraenkel @bcmills @seankhliao

I found out why the program crashed because the website I requested returned the following response:

`HTTP/1.1 100001
Server: nginx/1.12.2
Date: Mon, 22 Feb 2021 03:27:06 GMT
Content-Type: application/json; charset=utf-8
Connection: close
X-Powered-By: PHP/5.5.38
Set-Cookie: PHPSESSID=e9bthjpj2gu8cgqohhfeo2j8r2; path=/
Expires: Thu, 19 Nov 1981 08:52:00 GMT
Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
Pragma: no-cache

`
This site does not return a standard HTTP response header and has no response body.

[fraenkel]

There has to be more than this. The fact that your panic was in processData means we saw a data frame. There is no way for the http2 stack to process the above as something remotely valid.
I am just trying to understand how the above causes the panic given there was an http2 negotiation and we received enough detail that a DATA frame is coming.

Do you have any more of the actual wire flow?

[wgplt]

There has to be more than this. The fact that your panic was in processData means we saw a data frame. There is no way for the http2 stack to process the above as something remotely valid.
I am just trying to understand how the above causes the panic given there was an http2 negotiation and we received enough detail that a DATA frame is coming.

Do you have any more of the actual wire flow?

The test code is as follows：

`// test project main.go
package main

import (
"crypto/tls"
"net/http"
)

func main() {
GET("https://xxxx.com/")
}

func GET(URL string) {
var (
client *http.Client
)
client = &http.Client{
Transport: &http.Transport{
TLSClientConfig: &tls.Config{InsecureSkipVerify: true},
ForceAttemptHTTP2: true, //The crash caused by this parameter
},
}
req, err := http.NewRequest("GET", URL, nil)
if err != nil {
return
}
client.Do(req)
}
`

[3lixy]

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

1.15.7
1.15.13
1.16.5

Does this issue reproduce with the latest release?
Yes 1.16.5

What operating system and processor architecture are you using (go env)?
Windows 10 amd64 (dev machine) and FreeBSD 12.2 amd64 (server)

go env

set GO111MODULE=on
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\Luke\AppData\Local\go-build
set GOENV=C:\Users\Luke\AppData\Roaming\go\env
set GOEXE=.exe
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=C:\Users\Luke\go\pkg\mod
set GONOPROXY=github.com/cyber-inspector/*
set GONOSUMDB=github.com/cyber-inspector/*
set GOOS=windows
set GOPATH=C:\Users\Luke\go
set GOPRIVATE=github.com/cyber-inspector/*
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=C:\Users\Luke\GoLangProjects\custom_god\go1.16.5
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=C:\Users\Luke\GoLangProjects\custom_god\go1.16.5\pkg\tool\windows_amd64
set GOVCS=
set GOVERSION=go1.16.5
set GCCGO=gccgo
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=C:\Users\Luke\GoLangProjects\play\go.mod
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -fmessage-length=0 -fdebug-prefix-map=C:\Users\Luke\AppData\Local\Temp\go-build1196881057=/tmp/go-build -gno-record-gcc-switches

What did you do?

package main

import "net/http"

func main() {
	http.Get("http://litevault.net")
}

and got

panic: runtime error: invalid memory address or nil pointer dereference
        panic: err must be non-nil
[signal 0xc0000005 code=0x0 addr=0x28 pc=0xea2bad]

goroutine 40 [running]:
net/http.(*http2pipe).closeWithError(0xc00020c708, 0xc00020c760, 0x0, 0x0, 0x0)
        net/http/h2_bundle.go:3558 +0x245
net/http.(*http2pipe).CloseWithError(...)
        net/http/h2_bundle.go:3545
net/http.(*http2clientConnReadLoop).cleanup(0xc000051fa8)
        net/http/h2_bundle.go:8298 +0x2d4
panic(0xf0a360, 0x10e4470)
        runtime/panic.go:965 +0x1c7
net/http.(*http2pipe).Write(0xc00020c708, 0xc000162000, 0x1fe7, 0x1fe7, 0x0, 0x0, 0x0)
        net/http/h2_bundle.go:3537 +0x10d
net/http.(*http2clientConnReadLoop).processData(0xc000051fa8, 0xc000072ff0, 0xc000072ff0, 0x0)
        net/http/h2_bundle.go:8780 +0x325
net/http.(*http2clientConnReadLoop).run(0xc000051fa8, 0x0, 0x0)
        net/http/h2_bundle.go:8360 +0x60b
net/http.(*http2ClientConn).readLoop(0xc000228600)
        net/http/h2_bundle.go:8244 +0x76
created by net/http.(*http2Transport).newClientConn
        net/http/h2_bundle.go:7208 +0x6c5
exit status 2

Hi I have come across a site that does this issue here each time. I have no idea what this site is as it does not even load in chrome or curl, due to I assume the same issue go is seeing. litevault.net Please DO NOT visit this site in a browser as I cannot say to its purpose. I came across this site as it was in this list https://tranco-list.eu/top-1m.csv.zip.

Curl shows this.

* TCP_NODELAY set
* Connected to litevault.net (206.189.19.107) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server accepted to use h2
* Server certificate:
*  subject: CN=litevault.net
*  start date: May 13 23:24:20 2021 GMT
*  expire date: Aug 11 23:24:20 2021 GMT
*  subjectAltName: host "litevault.net" matched cert's "litevault.net"
*  issuer: C=US; O=Let's Encrypt; CN=R3
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x7fffd9555e80)
> GET / HTTP/1.1
> Host: litevault.net
> User-Agent: curl/7.52.1
> Accept: */*
>
* Connection state changed (MAX_CONCURRENT_STREAMS updated)!
< HTTP/2 100
< server: nginx/1.10.3 (Ubuntu)
< date: Wed, 23 Jun 2021 18:55:45 GMT
* HTTP/2 stream 1 was not closed cleanly: PROTOCOL_ERROR (err 1)
* Curl_http_done: called premature == 1
* Closing connection 0
* TLSv1.2 (OUT), TLS alert, Client hello (1):
curl: (92) HTTP/2 stream 1 was not closed cleanly: PROTOCOL_ERROR (err 1)

Any ideas how to cope with this scenario without causing a panic. For now I have put this site on a skip list.

[fraenkel]

@3lixy Thanks for the reproducer.
The issue is that we aren't setting up the pipe when a 100 status code is returned. When the DATA shows up which is unexpected, things blow up.

[gopherbot]

Change https://golang.org/cl/330415 mentions this issue: http2: prevent processing DATA before HEADERS

[yusong0926]

just wondering when this fix will be merged to master branch?

[ianlancetaylor]

@yusong0926 The patch is still under review. We can't make a prediction yet. Sorry.