Skip to content

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

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

Closed
dssysolyatin opened this issue Jun 18, 2019 · 3 comments
Closed

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

dssysolyatin opened this issue Jun 18, 2019 · 3 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@dssysolyatin
Copy link

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

Does anyone help me ?)

@andybons
Copy link
Member

@mikioh @bradfitz

@andybons andybons added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. Question labels Jun 28, 2019
@andybons andybons added this to the Unplanned milestone Jun 28, 2019
@andybons
Copy link
Member

Hi there,
We have decided that our experiment to allow questions on the issue tracker has not had the outcome we desired, so I am closing this issue. I'm sorry that we can't answer your question here.

There are many other methods to get help if you're still looking for answers:

Thanks

@golang golang locked and limited conversation to collaborators Aug 11, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

3 participants