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

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

Open
wgplt opened this issue Jan 28, 2021 · 12 comments
Open

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

wgplt opened this issue Jan 28, 2021 · 12 comments

Comments

@wgplt
Copy link

@wgplt wgplt commented Jan 28, 2021

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
@seankhliao seankhliao changed the title HTTP Packet “net/http.(*http2pipe).closeWithError” Crashed net/http: (*http2pipe).closeWithError” Crashed Jan 28, 2021
@bcmills
Copy link
Member

@bcmills bcmills commented Jan 28, 2021

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

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':

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:

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)

@bcmills bcmills added this to the Backlog milestone Jan 28, 2021
@fraenkel
Copy link
Contributor

@fraenkel fraenkel commented Jan 28, 2021

@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
Copy link
Author

@wgplt wgplt commented Feb 1, 2021

@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
Copy link
Contributor

@davecheney davecheney commented Feb 1, 2021

@wgplt can you provide more details?

@wgplt
Copy link
Author

@wgplt wgplt commented Feb 22, 2021

@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
Copy link
Contributor

@fraenkel fraenkel commented Feb 22, 2021

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
Copy link
Author

@wgplt wgplt commented Feb 23, 2021

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
Copy link

@3lixy 3lixy commented Jun 23, 2021

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
Copy link
Contributor

@fraenkel fraenkel commented Jun 24, 2021

@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
Copy link

@gopherbot gopherbot commented Jun 24, 2021

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

@yusong0926
Copy link

@yusong0926 yusong0926 commented Jun 28, 2021

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

@ianlancetaylor
Copy link
Contributor

@ianlancetaylor ianlancetaylor commented Jun 28, 2021

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
9 participants