Skip to content

Mget May Cause Goroutine Leak #250

Closed
@Bars92

Description

@Bars92

Bug Description
mget request which is implemented as a GET request with body may cause go routine leaks when golang delays reading the body under golang open issue golang/go#29246. Once the issue occurs, the request will never end thus keeping the go-routine and connection stuck.

Reproduction
By using a simple program it is possible to reproduce the bug. The program will run 100 go-routines attempting to create/update a document in half of them (to generate traffic), and in the other half run MGET request on the first document:

package main

import (
	"context"
	"fmt"
	"net/http"
	_ "net/http/pprof"
	"net/url"
	"os"
	"strconv"
	"sync"
	"time"

	"github.com/elastic/go-elasticsearch/v8"
	"github.com/elastic/go-elasticsearch/v8/esapi"
	"github.com/elastic/go-elasticsearch/v8/esutil"
)

func main() {
	indexName := "test"
	amount := 10000
	routines := 100

	startTime := time.Now()
	es, err := elasticsearch.NewClient(elasticsearch.Config{
		Addresses: []string{"http://localhost:9200"},
		Transport: &http.Transport{MaxIdleConns: 8, MaxIdleConnsPerHost: 8, MaxConnsPerHost: 16, IdleConnTimeout: 10 * time.Second},
	})
	exitIfErr(err)

	go func() {
		// enable PProf
		fmt.Println(http.ListenAndServe("localhost:6060", nil))
	}()

	wg := sync.WaitGroup{}
	for j := 0; j < routines; j++ {
		wg.Add(1)
		go func(routine int) {
			for i := 0; i < amount; i++ {
				var err error
				if routine % 2 == 0 {
					req := esapi.CreateRequest{
						Index:      indexName,
						DocumentID: url.PathEscape(strconv.Itoa(i)),
					}
					_, err = req.Do(context.Background(), es)
				} else {
					bodyList := []map[string]interface{}{
						{"_id": 0, "_index": indexName},
					}

					req := esapi.MgetRequest{Body: esutil.NewJSONReader(bodyList)}
					_, err = req.Do(context.Background(), es)
				}
				if err != nil {
					fmt.Printf("Error: %s", err)
				}
				time.Sleep(time.Millisecond * 100)
			}
			wg.Done()
		}(j)
	}

	wg.Wait()
	fmt.Printf("Finished. Took: %s", time.Since(startTime))
}

func exitIfErr(err error) {
	if err != nil {
		fmt.Printf("Error: %s", err)
		os.Exit(1)
	}
}

after running for a while assuming probeRequestBody will take more than 200 ms we will encounter /usr/local/go/src/net/http/transfer.go:237
image

Using pprof you would be able to see go routines stuck waiting to read the body

goroutine 198 [chan receive, 6 minutes]:
net/http.finishAsyncByteRead.Read(0xc000366000, 0xc000722000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/http/transfer.go:1069 +0x94
io.(*multiReader).Read(0xc000132720, 0xc000722000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
	/usr/local/go/src/io/multi.go:26 +0x17f
io.copyBuffer(0x3595008, 0xc0000a1810, 0x1728ec0, 0xc000132720, 0xc000722000, 0x8000, 0x8000, 0x1, 0x0, 0x0)
	/usr/local/go/src/io/io.go:423 +0x35f
io.Copy(0x3595008, 0xc0000a1810, 0x1728ec0, 0xc000132720, 0x0, 0x0, 0x0)
	/usr/local/go/src/io/io.go:382 +0x97
net/http.(*transferWriter).doBodyCopy(0xc000366000, 0x3595008, 0xc0000a1810, 0x1728ec0, 0xc000132720, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/http/transfer.go:409 +0x72
net/http.(*transferWriter).writeBody(0xc000366000, 0x17292a0, 0xc0000c2170, 0x0, 0x0)
	/usr/local/go/src/net/http/transfer.go:356 +0x2f4
net/http.(*Request).write(0xc000110800, 0x1728b40, 0xc00032e3c0, 0x0, 0xc000322a20, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/http/request.go:697 +0x1125
net/http.(*persistConn).writeLoop(0xc00018ac60)
	/usr/local/go/src/net/http/transport.go:2385 +0x2c5
created by net/http.(*Transport).dialConn
	/usr/local/go/src/net/http/transport.go:1744 +0x166c

That async reader fails to send EOF causing the same open issue described in this comment

How to Handle
Since this issue does not seem to resolve in golang anytime soon and this library did not have any option to workaround this behavior, we forked this library and added an option to read the Content-Length from the headers and copy it to the request, thus avoiding probeRequestBody:
image

example in our forked repo: https://github.com/demisto/go-elasticsearch/blob/master/esapi/api.mget.go#L155 )

I would love a feedback on the issue and/or solution before pushing a PR.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions