x/net/http2/h2c: upgrade fails with request body

[suiriass]

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

$ go version
1.14.1

Does this issue reproduce with the latest release?

Yes

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

go env Output

$ go env
set GO111MODULE=on
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\simms.shi\AppData\Local\go-build
set GOENV=C:\Users\simms.shi\AppData\Roaming\go\env
set GOEXE=.exe
set GOFLAGS= -mod=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GONOPROXY=code.aliyun.com
set GONOSUMDB=code.aliyun.com
set GOOS=windows
set GOPATH=C:\Users\simms.shi\go
set GOPRIVATE=code.aliyun.com
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=C:\Go
set GOSUMDB=off
set GOTMPDIR=
set GOTOOLDIR=C:\Go\pkg\tool\windows_amd64
set GCCGO=gccgo
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=D:\gowork\fabio-esb-agent\fabio\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 -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=C:\Users\simms.shi\AppData\Local\Temp\go-build693576242=/tmp/go-build -gno-record-gcc-switc
hes

What did you do?

// ex: https://godoc.org/golang.org/x/net/http2/h2c
golang.org/x/net v0.0.0-20181114220301-adae6a3d119a

func HTTP2CServer(l config.Listen, h http.Handler, cfg *tls.Config) *http.Server {
	return &http.Server{
		Addr: l.Addr,
		//Handler:      h,
		Handler:      h2c.NewHandler(h, &http2.Server{}),
		ReadTimeout:  l.ReadTimeout,
		WriteTimeout: l.WriteTimeout,
		TLSConfig:    cfg,
	}
}

I created a server(h2c) as per the above，

java11 code

import java.io.IOException;
import java.net.URI;
import java.net.http.HttpClient;
import java.net.http.HttpRequest;
import java.net.http.HttpResponse;
import java.nio.charset.StandardCharsets;
import java.time.Duration;


public class MainH2 {
   public static void main(String[] args) throws IOException, InterruptedException {
   	//1.set connect timeout
   	HttpClient client = HttpClient.newBuilder()
   		.version(HttpClient.Version.HTTP_2)
   		.connectTimeout(Duration.ofMillis(50000))
   		.followRedirects(HttpClient.Redirect.NORMAL)
   		.build();

   	//2.set read timeout
   	HttpRequest request = HttpRequest.newBuilder()
//			.GET()
   		.POST(HttpRequest.BodyPublishers.ofString("{\"yearMonth\":\"2019-12\"}", StandardCharsets.UTF_8))
   		.uri(URI.create("http://127.0.0.1:9999/xxxx/month/amount/pie"))
   		.header("Content-Type", "application/json")
   		.timeout(Duration.ofMillis(50009))
   		.build();

   	HttpResponse<String> response =
   		client.send(request, HttpResponse.BodyHandlers.ofString());
   	System.out.println(response.version());
   	System.out.println(response.statusCode());
   	System.out.println(response.body());
   }

}

What did you expect to see?

I tried using the latest version of net/http2/h2c and The problem is the same，
H2c server is expected to work properly in the case of the post method.
thank you very much.

What did you see instead?

This client works correctly if it accesses Java's undertow server， not work if it accesses go's h2c server，
Error message source call chain:
(ServeHTTP>h2cUpgrade>drainClientPreface)
golang.org/x/net/http2/h2c/h2c.go

[return fmt.Errorf("Client never sent: %s", http2.ClientPreface)], but The Get method is correct

Analyze TCP messages and discover that the location of http2.ClientPreface(PRI * HTTP/2.0...) may not conform to the go's rules

[andybons]

@bradfitz @tombergan

[rakheshkumbi]

Any updates on this issue?

[nussjustin]

This looks like a bug in the x/net/http2/h2c package.

From RFC 7540 section 3.2:

Requests that contain a payload body MUST be sent in their entirety
before the client can send HTTP/2 frames. This means that a large
request can block the use of the connection until it is completely
sent.

and

Upon receiving the 101 response, the client MUST send a connection
preface (Section 3.5), which includes a SETTINGS frame.

The specified behavior (which is also how the Java client seems to behave, based on the screenshots in the issue description) can be seen by using something like nc to listen on a local port and curl with the --http2 flag and -d for sending the request. For example:

$ curl -d hello=world --http2 http://127.0.0.1:12345

and in another shell

$ nc -l 12345
POST / HTTP/1.1
Host: 127.0.0.1:12345
User-Agent: curl/7.66.0
Accept: */*
Connection: Upgrade, HTTP2-Settings
Upgrade: h2c
HTTP2-Settings: AAMAAABkAARAAAAAAAIAAAAA
Content-Length: 11
Content-Type: application/x-www-form-urlencoded

hello=world

At this point curl will wait for the response. To respond it's enough to send the following to curl (including the multiple line breaks at the end):

HTTP/1.1 101 Switching Protocols
Connection: Upgrade
Upgrade: h2c

Once the response was send, curl will continue speaking HTTP/2

PRI * HTTP/2.0

SM

d?

The reason the x/net/http2/h2c handler fails is that the h2cUpgrade function doesn't read the body of the original request and assumes that the next thing after the initial request headers is the HTTP 2 preface, but since the body of the initial request comes before the preface, the upgrade fails.

I think the correct way to fix this would be to just handle the initial request before hijacking the connection, by passing it to the wrapped http.Handler, but there are probably some other problems with that which I can't think of right now.

[networkimprov]

cc @fraenkel

[fraenkel]

Can someone provide a test case?

[networkimprov]

cc @rakheshkumbi

[seankhliao]

using curl:

package main

import (
	"fmt"
	"net/http"
	"os"
	"os/exec"

	"golang.org/x/net/http2"
	"golang.org/x/net/http2/h2c"
)

func main() {
	H2CUpgrade()
}

func H2CUpgrade() {
	h2s := &http2.Server{}

	handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		fmt.Fprintf(w, "Hello, %v, http: %v", r.URL.Path, r.TLS == nil)
	})

	server := &http.Server{
		Addr:    "0.0.0.0:8090",
		Handler: h2c.NewHandler(handler, h2s),
	}

	go func() {
		fmt.Printf("Listening [0.0.0.0:8090]...\n")
		server.ListenAndServe()
	}()

	cmd := exec.Command("curl", "-d", "hello=world", "--http2", "http://127.0.0.1:8090")
	cmd.Stdout = os.Stdout
	cmd.Stderr = os.Stderr
	fmt.Println(cmd.Run())
}

outputs and hangs indefinitely

go run .
Listening [0.0.0.0:8090]...
2021/01/27 12:21:32 http: response.Write on hijacked connection from fmt.Fprintf (print.go:205)

[fraenkel]

This uncovered a few issues.

1. When the upgrade fails internally with an error, the h2c stack just goes on its merry way.
2. The actual issue here is that the body of the original request is not consumed and is instead left behind which causes issue 1 above that is hidden.

The body of the original request is being munged with the client preface,hello=worldPRI * HTTP/2.
Internally the h2c handler flows and error, Client never sent: PRI * HTTP/2.0 which is being ignored.

[gopherbot]

Change https://golang.org/cl/288572 mentions this issue: http2/h2c: Read body during upgrade

[AlexanderYastrebov]

A related problem exists with GET requests. If handler attempts to read out the body it will hang:

package main

import (
	"fmt"
	"net/http"
	"os"
	"io"
	"os/exec"

	"golang.org/x/net/http2"
	"golang.org/x/net/http2/h2c"
)

func main() {
	H2CUpgrade()
}

func H2CUpgrade() {
	h2s := &http2.Server{}

	handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		fmt.Printf("proto: %v, content-length: %v\n", r.Proto, r.ContentLength)
		io.Copy(io.Discard, r.Body)
	})

	server := &http.Server{
		Addr:    "0.0.0.0:8090",
		Handler: h2c.NewHandler(handler, h2s),
	}

	go func() {
		fmt.Printf("Listening [0.0.0.0:8090]...\n")
		server.ListenAndServe()
	}()

	cmd := exec.Command("curl", "--http2", "http://127.0.0.1:8090")
	cmd.Stdout = os.Stdout
	cmd.Stderr = os.Stderr
	fmt.Println(cmd.Run())
}

Running with --http2-prior-knowledge works ok.

Also I think the approach https://golang.org/cl/288572 is not correct - it attempts to throw away request body while it should be properly encoded similar to the request headers and passed to the handler.

[AlexanderYastrebov]

I think this was closed without a fix

[seankhliao]

I think this was fixed with #52882 ?