labstack / echo

High performance, minimalist Go web framework
https://echo.labstack.com
MIT License
29.94k stars 2.23k forks source link

A large number of HTTP request connections have not been released. #2674

Closed Christian-health closed 3 months ago

Christian-health commented 3 months ago

Issue Description

I am using the Go echo framework to set up an HTTPS server, and it's running in a pod. After a period of time, this pod experiences an Out-Of-Memory (OOM) issue, gets killed, and is rebuilt. I noticed that there are a large number of HTTP request connections that are not being released. Additionally, for each request, a new goroutine is created. These goroutines show a significant I/O wait time, for example, 5801 minutes.

Could you please help analyze what might be the cause of this issue?

goroutine 3217392 [running]:
runtime/pprof.writeGoroutineStacks({0x7f27b15a7590, 0xc01ee3b890})
        /usr/local/go1.14/go/src/runtime/pprof/pprof.go:703 +0x70
runtime/pprof.writeGoroutine({0x7f27b15a7590?, 0xc01ee3b890?}, 0xfbb120?)
        /usr/local/go1.14/go/src/runtime/pprof/pprof.go:692 +0x2b
runtime/pprof.(*Profile).WriteTo(0xaa9480?, {0x7f27b15a7590?, 0xc01ee3b890?}, 0xc?)
        /usr/local/go1.14/go/src/runtime/pprof/pprof.go:329 +0x14b
net/http/pprof.handler.ServeHTTP({0xafdf45, 0x9}, {0xbea500, 0xc01ee3b890}, 0xc00028d300?)
        /usr/local/go1.14/go/src/net/http/pprof/pprof.go:259 +0x4a5
fmadapter/router.registerPprof.func4({0xbf42e8, 0xc01b08e0a0})
        /media/vdb/go14workspace/src/fmadapter/router/router.go:56 +0x66
github.com/labstack/echo/v4.(*Echo).add.func1({0xbf42e8, 0xc01b08e0a0})
        /media/vdb/go14workspace/pkg/mod/github.com/labstack/echo/v4@v4.10.2/echo.go:575 +0x51
github.com/labstack/echo/v4.(*Echo).ServeHTTP(0xc00027cd80, {0xbea500?, 0xc01ee3b890}, 0xc01e754100)
        /media/vdb/go14workspace/pkg/mod/github.com/labstack/echo/v4@v4.10.2/echo.go:662 +0x3d1
net/http.serverHandler.ServeHTTP({0x0?}, {0xbea500, 0xc01ee3b890}, 0xc01e754100)
        /usr/local/go1.14/go/src/net/http/server.go:2936 +0x316
net/http.initALPNRequest.ServeHTTP({{0xbeac68?, 0xc01a8de510?}, 0xc01f766700?, {0xc00028a0f0?}}, {0xbea500, 0xc01ee3b890}, 0xc01e754100)
        /usr/local/go1.14/go/src/net/http/server.go:3545 +0x245
net/http.(*http2serverConn).runHandler(0xbe63a0?, 0xfeb420?, 0x0?, 0x0?)
        /usr/local/go1.14/go/src/net/http/h2_bundle.go:6049 +0x83
created by net/http.(*http2serverConn).processHeaders
        /usr/local/go1.14/go/src/net/http/h2_bundle.go:5762 +0x68a

There are many similar and repeated goroutine details ====》
goroutine 1124 [IO wait, 5801 minutes]:
internal/poll.runtime_pollWait(0x7f27b21c3168, 0x72)
        /usr/local/go1.14/go/src/runtime/netpoll.go:306 +0x89
internal/poll.(*pollDesc).wait(0xc0001aad80?, 0xc0000ffb00?, 0x0)
        /usr/local/go1.14/go/src/internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/go1.14/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc0001aad80, {0xc0000ffb00, 0x240, 0x240})
        /usr/local/go1.14/go/src/internal/poll/fd_unix.go:167 +0x299
net.(*netFD).Read(0xc0001aad80, {0xc0000ffb00?, 0xc0006ef558?, 0xc0004f5658?})
        /usr/local/go1.14/go/src/net/fd_posix.go:55 +0x29
net.(*conn).Read(0xc000012138, {0xc0000ffb00?, 0xc0005d2fd0?, 0x2c?})
        /usr/local/go1.14/go/src/net/net.go:183 +0x45
crypto/tls.(*atLeastReader).Read(0xc00032c6f0, {0xc0000ffb00?, 0xc00032c6f0?, 0x0?})
        /usr/local/go1.14/go/src/crypto/tls/conn.go:788 +0x3d
bytes.(*Buffer).ReadFrom(0xc000363b10, {0xbe5380, 0xc00032c6f0})
        /usr/local/go1.14/go/src/bytes/buffer.go:202 +0x98
crypto/tls.(*Conn).readFromUntil(0xc000363880, {0xbe5d00?, 0xc000012138}, 0x507786?)
        /usr/local/go1.14/go/src/crypto/tls/conn.go:810 +0xe5
crypto/tls.(*Conn).readRecordOrCCS(0xc000363880, 0x0)
        /usr/local/go1.14/go/src/crypto/tls/conn.go:617 +0x116
crypto/tls.(*Conn).readRecord(...)
        /usr/local/go1.14/go/src/crypto/tls/conn.go:583
crypto/tls.(*Conn).Read(0xc000363880, {0xc0005b3000, 0x1000, 0x0?})
        /usr/local/go1.14/go/src/crypto/tls/conn.go:1316 +0x16f
net/http.(*connReader).Read(0xc0001a9770, {0xc0005b3000, 0x1000, 0x1000})
        /usr/local/go1.14/go/src/net/http/server.go:782 +0x171
bufio.(*Reader).fill(0xc00056e8a0)
        /usr/local/go1.14/go/src/bufio/bufio.go:106 +0xff
bufio.(*Reader).Peek(0xc00056e8a0, 0x4)
        /usr/local/go1.14/go/src/bufio/bufio.go:144 +0x5d
net/http.(*conn).serve(0xc0006a6c60, {0xbeac68, 0xc000326360})
        /usr/local/go1.14/go/src/net/http/server.go:2030 +0x77c
created by net/http.(*Server).Serve
        /usr/local/go1.14/go/src/net/http/server.go:3089 +0x5ed

《 ===  There are many such goroutine details.
omm-oss-idn-7bf55d7ff8-d8jrt:/$ netstat -antp |wc -l
2013
omm-oss-idn-7bf55d7ff8-d8jrt:/$ netstat -antp |more
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 :::1949                 :::*                    LISTEN      1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:50416 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:54250 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:40024 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:47650 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:60722 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:57748 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:48114 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:40332 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:56668 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:56430 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:60544 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:53270 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:33168 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:53602 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:47670 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:44924 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:35346 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:53282 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:51574 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:51034 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:60722 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:51470 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:50850 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:34188 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:60672 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:46126 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:43380 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:57416 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:34140 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:36962 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:37674 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:56818 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:46180 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:44656 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.4.209:43484 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:59700 ESTABLISHED 1/oss
tcp        0      0 ::ffff:192.169.8.171:1949 ::ffff:192.169.12.127:43706 ESTABLISHED 1/oss

Version/commit

go1.14 echo

aldas commented 3 months ago

If you are really using go 1.14, to start with, please upgrade to newer version and see if it changes.

Christian-health commented 3 months ago

If you are really using go 1.14, to start with, please upgrade to newer version and see if it changes.

Thank you for your response. This issue has been resolved.

server-side code:

srv := &http.Server{
        Addr:         fmt.Sprintf("%s:%d", serverCfg.Addr, serverCfg.Port),
        Handler:      e,
                 //  If the server has the following two lines of code, it will be able to release the client's connection from the server.
        ReadTimeout:  time.Duration(serverCfg.ReadTimeout) * time.Second,
        WriteTimeout: time.Duration(serverCfg.WriteTimeout) * time.Second,
    }

client-side code:

HTTPTransport := &http.Transport{ 
        TLSClientConfig: &tls.Config{InsecureSkipVerify: true}, 
        Proxy:           http.ProxyFromEnvironment, 
        Dial: (&net.Dialer{
            Timeout:   time.Duration(100) * time.Second,
            KeepAlive: time.Duration(100) * time.Second,
        }).Dial,
        TLSHandshakeTimeout:   time.Duration(100) * time.Second,
        ExpectContinueTimeout: time.Duration(100) * time.Second,
                // If the client has the following three lines of code, it will ensure that the number of client connections created is limited.
        MaxIdleConnsPerHost:   100,
        MaxIdleConns:          100,
        IdleConnTimeout:       100,
    }

The issue is that the server did not configure a timeout, and the client did not limit the number of connections created and used a connection pool. As a result, each time the client sent data, a new connection was created. Additionally, Go's default behavior open keep-alive. This led to a large number of connections not being released, eventually resulting in an out-of-memory (OOM) error."