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

x/net/http2: request.Body.Read hangs #32664

Open
dssysolyatin opened this issue Jun 18, 2019 · 2 comments

Comments

Projects
None yet
2 participants
@dssysolyatin
Copy link

commented Jun 18, 2019

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

$ go version
go version go1.12.1 linux/amd64

Does this issue reproduce with the latest release?

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

go env Output
$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/dmitry/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/dmitry/go"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
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 -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build879473706=/tmp/go-build -gno-record-gcc-switches"

What did you do?

One of http2 server handler reads file content from request body to a buffer. In order to limit of using memory I use https://github.com/facebookarchive/rpool library.
The code looks like this:

func (s *Server) HandleUpload(w http.ResponseWriter, r *http.Request, p httprouter.Params) {
    defer r.Body.Close()
    
    buf, err := s.rm.Acquire()
    defer s.rm.Release(buf)
    
    for {
        n, err := r.Body.Read(buf.(memu.ByteSlice))
        if err != nil && err != io.EOF {
            log.Print(err.Error())
        }
        doSomeActionWithBuffer(buf)
        if err != io.EOF {
            break
        }
    }
}

Handlers starts hang on r.Body.Read if there are handlers which hangs on s.rm.Acquire()

You can reproduce it with the following steps:

  1. Generate tls certificates: openssl req -newkey rsa:2048 -nodes -keyout server.key -x509 -days 365 -out server.crt
  2. Compile server.go, client.go
  3. Generate directory with 20 files with size 10 MB: ./generate.sh files
  4. Start server.go ./server
  5. Run client.go ./client --dir=$(pwd)/files --parallel=20

server.go:

package main

import (
	"io"
	"io/ioutil"
	"log"
	"net/http"
	"time"
)

type handler struct {
	gate chan struct{}
}

func NewHandler() *handler {
	return &handler{gate: make(chan struct{}, 5)}
}

func (h *handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
	defer r.Body.Close()

	h.gate <- struct{}{}
	defer func() { <-h.gate }()

	buf := make([]byte, 2*1024*1024)
	for {
		log.Printf("Start reading")
		n, err := r.Body.Read(buf)
		if err == io.EOF {
			break
		}

		if err != nil {
			log.Printf("Error %v", err)
			return
		}

		log.Printf("%d bytes is readed (error %v)", n, err)
		time.Sleep(1 * time.Second)
	}

	_, err := ioutil.ReadAll(r.Body)
	log.Printf("End read body (err: %v)", err)
}

func main() {
	srv := &http.Server{Addr: ":16999", Handler: NewHandler()}
	log.Fatal(srv.ListenAndServeTLS("server.crt", "server.key"))
}

client.go

package main

import (
	"context"
	"crypto/tls"
	"crypto/x509"
	"flag"
	"io/ioutil"
	"log"
	"net/http"
	"os"
	"os/signal"
	"path/filepath"

	"golang.org/x/net/http2"
	"golang.org/x/sync/errgroup"
)

const url = "https://localhost:16999"

var (
	dir      = flag.String("dir", "", "directory")
	parallel = flag.Int("parallel", 100, "parallel")
)

func initClient() *http.Client {
	client := &http.Client{}

	caCert, err := ioutil.ReadFile("server.crt")
	if err != nil {
		log.Fatalf("Reading server certificate: %s", err)
	}
	caCertPool := x509.NewCertPool()
	caCertPool.AppendCertsFromPEM(caCert)

	tlsConfig := &tls.Config{
		RootCAs: caCertPool,
	}

	client.Transport = &http2.Transport{
		TLSClientConfig: tlsConfig,
	}

	return client
}

func fileUpload(ctx context.Context, filepath string, client *http.Client) error {
	file, err := os.Open(filepath)
	if err != nil {
		return err
	}
	defer file.Close()

	req, err := http.NewRequest("POST", url, file)
	if err != nil {
		return err
	}
	req = req.WithContext(ctx)
	req.Header.Set("Content-Type", "binary/octet-stream")

	log.Printf("Start uploading file %s", filepath)
	res, err := client.Do(req)
	if err != nil {
		return err
	}
	defer res.Body.Close()

	log.Printf("File %s is uploaded", filepath)
	return nil
}

func startWorkers(ctx context.Context, jobs <-chan string, client *http.Client) *errgroup.Group {
	g, _ := errgroup.WithContext(ctx)
	for i := 0; i < *parallel; i++ {
		g.Go(func() error {
			for filepath := range jobs {
				if err := fileUpload(ctx, filepath, client); err != nil {
					return err
				}
			}

			return nil
		})
	}

	return g
}

func CtrlCContext(ctx context.Context) context.Context {
	c, cancel := context.WithCancel(ctx)
	signalCh := make(chan os.Signal, 1)
	signal.Notify(signalCh, os.Interrupt)
	go func() {
		select {
		case <-signalCh:
			cancel()
			return
		}
	}()
	return c
}

func main() {
	flag.Parse()

	client := initClient()
	jobs := make(chan string, *parallel*2)
	ctx := CtrlCContext(context.Background())
	g := startWorkers(ctx, jobs, client)

	err := filepath.Walk(*dir, func(path string, info os.FileInfo, err error) error {
		if info == nil {
			return nil
		}

		if info.IsDir() {
			return nil
		}

		select {
		case <-ctx.Done():
			return ctx.Err()
		case jobs <- path:
		}
		return nil
	})
	close(jobs)
	if err != nil {
		log.Fatal(err)
	}

	log.Fatal(g.Wait())
}

generate.sh

#!/bin/bash

mkdir -p $1
for n in {1..100}; do
    dd if=/dev/urandom of=${1}/file$( printf %03d "$n" ).bin bs=1M count=64
done

What did you expect to see?

I expect that r.Body.Read will not hang

What did you see instead?

r.Body.Read function hangs:

goroutine 38 [sync.Cond.Wait, 2 minutes]:
runtime.goparkunlock(...)
        /usr/local/go/src/runtime/proc.go:307
sync.runtime_notifyListWait(0xc000196198, 0x0)
        /usr/local/go/src/runtime/sema.go:510 +0xf9
sync.(*Cond).Wait(0xc000196188)
        /usr/local/go/src/sync/cond.go:56 +0x9e
net/http.(*http2pipe).Read(0xc000196180, 0xc0001e2000, 0x200000, 0x200000, 0x0, 0x0, 0x0)
        /usr/local/go/src/net/http/h2_bundle.go:3511 +0x8a
net/http.(*http2requestBody).Read(0xc00015a1e0, 0xc0001e2000, 0x200000, 0x200000, 0x0, 0x0, 0x0)
        /usr/local/go/src/net/http/h2_bundle.go:5814 +0xa0
main.(*handler).ServeHTTP(0xc000098020, 0x74e7e0, 0xc00014a008, 0xc000198100)
        /home/dmitry/go/src/github.com/http2hang/server.go:28 +0x1b4
net/http.serverHandler.ServeHTTP(0xc00008ed00, 0x74e7e0, 0xc00014a008, 0xc000198100)
        /usr/local/go/src/net/http/server.go:2774 +0xa8
net/http.initNPNRequest.ServeHTTP(0xc000062e00, 0xc00008ed00, 0x74e7e0, 0xc00014a008, 0xc000198100)
        /usr/local/go/src/net/http/server.go:3323 +0x8d
net/http.(*http2serverConn).runHandler(0xc000064d80, 0xc00014a008, 0xc000198100, 0xc000146040)
        /usr/local/go/src/net/http/h2_bundle.go:5658 +0x89
created by net/http.(*http2serverConn).processHeaders
        /usr/local/go/src/net/http/h2_bundle.go:5392 +0x4f4
@dssysolyatin

This comment has been minimized.

Copy link
Author

commented Jun 27, 2019

Does anyone help me ?)

@andybons

This comment has been minimized.

Copy link
Member

commented Jun 28, 2019

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.