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: Segfault when making request to specific URL #22376

Closed
cgt opened this issue Oct 21, 2017 · 16 comments
Closed

net/http: Segfault when making request to specific URL #22376

cgt opened this issue Oct 21, 2017 · 16 comments

Comments

@cgt
Copy link

cgt commented Oct 21, 2017

What did you do?

I made an HTTP HEAD request for https://www.gkogan.co/blog/dont-design-email. The program crashed. The following program reproduces the issue:

package main

import (
	"net/http"
	"net/url"
)

func main() {
	badURL, err := url.Parse("https://www.gkogan.co/blog/dont-design-emails")
	if err != nil {
		panic(err)
	}
	req, err := http.NewRequest("HEAD", badURL.String(), nil)
	if err != nil {
		panic(err)
	}
	_, err = http.DefaultClient.Do(req)
	if err != nil {
		panic(err)
	}
}

What did you expect to see?

The program should exit with no output.

What did you see instead?

$ go run minimal.go
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x30 pc=0x5bab30]

goroutine 12 [running]:
net/http.(*http2pipe).Write(0xc4203a2668, 0xc4201c19e0, 0x29, 0x8f, 0x0, 0x0, 0x0)
        /opt/go/src/net/http/h2_bundle.go:3661 +0x100
net/http.(*http2clientConnReadLoop).processData(0xc420159fb0, 0xc4201f2570, 0xc4201f2570, 0x0)
        /opt/go/src/net/http/h2_bundle.go:8259 +0x2ac
net/http.(*http2clientConnReadLoop).run(0xc420159fb0, 0x67ec38, 0xc4204677b0)
        /opt/go/src/net/http/h2_bundle.go:7896 +0x54f
net/http.(*http2ClientConn).readLoop(0xc42008ab60)
        /opt/go/src/net/http/h2_bundle.go:7788 +0x9d
created by net/http.(*http2Transport).newClientConn
        /opt/go/src/net/http/h2_bundle.go:7053 +0x6b9
exit status 2

More information

If I instead make a request to https://www.gkogan.co/blog/dont-design-emails/ (note the trailing slash) rather than https://www.gkogan.co/blog/dont-design-emails, the program does not crash.

I made another program which demonstrates this. See my gist at https://gist.github.com/cgt/bd14b8250eac6a7dc8a9830f5bb0bf85 which contains the program and its output.

I cannot reproduce the crash with any URL other than https://www.gkogan.co/blog/dont-design-email.

System details

go version go1.9.1 linux/amd64
GOARCH="amd64"
GOBIN="/home/cgt/dev/go/bin"
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/cgt/dev/go"
GORACE=""
GOROOT="/opt/go"
GOTOOLDIR="/opt/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build723076921=/tmp/go-build -gno-record-gcc-switches"
CXX="g++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOROOT/bin/go version: go version go1.9.1 linux/amd64
GOROOT/bin/go tool compile -V: compile version go1.9.1
uname -sr: Linux 4.13.7-1-cgt
/usr/lib/libc.so.6: GNU C Library (GNU libc) stable release version 2.26, by Roland McGrath et al.
gdb --version: GNU gdb (GDB) 8.0.1
@fraenkel
Copy link
Contributor

Using the same test case against HEAD (a31e0a4)
Running with http2debug=2 and -race, you get 2 SIGSEVs

[signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x6cbc0b]

goroutine 1 [running]:
net/http.(*http2ClientConn).RoundTrip.func1(0x0, 0x0, 0x0, 0x0, 0x5, 0x0)
	go/src/net/http/h2_bundle.go:7371 +0x35b
net/http.(*http2ClientConn).RoundTrip(0xc4201b2000, 0xc420130100, 0x0, 0x0, 0x0)
	go/src/net/http/h2_bundle.go:7402 +0x11e6
net/http.(*http2Transport).RoundTripOpt(0xc4200ac230, 0xc420130100, 0x431100, 0xc4200be900, 0x88, 0xc4200be988)
	go/src/net/http/h2_bundle.go:6871 +0x3be
net/http.(*http2Transport).RoundTrip(0xc4200ac230, 0xc420130100, 0x674fe4, 0xc420059820, 0xc4205043c0)
	go/src/net/http/h2_bundle.go:6833 +0x4c
net/http.http2noDialH2RoundTripper.RoundTrip(0xc4200ac230, 0xc420130100, 0xc4200a80f0, 0x5, 0xc4200be988)
	go/src/net/http/h2_bundle.go:991 +0x47
net/http.(*Transport).RoundTrip(0x8eff60, 0xc420130100, 0x8eff60, 0x0, 0x0)
	go/src/net/http/transport.go:371 +0x1192
net/http.send(0xc420130100, 0x79be60, 0x8eff60, 0x0, 0x0, 0x0, 0x46bf90, 0xc420059cc8, 0x46c1f2, 0xc42008ed60)
	go/src/net/http/client.go:249 +0x35c
net/http.(*Client).send(0x8f4a80, 0xc420130100, 0x0, 0x0, 0x0, 0xc42008ed60, 0x1, 0x2, 0x0)
	go/src/net/http/client.go:173 +0x1b1
net/http.(*Client).Do(0x8f4a80, 0xc420130000, 0xc4200a80f0, 0x2d, 0x0)
	go/src/net/http/client.go:612 +0x4de
main.main()
	test/src/example/test.go:17 +0x13b
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x28 pc=0x694e9c]

goroutine 13 [running]:
net/http.(*http2pipe).Write(0xc4200e4028, 0xc4203e6000, 0x29, 0x8f, 0x0, 0x0, 0x0)
	go/src/net/http/h2_bundle.go:3662 +0x14c
net/http.(*http2clientConnReadLoop).processData(0xc420537fb0, 0xc420504450, 0x1c, 0xc420537eb8)
	go/src/net/http/h2_bundle.go:8407 +0x3a5
net/http.(*http2clientConnReadLoop).run(0xc420537fb0, 0x778330, 0xc4200b57b0)
	go/src/net/http/h2_bundle.go:8025 +0x707
net/http.(*http2ClientConn).readLoop(0xc4201b2000)
	go/src/net/http/h2_bundle.go:7916 +0xf3
created by net/http.(*http2Transport).newClientConn
	go/src/net/http/h2_bundle.go:7100 +0xd72

@fraenkel
Copy link
Contributor

Doesn't appear to be reproducible anymore.

@odeke-em
Copy link
Member

Doesn't appear to be reproducible anymore.

@fraenkel I can consistently reproduce this as originally reported, even at tip e769c9d
screen shot 2017-10-21 at 7 59 22 pm

@fraenkel
Copy link
Contributor

A bit odd, I had to reboot in order to get the failures to occur again.

@odeke-em
Copy link
Member

Perhaps the author is changing the contents of that URL and actively switching the Netlify addresses because I got back to my hotel after dinner an hour ago, and now it 404s

$ curl -iL https://www.gkogan.co/blog/dont-design-email
HTTP/1.1 404 Not Found
Cache-Control: public, max-age=0, must-revalidate
Content-Type: text/html; charset=utf-8
Date: Sun, 22 Oct 2017 06:09:51 GMT
Etag: 1502484154-ssl
Age: 0
Transfer-Encoding: chunked
Connection: keep-alive
Server: Netlify

<!DOCTYPE html>
<html>
  <head>
    <meta charset="utf-8">

    <title>Page Not found</title>
    <link href='https://fonts.googleapis.com/css?family=Roboto:400,700&subset=latin,latin-ext' rel='stylesheet' type='text/css'>
    <style>
      * {
        -webkit-box-sizing: border-box;
           -moz-box-sizing: border-box;
            -ms-box-sizing: border-box;
                box-sizing: border-box;
      }
      body, html {
        height: 100%;
      }

      body {
        background: #f4f6f6;
        font-family: 'Roboto', sans-serif;
        color: #414546;
        display: flex;
        align-items: center;
        justify-content: center;
      }

      p {
        margin: 20px 0;
      }

      .panel {
        background: #eee;
        padding: 40px 60px;
        border-radius: 6px;
        width: 40em;
        margin: 50px auto;
        max-width: 100%;
      }

      a, a:link, a:active, a:visited {
        color: #00c7b7;
        text-decoration: none;
      }
      a:hover {
        text-decoration: underline;
      }
    </style>
  <script>
  (function(i,s,o,g,r,a,m){i['GoogleAnalyticsObject']=r;i[r]=i[r]||function(){
  (i[r].q=i[r].q||[]).push(arguments)},i[r].l=1*new Date();a=s.createElement(o),
  m=s.getElementsByTagName(o)[0];a.async=1;a.src=g;m.parentNode.insertBefore(a,m)
  })(window,document,'script','https://www.google-analytics.com/analytics.js','ga');

  ga('create', 'UA-253953-15', 'auto');
  ga('send', 'pageview');

</script></head>
  <body>

    <div class="main">
      <div class="panel">
        <div class="header">
          <h1>Page Not found</h1>
        </div>
        <div class="body">

          <p>Looks like you've followed a broken link or entered a URL that doesn't exist on this site.</p>

          <p>
            <a id="back-link" href="/">← Back to our site</a>
          </p>
        </div>
      </div>
    </div>
    <script>
      (function() {
        if (document.referrer && document.location.host && document.referrer.match(new RegExp("^https?://" + document.location.host))) {
          document.getElementById("back-link").setAttribute("href", document.referrer);
        }
      })();
    </script>
  </body>
</html>

However, I was able to capture the 301 response that caused it to break in the first place

package main

import (
	"bufio"
	"bytes"
	"flag"
	"fmt"
	"log"
	"net"
	"net/http"
)

func main() {
	var port int
	flag.IntVar(&port, "port", 8877, "the port to run on")
	flag.Parse()
	addr := fmt.Sprintf(":%d", port)
	ln, err := net.Listen("tcp", addr)
	if err != nil {
		log.Fatal(err)
	}
	for {
		conn, err := ln.Accept()
		if err == nil {
			go handleConn(conn)
		}
	}
}

var onRedirect = []byte(
	`HTTP/1.1 301 Moved Permanently
Cache-Control: public, max-age=0, must-revalidate
Date: Sun, 22 Oct 2017 04:32:22 GMT
Etag: "fc0674b76d7fc65eab9b07076c43b0e4-ssl"
Strict-Transport-Security: max-age=31536000
Content-Length: 0
Age: 3960
Connection: keep-alive
Server: Netlify
Location: /blog/dont-design-emails/
Content-Type: text/plain`)

var finalResponse = []byte(
	`HTTP/1.1 200 OK
Cache-Control: public, max-age=0, must-revalidate
Content-Type: text/html; charset=UTF-8
Date: Sun, 22 Oct 2017 04:32:23 GMT
Etag: "fc0674b76d7fc65eab9b07076c43b0e4-ssl"
Strict-Transport-Security: max-age=31536000
Age: 3960
Content-Length: 12
Connection: keep-alive
Server: Netlify` + "\r\n\r\nHello Gopher")

func handleConn(conn net.Conn) {
	in := make([]byte, 1024)
	n, err := conn.Read(in)
	if err != nil {
		return
	}
	in = in[:n]
	log.Printf("in: %q\n", in)
	req, err := http.ReadRequest(bufio.NewReader(bytes.NewReader(in)))
	if err != nil {
		return
	}
	data := onRedirect
	if req.URL.Path != "/" {
		data = finalResponse
	}
	conn.Write(data)
	conn.Close()
}

We'll need to put that behind self-signed TLS certs so that we take the HTTP/2 path as well.
/cc @tombergan

@odeke-em
Copy link
Member

odeke-em commented Oct 22, 2017

I got back to my hotel after a walk and I've written perhaps the closest repro to almost retrace the path taken, HTTP/2 server enabled, HTTP/2 transport but in vain. Repros at https://github.com/odeke-em/bugs/blob/master/golang/22376 and server in particular

package main

import (
	"flag"
	"fmt"
	"log"
	"net/http"
)

func main() {
	var port int
	var certFile, keyFile string

	flag.StringVar(&certFile, "cert", "cert.pem", "the certificate")
	flag.StringVar(&keyFile, "key", "key.pem", "the key file")
	flag.IntVar(&port, "port", 8877, "the port to run on")
	flag.Parse()

	addr := fmt.Sprintf(":%d", port)
	if err := http.ListenAndServeTLS(addr, certFile, keyFile, &handler{}); err != nil {
		log.Fatal(err)
	}
}

type handler struct{}

func (h *handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
	hdr := w.Header()
	if r.URL.Path == "/" {
		hdr.Set("Content-Type", "text/plain")
		hdr.Set("Age", "3960")
		hdr.Set("Connection", "keep-alive")
		hdr.Set("Date", "keep-alive")
		hdr.Set("Server", "Netlify")
		hdr.Set("Cache-Control", "public, max-age=0, must-revalidate")
		hdr.Set("Date", "Sun, 22 Oct 2017 04:32:22 GMT")
		if false && r.URL.RawPath == "" { // Can't seem to differentiate between localhost:8877 & localhost:8877/
			hdr.Set("Location", "/")
		} else {
			hdr.Set("Location", "/blog/dont-design-emails/")
		}
		w.WriteHeader(301)
	} else {
		hdr.Set("Cache-Control", "public, max-age=0, must-revalidate")
		hdr.Set("Content-Type", "text/html; charset=UTF-8")
		hdr.Set("Date", "Sun, 22 Oct 2017 04:32:23 GMT")
		hdr.Set("Age", "3960")
		hdr.Set("Connection", "keep-alive")
		hdr.Set("Server", "Netlify")
		fmt.Fprintf(w, "Hello Gopher")
	}
	w.(http.Flusher).Flush()
}

Perhaps @tombergan @fraenkel @bradfitz y'all might see something here?

@fraenkel
Copy link
Contributor

I captured the http2debug when it works and when it fails. It seems we are getting back slightly different responses.
The header lens have different size because the content-length is different.
But more importantly the data read after is completely different. I am surprised we read anything given its a HEAD request.

BAD response

2017/10/22 08:55:32 http2: Transport failed to get client conn for www.gkogan.co:443: http2: no cached connection was available
2017/10/22 08:55:32 http2: Transport creating client conn 0xc42008c1a0 to 104.198.56.15:443
2017/10/22 08:55:32 http2: Framer 0xc42015c000: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2017/10/22 08:55:32 http2: Framer 0xc42015c000: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2017/10/22 08:55:32 http2: Transport encoding header ":authority" = "www.gkogan.co"
2017/10/22 08:55:32 http2: Transport encoding header ":method" = "HEAD"
2017/10/22 08:55:32 http2: Transport encoding header ":path" = "/blog/dont-design-emails"
2017/10/22 08:55:32 http2: Transport encoding header ":scheme" = "https"
2017/10/22 08:55:32 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2017/10/22 08:55:32 http2: Framer 0xc42015c000: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=53
2017/10/22 08:55:32 http2: Framer 0xc42015c000: read SETTINGS len=12, settings: MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576
2017/10/22 08:55:32 http2: Transport received SETTINGS len=12, settings: MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576
2017/10/22 08:55:32 http2: Framer 0xc42015c000: wrote SETTINGS flags=ACK len=0
2017/10/22 08:55:32 http2: Framer 0xc42015c000: read WINDOW_UPDATE len=4 (conn) incr=983041
2017/10/22 08:55:32 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=983041
2017/10/22 08:55:33 http2: Framer 0xc42015c000: read SETTINGS flags=ACK len=0
2017/10/22 08:55:33 http2: Transport received SETTINGS flags=ACK len=0
2017/10/22 08:55:33 http2: Framer 0xc42015c000: read HEADERS flags=END_HEADERS stream=1 len=143
2017/10/22 08:55:33 http2: decoded hpack field header field ":status" = "301"
2017/10/22 08:55:33 http2: decoded hpack field header field "cache-control" = "public, max-age=0, must-revalidate"
2017/10/22 08:55:33 http2: decoded hpack field header field "date" = "Sun, 22 Oct 2017 12:55:33 GMT"
2017/10/22 08:55:33 http2: decoded hpack field header field "etag" = "\"fc0674b76d7fc65eab9b07076c43b0e4-ssl\""
2017/10/22 08:55:33 http2: decoded hpack field header field "strict-transport-security" = "max-age=31536000"
2017/10/22 08:55:33 http2: decoded hpack field header field "content-length" = "41"
2017/10/22 08:55:33 http2: decoded hpack field header field "age" = "0"
2017/10/22 08:55:33 http2: decoded hpack field header field "server" = "Netlify"
2017/10/22 08:55:33 http2: decoded hpack field header field "location" = "/blog/dont-design-emails/"
2017/10/22 08:55:33 http2: decoded hpack field header field "content-type" = "text/plain"
2017/10/22 08:55:33 http2: Transport received HEADERS flags=END_HEADERS stream=1 len=143
2017/10/22 08:55:33 http2: Framer 0xc42015c000: read DATA flags=END_STREAM stream=1 len=41 data="Redirecting to /blog/dont-design-emails/\n"
2017/10/22 08:55:33 http2: Transport received DATA flags=END_STREAM stream=1 len=41 data="Redirecting to /blog/dont-design-emails/\n"
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x30 pc=0x5bafd0]

goroutine 22 [running]:
net/http.(*http2pipe).Write(0xc4200b8028, 0xc420356000, 0x29, 0x8f, 0x0, 0x0, 0x0)
	/snap/go/922/src/net/http/h2_bundle.go:3661 +0x100
net/http.(*http2clientConnReadLoop).processData(0xc420053fb0, 0xc4201264b0, 0x1c, 0xc420053ec8)
	/snap/go/922/src/net/http/h2_bundle.go:8259 +0x2ac
net/http.(*http2clientConnReadLoop).run(0xc420053fb0, 0x67ec58, 0xc4204787b0)
	/snap/go/922/src/net/http/h2_bundle.go:7896 +0x54f
net/http.(*http2ClientConn).readLoop(0xc42008c1a0)
	/snap/go/922/src/net/http/h2_bundle.go:7788 +0x9d
created by net/http.(*http2Transport).newClientConn
	/snap/go/922/src/net/http/h2_bundle.go:7053 +0x6b9
exit status 2

GOOD

2017/10/22 08:07:30 http2: Transport failed to get client conn for www.gkogan.co:443: http2: no cached connection was available
2017/10/22 08:07:31 http2: Transport creating client conn 0xc42008c1a0 to 67.207.94.142:443
2017/10/22 08:07:31 http2: Framer 0xc42015c000: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2017/10/22 08:07:31 http2: Framer 0xc42015c000: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2017/10/22 08:07:31 http2: Transport encoding header ":authority" = "www.gkogan.co"
2017/10/22 08:07:31 http2: Transport encoding header ":method" = "HEAD"
2017/10/22 08:07:31 http2: Transport encoding header ":path" = "/blog/dont-design-emails"
2017/10/22 08:07:31 http2: Transport encoding header ":scheme" = "https"
2017/10/22 08:07:31 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2017/10/22 08:07:31 http2: Framer 0xc42015c000: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=53
2017/10/22 08:07:31 http2: Framer 0xc42015c000: read SETTINGS len=12, settings: MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576
2017/10/22 08:07:31 http2: Transport received SETTINGS len=12, settings: MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576
2017/10/22 08:07:31 http2: Framer 0xc42015c000: wrote SETTINGS flags=ACK len=0
2017/10/22 08:07:31 http2: Framer 0xc42015c000: read WINDOW_UPDATE len=4 (conn) incr=983041
2017/10/22 08:07:31 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=983041
2017/10/22 08:07:31 http2: Framer 0xc42015c000: read SETTINGS flags=ACK len=0
2017/10/22 08:07:31 http2: Transport received SETTINGS flags=ACK len=0
2017/10/22 08:07:31 http2: Framer 0xc42015c000: read HEADERS flags=END_HEADERS stream=1 len=147
2017/10/22 08:07:31 http2: decoded hpack field header field ":status" = "301"
2017/10/22 08:07:31 http2: decoded hpack field header field "cache-control" = "public, max-age=0, must-revalidate"
2017/10/22 08:07:31 http2: decoded hpack field header field "date" = "Sat, 21 Oct 2017 22:02:00 GMT"
2017/10/22 08:07:31 http2: decoded hpack field header field "etag" = "\"fc0674b76d7fc65eab9b07076c43b0e4-ssl\""
2017/10/22 08:07:31 http2: decoded hpack field header field "strict-transport-security" = "max-age=31536000"
2017/10/22 08:07:31 http2: decoded hpack field header field "age" = "50731"
2017/10/22 08:07:31 http2: decoded hpack field header field "content-length" = "13817"
2017/10/22 08:07:31 http2: decoded hpack field header field "server" = "Netlify"
2017/10/22 08:07:31 http2: decoded hpack field header field "location" = "/blog/dont-design-emails/"
2017/10/22 08:07:31 http2: decoded hpack field header field "content-type" = "text/plain"
2017/10/22 08:07:31 http2: Transport received HEADERS flags=END_HEADERS stream=1 len=147
2017/10/22 08:07:31 http2: Framer 0xc42015c000: read DATA flags=END_STREAM stream=1 len=0 data=""
2017/10/22 08:07:31 http2: Transport received DATA flags=END_STREAM stream=1 len=0 data=""
2017/10/22 08:07:31 http2: Transport encoding header ":authority" = "www.gkogan.co"
2017/10/22 08:07:31 http2: Transport encoding header ":method" = "HEAD"
2017/10/22 08:07:31 http2: Transport encoding header ":path" = "/blog/dont-design-emails/"
2017/10/22 08:07:31 http2: Transport encoding header ":scheme" = "https"
2017/10/22 08:07:31 http2: Transport encoding header "referer" = "https://www.gkogan.co/blog/dont-design-emails"
2017/10/22 08:07:31 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2017/10/22 08:07:31 http2: Framer 0xc42015c000: wrote HEADERS flags=END_STREAM|END_HEADERS stream=3 len=59
2017/10/22 08:07:31 http2: Framer 0xc42015c000: read HEADERS flags=END_HEADERS stream=3 len=56
2017/10/22 08:07:31 http2: decoded hpack field header field ":status" = "200"
2017/10/22 08:07:31 http2: decoded hpack field header field "cache-control" = "public, max-age=0, must-revalidate"
2017/10/22 08:07:31 http2: decoded hpack field header field "content-type" = "text/html; charset=UTF-8"
2017/10/22 08:07:31 http2: decoded hpack field header field "date" = "Sat, 21 Oct 2017 21:32:18 GMT"
2017/10/22 08:07:31 http2: decoded hpack field header field "etag" = "\"fc0674b76d7fc65eab9b07076c43b0e4-ssl\""
2017/10/22 08:07:31 http2: decoded hpack field header field "strict-transport-security" = "max-age=31536000"
2017/10/22 08:07:31 http2: decoded hpack field header field "age" = "52513"
2017/10/22 08:07:31 http2: decoded hpack field header field "content-length" = "13817"
2017/10/22 08:07:31 http2: decoded hpack field header field "server" = "Netlify"
2017/10/22 08:07:31 http2: Transport received HEADERS flags=END_HEADERS stream=3 len=56
2017/10/22 08:07:31 http2: Framer 0xc42015c000: read DATA flags=END_STREAM stream=3 len=0 data=""
2017/10/22 08:07:31 http2: Transport received DATA flags=END_STREAM stream=3 len=0 data=""

@artyom
Copy link
Member

artyom commented Oct 22, 2017

Some details in case this endpoint changes:

(this is for go version go1.9.2rc2 darwin/amd64)

If OP's program is run with GODEBUG=http2client=0, the following message is logged:

2017/10/22 17:57:11 Unsolicited response received on idle HTTP channel starting with "Redirecting to /blog/dont-design-emails/\n"; err=<nil>

If run with GODEBUG=http2debug=2:

2017/10/22 17:58:44 http2: Transport failed to get client conn for www.gkogan.co:443: http2: no cached connection was available
2017/10/22 17:58:45 http2: Transport creating client conn 0xc4200841a0 to 54.93.37.149:443
2017/10/22 17:58:45 http2: Framer 0xc420146000: wrote SETTINGS len=18, settings: ENABLE_PUSH=0, INITIAL_WINDOW_SIZE=4194304, MAX_HEADER_LIST_SIZE=10485760
2017/10/22 17:58:45 http2: Framer 0xc420146000: wrote WINDOW_UPDATE len=4 (conn) incr=1073741824
2017/10/22 17:58:45 http2: Transport encoding header ":authority" = "www.gkogan.co"
2017/10/22 17:58:45 http2: Transport encoding header ":method" = "HEAD"
2017/10/22 17:58:45 http2: Transport encoding header ":path" = "/blog/dont-design-emails"
2017/10/22 17:58:45 http2: Transport encoding header ":scheme" = "https"
2017/10/22 17:58:45 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2017/10/22 17:58:45 http2: Framer 0xc420146000: wrote HEADERS flags=END_STREAM|END_HEADERS stream=1 len=53
2017/10/22 17:58:45 http2: Framer 0xc420146000: read SETTINGS len=12, settings: MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576
2017/10/22 17:58:45 http2: Transport received SETTINGS len=12, settings: MAX_CONCURRENT_STREAMS=100, INITIAL_WINDOW_SIZE=1048576
2017/10/22 17:58:45 http2: Framer 0xc420146000: wrote SETTINGS flags=ACK len=0
2017/10/22 17:58:45 http2: Framer 0xc420146000: read WINDOW_UPDATE len=4 (conn) incr=983041
2017/10/22 17:58:45 http2: Transport received WINDOW_UPDATE len=4 (conn) incr=983041
2017/10/22 17:58:45 http2: Framer 0xc420146000: read SETTINGS flags=ACK len=0
2017/10/22 17:58:45 http2: Transport received SETTINGS flags=ACK len=0
2017/10/22 17:58:46 http2: Framer 0xc420146000: read HEADERS flags=END_HEADERS stream=1 len=143
2017/10/22 17:58:46 http2: decoded hpack field header field ":status" = "301"
2017/10/22 17:58:46 http2: decoded hpack field header field "cache-control" = "public, max-age=0, must-revalidate"
2017/10/22 17:58:46 http2: decoded hpack field header field "date" = "Sun, 22 Oct 2017 14:58:45 GMT"
2017/10/22 17:58:46 http2: decoded hpack field header field "etag" = "\"fc0674b76d7fc65eab9b07076c43b0e4-ssl\""
2017/10/22 17:58:46 http2: decoded hpack field header field "strict-transport-security" = "max-age=31536000"
2017/10/22 17:58:46 http2: decoded hpack field header field "content-length" = "41"
2017/10/22 17:58:46 http2: decoded hpack field header field "age" = "0"
2017/10/22 17:58:46 http2: decoded hpack field header field "server" = "Netlify"
2017/10/22 17:58:46 http2: decoded hpack field header field "location" = "/blog/dont-design-emails/"
2017/10/22 17:58:46 http2: decoded hpack field header field "content-type" = "text/plain"
2017/10/22 17:58:46 http2: Transport received HEADERS flags=END_HEADERS stream=1 len=143
2017/10/22 17:58:46 http2: Framer 0xc420146000: read DATA flags=END_STREAM stream=1 len=41 data="Redirecting to /blog/dont-design-emails/\n"
2017/10/22 17:58:46 http2: Transport received DATA flags=END_STREAM stream=1 len=41 data="Redirecting to /blog/dont-design-emails/\n"
2017/10/22 17:58:46 http2: Transport encoding header ":authority" = "www.gkogan.co"
2017/10/22 17:58:46 http2: Transport encoding header ":method" = "HEAD"
2017/10/22 17:58:46 http2: Transport encoding header ":path" = "/blog/dont-design-emails/"
2017/10/22 17:58:46 http2: Transport encoding header ":scheme" = "https"
2017/10/22 17:58:46 http2: Transport encoding header "referer" = "https://www.gkogan.co/blog/dont-design-emails"
2017/10/22 17:58:46 http2: Transport encoding header "user-agent" = "Go-http-client/2.0"
2017/10/22 17:58:46 http2: Framer 0xc420146000: wrote HEADERS flags=END_STREAM|END_HEADERS stream=3 len=59
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x30 pc=0x11baf90]

goroutine 51 [running]:
net/http.(*http2pipe).Write(0xc4200ac028, 0xc420436750, 0x29, 0x8f, 0x0, 0x0, 0x0)
	/Users/artyom/Library/go/src/net/http/h2_bundle.go:3661 +0x100
net/http.(*http2clientConnReadLoop).processData(0xc420049fb0, 0xc42040a390, 0x1c, 0xc420049ec8)
	/Users/artyom/Library/go/src/net/http/h2_bundle.go:8259 +0x2ac
net/http.(*http2clientConnReadLoop).run(0xc420049fb0, 0x127e370, 0xc4200277b0)
	/Users/artyom/Library/go/src/net/http/h2_bundle.go:7896 +0x54f
net/http.(*http2ClientConn).readLoop(0xc4200841a0)
	/Users/artyom/Library/go/src/net/http/h2_bundle.go:7788 +0x9d
created by net/http.(*http2Transport).newClientConn
	/Users/artyom/Library/go/src/net/http/h2_bundle.go:7053 +0x6b9
exit status 2

@tombergan
Copy link
Contributor

Thanks for the detailed http2debug logs. I'm pretty sure I know what's wrong and will fix it tomorrow if no one else gets there first.

Briefly: cs.bufPipe is nil when isHead but we don't check isHead in processData. Actually we should be treating isHead the same as if the HEADERS frame contained END_STREAM (here).

@gopherbot
Copy link

Change https://golang.org/cl/72551 mentions this issue: http2: Discard data reads on HEAD requests

@tombergan
Copy link
Contributor

Reopening: not fixed until I backport into net/http.

@tombergan tombergan reopened this Oct 23, 2017
@tombergan tombergan self-assigned this Oct 23, 2017
@gopherbot
Copy link

Change https://golang.org/cl/75210 mentions this issue: net/http: update bundled http2

@gopherbot
Copy link

Change https://golang.org/cl/88319 mentions this issue: [release-branch.go1.9] net/http: update bundled http2

@gopherbot
Copy link

Change https://golang.org/cl/88655 mentions this issue: http2: Discard data reads on HEAD requests

@gopherbot
Copy link

Change https://golang.org/cl/88675 mentions this issue: [release-branch.go1.9] net/http: update bundled http2

@gopherbot
Copy link

Change https://golang.org/cl/88676 mentions this issue: [release-branch.go1.9] net/http: update bundled http2

gopherbot pushed a commit to golang/net that referenced this issue Jan 20, 2018
If a server returns a DATA frame while procesing a HEAD request, the
client will discard the data.

Fixes golang/go#22376

Change-Id: Ief9c17ddfe51cc17f7f6326c87330ac9d8b9d3ff
Reviewed-on: https://go-review.googlesource.com/72551
Run-TryBot: Tom Bergan <tombergan@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Tom Bergan <tombergan@google.com>
Reviewed-on: https://go-review.googlesource.com/88655
Run-TryBot: Andrew Bonventre <andybons@golang.org>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
gopherbot pushed a commit that referenced this issue Jan 22, 2018
Updates http2 to x/net/http2 git rev 44b7c21 for

  http2: Discard data reads on HEAD requests
  https://golang.org/cl/88655

Fixes #22376

Change-Id: I931d9065d7309bc6d3f978bfe8cc6a9f940ce9e9
Reviewed-on: https://go-review.googlesource.com/88676
Run-TryBot: Andrew Bonventre <andybons@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Ian Lance Taylor <iant@golang.org>
c3mb0 pushed a commit to c3mb0/net that referenced this issue Apr 2, 2018
If a server returns a DATA frame while procesing a HEAD request, the
client will discard the data.

Fixes golang/go#22376

Change-Id: Ief9c17ddfe51cc17f7f6326c87330ac9d8b9d3ff
Reviewed-on: https://go-review.googlesource.com/72551
Run-TryBot: Tom Bergan <tombergan@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Tom Bergan <tombergan@google.com>
@golang golang locked and limited conversation to collaborators Jan 20, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

6 participants