Caddy: Proxy in 0.10.14 leaks file descriptors

Created on 26 Apr 2018  路  8Comments  路  Source: caddyserver/caddy

1. What version of Caddy are you using (caddy -version)?

0.10.14

2. What are you trying to do?

Have Caddy sit in front of Prometheus Node Exporter to add TLS, access control, and authentication.

3. What is your entire Caddyfile?

host.example.com {
    bind host.example.com
    tls /path/to/cert.pem /path/to/cert.key
    ipfilter / {
        rule allow
        ip [some IP addresses]
    }
    basicauth / user password
    gzip {
        level 3
        min_length 1024
    }
    proxy /node http://localhost:9100/ {
        without /node
        transparent
    }
}

4. How did you run Caddy (give the full command and describe the execution environment)?

systemctl start caddy.service using the default systemd unit.

5. Please paste any relevant HTTP request(s) here.

curl https://host.example.com/node/metrics

6. What did you expect to see?

We upgraded from Caddy 0.10.12 to 0.10.14, and didn't expect any significant change in open file descriptors.

7. What did you see instead (give full error messages and/or log)?

On a host where Prometheus usually reports between 2000 and 2200 open file descriptors (metric name: node_filefd_allocated), we went to about 12000 in less than an hour. Something similar happened accross all our hosts, and various services started failing with too many open files errors.

Reverting to Caddy 0.10.12 solved the problem, i.e. node_filefd_allocated went back to what it was before.

8. How can someone who is starting from scratch reproduce the bug as minimally as possible?

Download Prometheus and Node Exporter from https://prometheus.io/download/.

On prom.example.com, start Prometheus with the following prometheus.yml config:

global:
  scrape_interval: 1m
  scrape_timeout:  25s
scrape_configs:
  - job_name: node
    scheme: https
    basic_auth:
      username: user
      password: password
    metrics_path: /node/metrics
    static_configs:
      - targets:
          - host.example.com

On host.example.com, start Prometheus Node Exporter and Caddy (see above for the Caddyfile). Then wait a bit and watch the number of file descriptors increase:

$ ps ax | grep caddy # Get Caddy's PID, e.g. 19374
$ ls /proc/19374/fd | wc -l # Count file descriptors

With 0.10.12, the number increases a bit after start, but then stabilizes. With 0.10.14, it keeps increasing.

bug

Most helpful comment

PR #2134 seems to fix the problem. Thank you so much, @crvv and @mholt!

Below is what Prometheus says about the node_filefd_allocated metric after the patch was deployed around the 3 minute mark (i.e., normal fluctuation as opposed to linear increase caused by 0.10.14):

node_filefd_allocated

For reference:

# Download Caddy and plugins
go get github.com/mholt/caddy/caddy
go get github.com/caddyserver/builds
go get github.com/pyed/ipfilter          # `http.ipfilter` plugin
go get github.com/miekg/caddy-prometheus # `http.prometheus` plugin
cd $GOPATH/src/github.com/mholt/caddy/caddy
git diff caddymain/run.go
diff --git a/caddy/caddymain/run.go b/caddy/caddymain/run.go
index ddc50aa..386240d 100644
--- a/caddy/caddymain/run.go
+++ b/caddy/caddymain/run.go
@@ -35,6 +35,8 @@ import (

        "github.com/mholt/caddy/caddytls"
        // This is where other plugins get plugged in (imported)
+       _ "github.com/miekg/caddy-prometheus"
+       _ "github.com/pyed/ipfilter"
 )

 func init() {
# Apply PR #2134 and build
git fetch origin pull/2134/head:pr2134
git checkout pr2134
go run build.go --goos=linux --goarch=amd64

All 8 comments

Hi, thanks for filing an issue and following the template. Could you please use the pprof and expvar directives to give us a dump of all the goroutines when the number of file descriptors are high?

I wonder if you're hitting https://github.com/mholt/caddy/pull/2134

Hi Matt! Thanks for the quick reply and sorry for the delay (time zones). Dumps are below.

node_filefd_allocated

Screenshot of Prometheus graphing the node_filefd_allocated metric. Around the 17 minute mark, we deployed Caddy 0.10.14. The dumps were taken after about 15 minutes, at the 34 minute mark. After that, we reverted to Caddy 0.10.12 which put everything back to normal.

node_filefd_allocated

curl https://host.example.com/debug/pprof/goroutine?debug=1


Click to expand response...

goroutine profile: total 3517
1730 @ 0x42d07a 0x42839a 0x427a17 0x49415b 0x4941dd 0x49503d 0x5886ef 0x59a86a 0x6c1e96 0x4efb7e 0x4efcca 0x6c2955 0x45ab71
#   0x427a16    internal/poll.runtime_pollWait+0x56 /usr/local/go/src/runtime/netpoll.go:173
#   0x49415a    internal/poll.(*pollDesc).wait+0x9a /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x4941dc    internal/poll.(*pollDesc).waitRead+0x3c /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49503c    internal/poll.(*FD).Read+0x17c      /usr/local/go/src/internal/poll/fd_unix.go:157
#   0x5886ee    net.(*netFD).Read+0x4e          /usr/local/go/src/net/fd_unix.go:202
#   0x59a869    net.(*conn).Read+0x69           /usr/local/go/src/net/net.go:176
#   0x6c1e95    net/http.(*persistConn).Read+0x135  /usr/local/go/src/net/http/transport.go:1453
#   0x4efb7d    bufio.(*Reader).fill+0x11d      /usr/local/go/src/bufio/bufio.go:100
#   0x4efcc9    bufio.(*Reader).Peek+0x39       /usr/local/go/src/bufio/bufio.go:132
#   0x6c2954    net/http.(*persistConn).readLoop+0x184  /usr/local/go/src/net/http/transport.go:1601

1730 @ 0x42d07a 0x43ce60 0x6c3f1b 0x45ab71
#   0x6c3f1a    net/http.(*persistConn).writeLoop+0x14a /usr/local/go/src/net/http/transport.go:1822

17 @ 0x42d07a 0x42839a 0x427a17 0x49415b 0x4941dd 0x49503d 0x5886ef 0x59a86a 0x915902 0x61ceb6 0x61d3c0 0x620960 0x6a9c08 0x4efb7e 0x4efcca 0x6aee93 0x45ab71
#   0x427a16    internal/poll.runtime_pollWait+0x56                     /usr/local/go/src/runtime/netpoll.go:173
#   0x49415a    internal/poll.(*pollDesc).wait+0x9a                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x4941dc    internal/poll.(*pollDesc).waitRead+0x3c                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49503c    internal/poll.(*FD).Read+0x17c                          /usr/local/go/src/internal/poll/fd_unix.go:157
#   0x5886ee    net.(*netFD).Read+0x4e                              /usr/local/go/src/net/fd_unix.go:202
#   0x59a869    net.(*conn).Read+0x69                               /usr/local/go/src/net/net.go:176
#   0x915901    github.com/mholt/caddy/caddyhttp/httpserver.(*clientHelloConn).Read+0x5f1   /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/mitm.go:159
#   0x61ceb5    crypto/tls.(*block).readFromUntil+0x95                      /usr/local/go/src/crypto/tls/conn.go:493
#   0x61d3bf    crypto/tls.(*Conn).readRecord+0xdf                      /usr/local/go/src/crypto/tls/conn.go:595
#   0x62095f    crypto/tls.(*Conn).Read+0xff                            /usr/local/go/src/crypto/tls/conn.go:1156
#   0x6a9c07    net/http.(*connReader).Read+0xf7                        /usr/local/go/src/net/http/server.go:764
#   0x4efb7d    bufio.(*Reader).fill+0x11d                          /usr/local/go/src/bufio/bufio.go:100
#   0x4efcc9    bufio.(*Reader).Peek+0x39                           /usr/local/go/src/bufio/bufio.go:132
#   0x6aee92    net/http.(*conn).serve+0x7c2                            /usr/local/go/src/net/http/server.go:1855

14 @ 0x42d07a 0x42839a 0x427a17 0x49415b 0x4941dd 0x49503d 0x5886ef 0x59a86a 0x6a9c08 0x4efb7e 0x4f085c 0x4f0a74 0x643060 0x642e6b 0x6a45ac 0x6aaeaf 0x6aebac 0x45ab71
#   0x427a16    internal/poll.runtime_pollWait+0x56     /usr/local/go/src/runtime/netpoll.go:173
#   0x49415a    internal/poll.(*pollDesc).wait+0x9a     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x4941dc    internal/poll.(*pollDesc).waitRead+0x3c     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49503c    internal/poll.(*FD).Read+0x17c          /usr/local/go/src/internal/poll/fd_unix.go:157
#   0x5886ee    net.(*netFD).Read+0x4e              /usr/local/go/src/net/fd_unix.go:202
#   0x59a869    net.(*conn).Read+0x69               /usr/local/go/src/net/net.go:176
#   0x6a9c07    net/http.(*connReader).Read+0xf7        /usr/local/go/src/net/http/server.go:764
#   0x4efb7d    bufio.(*Reader).fill+0x11d          /usr/local/go/src/bufio/bufio.go:100
#   0x4f085b    bufio.(*Reader).ReadSlice+0x2b          /usr/local/go/src/bufio/bufio.go:341
#   0x4f0a73    bufio.(*Reader).ReadLine+0x33           /usr/local/go/src/bufio/bufio.go:370
#   0x64305f    net/textproto.(*Reader).readLineSlice+0x6f  /usr/local/go/src/net/textproto/reader.go:55
#   0x642e6a    net/textproto.(*Reader).ReadLine+0x2a       /usr/local/go/src/net/textproto/reader.go:36
#   0x6a45ab    net/http.readRequest+0x8b           /usr/local/go/src/net/http/request.go:929
#   0x6aaeae    net/http.(*conn).readRequest+0x16e      /usr/local/go/src/net/http/server.go:944
#   0x6aebab    net/http.(*conn).serve+0x4db            /usr/local/go/src/net/http/server.go:1768

3 @ 0x42d07a 0x42839a 0x427a17 0x49415b 0x4941dd 0x49503d 0x5886ef 0x59a86a 0x915902 0x61ceb6 0x61d3c0 0x620960 0x471d26 0x471e98 0x677d7b 0x678604 0x683e79 0x45ab71
#   0x427a16    internal/poll.runtime_pollWait+0x56                     /usr/local/go/src/runtime/netpoll.go:173
#   0x49415a    internal/poll.(*pollDesc).wait+0x9a                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x4941dc    internal/poll.(*pollDesc).waitRead+0x3c                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49503c    internal/poll.(*FD).Read+0x17c                          /usr/local/go/src/internal/poll/fd_unix.go:157
#   0x5886ee    net.(*netFD).Read+0x4e                              /usr/local/go/src/net/fd_unix.go:202
#   0x59a869    net.(*conn).Read+0x69                               /usr/local/go/src/net/net.go:176
#   0x915901    github.com/mholt/caddy/caddyhttp/httpserver.(*clientHelloConn).Read+0x5f1   /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/mitm.go:159
#   0x61ceb5    crypto/tls.(*block).readFromUntil+0x95                      /usr/local/go/src/crypto/tls/conn.go:493
#   0x61d3bf    crypto/tls.(*Conn).readRecord+0xdf                      /usr/local/go/src/crypto/tls/conn.go:595
#   0x62095f    crypto/tls.(*Conn).Read+0xff                            /usr/local/go/src/crypto/tls/conn.go:1156
#   0x471d25    io.ReadAtLeast+0x85                             /usr/local/go/src/io/io.go:309
#   0x471e97    io.ReadFull+0x57                                /usr/local/go/src/io/io.go:327
#   0x677d7a    net/http.http2readFrameHeader+0x7a                      /usr/local/go/src/net/http/h2_bundle.go:1517
#   0x678603    net/http.(*http2Framer).ReadFrame+0xa3                      /usr/local/go/src/net/http/h2_bundle.go:1775
#   0x683e78    net/http.(*http2serverConn).readFrames+0xa8                 /usr/local/go/src/net/http/h2_bundle.go:4392

3 @ 0x42d07a 0x42839a 0x427a17 0x49415b 0x4941dd 0x4965d8 0x589002 0x5a445e 0x5a2a39 0x922f1f 0x916087 0x6b2de5 0x921826 0x7dea69 0x45ab71
#   0x427a16    internal/poll.runtime_pollWait+0x56                     /usr/local/go/src/runtime/netpoll.go:173
#   0x49415a    internal/poll.(*pollDesc).wait+0x9a                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x4941dc    internal/poll.(*pollDesc).waitRead+0x3c                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x4965d7    internal/poll.(*FD).Accept+0x1a7                        /usr/local/go/src/internal/poll/fd_unix.go:372
#   0x589001    net.(*netFD).accept+0x41                            /usr/local/go/src/net/fd_unix.go:238
#   0x5a445d    net.(*TCPListener).accept+0x2d                          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x5a2a38    net.(*TCPListener).AcceptTCP+0x48                       /usr/local/go/src/net/tcpsock.go:246
#   0x922f1e    github.com/mholt/caddy/caddyhttp/httpserver.tcpKeepAliveListener.Accept+0x2e    /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/server.go:517
#   0x916086    github.com/mholt/caddy/caddyhttp/httpserver.(*tlsHelloListener).Accept+0x36 /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/mitm.go:338
#   0x6b2de4    net/http.(*Server).Serve+0x1a4                          /usr/local/go/src/net/http/server.go:2770
#   0x921825    github.com/mholt/caddy/caddyhttp/httpserver.(*Server).Serve+0xa5        /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/server.go:321
#   0x7dea68    github.com/mholt/caddy.startServers.func1.1+0x48                /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddy.go:784

3 @ 0x42d07a 0x43ce60 0x684996 0x682ddb 0x6c8141 0x6af56e 0x45ab71
#   0x684995    net/http.(*http2serverConn).serve+0x5b5     /usr/local/go/src/net/http/h2_bundle.go:4505
#   0x682dda    net/http.(*http2Server).ServeConn+0x74a     /usr/local/go/src/net/http/h2_bundle.go:4124
#   0x6c8140    net/http.http2ConfigureServer.func1+0x80    /usr/local/go/src/net/http/h2_bundle.go:3962
#   0x6af56d    net/http.(*conn).serve+0xe9d            /usr/local/go/src/net/http/server.go:1751

3 @ 0x42d07a 0x43ce60 0x7ed52a 0x45ab71
#   0x7ed529    github.com/mholt/caddy/caddytls.standaloneTLSTicketKeyRotation+0x269    /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddytls/crypto.go:310

1 @ 0x40f972 0x441bf6 0x7cfa92 0x45ab71
#   0x441bf5    os/signal.signal_recv+0xa5  /usr/local/go/src/runtime/sigqueue.go:139
#   0x7cfa91    os/signal.loop+0x21     /usr/local/go/src/os/signal/signal_unix.go:22

1 @ 0x42d07a 0x42839a 0x427a17 0x49415b 0x4941dd 0x49503d 0x5886ef 0x59a86a 0x915902 0x61ceb6 0x61d3c0 0x620960 0x6a975a 0x45ab71
#   0x427a16    internal/poll.runtime_pollWait+0x56                     /usr/local/go/src/runtime/netpoll.go:173
#   0x49415a    internal/poll.(*pollDesc).wait+0x9a                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x4941dc    internal/poll.(*pollDesc).waitRead+0x3c                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x49503c    internal/poll.(*FD).Read+0x17c                          /usr/local/go/src/internal/poll/fd_unix.go:157
#   0x5886ee    net.(*netFD).Read+0x4e                              /usr/local/go/src/net/fd_unix.go:202
#   0x59a869    net.(*conn).Read+0x69                               /usr/local/go/src/net/net.go:176
#   0x915901    github.com/mholt/caddy/caddyhttp/httpserver.(*clientHelloConn).Read+0x5f1   /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/mitm.go:159
#   0x61ceb5    crypto/tls.(*block).readFromUntil+0x95                      /usr/local/go/src/crypto/tls/conn.go:493
#   0x61d3bf    crypto/tls.(*Conn).readRecord+0xdf                      /usr/local/go/src/crypto/tls/conn.go:595
#   0x62095f    crypto/tls.(*Conn).Read+0xff                            /usr/local/go/src/crypto/tls/conn.go:1156
#   0x6a9759    net/http.(*connReader).backgroundRead+0x59                  /usr/local/go/src/net/http/server.go:668

1 @ 0x42d07a 0x42839a 0x427a17 0x49415b 0x4941dd 0x4965d8 0x589002 0x5a445e 0x5a2a39 0x6b49af 0x6b2de5 0x6b2b39 0x6b3b7a 0x99e034 0x45ab71
#   0x427a16    internal/poll.runtime_pollWait+0x56             /usr/local/go/src/runtime/netpoll.go:173
#   0x49415a    internal/poll.(*pollDesc).wait+0x9a             /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x4941dc    internal/poll.(*pollDesc).waitRead+0x3c             /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x4965d7    internal/poll.(*FD).Accept+0x1a7                /usr/local/go/src/internal/poll/fd_unix.go:372
#   0x589001    net.(*netFD).accept+0x41                    /usr/local/go/src/net/fd_unix.go:238
#   0x5a445d    net.(*TCPListener).accept+0x2d                  /usr/local/go/src/net/tcpsock_posix.go:136
#   0x5a2a38    net.(*TCPListener).AcceptTCP+0x48               /usr/local/go/src/net/tcpsock.go:246
#   0x6b49ae    net/http.tcpKeepAliveListener.Accept+0x2e           /usr/local/go/src/net/http/server.go:3216
#   0x6b2de4    net/http.(*Server).Serve+0x1a4                  /usr/local/go/src/net/http/server.go:2770
#   0x6b2b38    net/http.(*Server).ListenAndServe+0xa8              /usr/local/go/src/net/http/server.go:2711
#   0x6b3b79    net/http.ListenAndServe+0x79                    /usr/local/go/src/net/http/server.go:2969
#   0x99e033    github.com/miekg/caddy-prometheus.(*Metrics).start.func1.1+0x43 /tmp/gopath_04-26-0306.471772998/src/github.com/miekg/caddy-prometheus/setup.go:62

1 @ 0x42d07a 0x42839a 0x427a17 0x49415b 0x4941dd 0x4965d8 0x589002 0x5a445e 0x5a2a39 0x922f1f 0x6b2de5 0x921826 0x7dea69 0x45ab71
#   0x427a16    internal/poll.runtime_pollWait+0x56                     /usr/local/go/src/runtime/netpoll.go:173
#   0x49415a    internal/poll.(*pollDesc).wait+0x9a                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:85
#   0x4941dc    internal/poll.(*pollDesc).waitRead+0x3c                     /usr/local/go/src/internal/poll/fd_poll_runtime.go:90
#   0x4965d7    internal/poll.(*FD).Accept+0x1a7                        /usr/local/go/src/internal/poll/fd_unix.go:372
#   0x589001    net.(*netFD).accept+0x41                            /usr/local/go/src/net/fd_unix.go:238
#   0x5a445d    net.(*TCPListener).accept+0x2d                          /usr/local/go/src/net/tcpsock_posix.go:136
#   0x5a2a38    net.(*TCPListener).AcceptTCP+0x48                       /usr/local/go/src/net/tcpsock.go:246
#   0x922f1e    github.com/mholt/caddy/caddyhttp/httpserver.tcpKeepAliveListener.Accept+0x2e    /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/server.go:517
#   0x6b2de4    net/http.(*Server).Serve+0x1a4                          /usr/local/go/src/net/http/server.go:2770
#   0x921825    github.com/mholt/caddy/caddyhttp/httpserver.(*Server).Serve+0xa5        /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/server.go:321
#   0x7dea68    github.com/mholt/caddy.startServers.func1.1+0x48                /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddy.go:784

1 @ 0x42d07a 0x42d12e 0x4046f2 0x4043ab 0x7df280 0x45ab71
#   0x7df27f    github.com/mholt/caddy.trapSignalsCrossPlatform.func1+0xff  /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/sigtrap.go:43

1 @ 0x42d07a 0x42d12e 0x4046f2 0x4043eb 0x50a378 0x45ab71
#   0x50a377    github.com/mholt/caddy/vendor/gopkg.in/natefinch/lumberjack%2ev2.(*Logger).millRun+0x57 /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/vendor/gopkg.in/natefinch/lumberjack.v2/lumberjack.go:379

1 @ 0x42d07a 0x42d12e 0x4046f2 0x4043eb 0x7dec61 0x45ab71
#   0x7dec60    github.com/mholt/caddy.startServers.func2+0x40  /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddy.go:796

1 @ 0x42d07a 0x42d12e 0x4046f2 0x4043eb 0x7df69f 0x45ab71
#   0x7df69e    github.com/mholt/caddy.trapSignalsPosix.func1+0x13e /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/sigtrap_posix.go:32

1 @ 0x42d07a 0x42d12e 0x43dae4 0x43d709 0x471872 0x7d744f 0xa690d3 0xa6a1e7 0x42cc22 0x45ab71
#   0x43d708    sync.runtime_Semacquire+0x38                /usr/local/go/src/runtime/sema.go:56
#   0x471871    sync.(*WaitGroup).Wait+0x71             /usr/local/go/src/sync/waitgroup.go:129
#   0x7d744e    github.com/mholt/caddy.(*Instance).Wait+0x2e        /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddy.go:438
#   0xa690d2    github.com/mholt/caddy/caddy/caddymain.Run+0x3e2    /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddy/caddymain/run.go:125
#   0xa6a1e6    main.main+0x26                      src/github.com/mholt/caddy/caddy/main.go:27
#   0x42cc21    runtime.main+0x211                  /usr/local/go/src/runtime/proc.go:198

1 @ 0x42d07a 0x43ce60 0x457774 0x45ab71
#   0x42d079    runtime.gopark+0x119        /usr/local/go/src/runtime/proc.go:291
#   0x43ce5f    runtime.selectgo+0xe4f      /usr/local/go/src/runtime/select.go:392
#   0x457773    runtime.ensureSigM.func1+0x1f3  /usr/local/go/src/runtime/signal_unix.go:549

1 @ 0x42d07a 0x43ce60 0x6c49a7 0x6bb3a2 0xa3fa75 0xa47030 0xa3d836 0xa49f71 0x9a0751 0x9a289b 0x9380b5 0x93ac87 0x9b87ee 0x9bab1b 0x9c9ff6 0x9cafb1 0x9c646c 0x9c91b1 0x922200 0x921dff 0x914a21 0x6b2a1c 0x6aed21 0x45ab71
#   0x6c49a6    net/http.(*persistConn).roundTrip+0x5a6                     /usr/local/go/src/net/http/transport.go:2033
#   0x6bb3a1    net/http.(*Transport).RoundTrip+0x8f1                       /usr/local/go/src/net/http/transport.go:422
#   0xa3fa74    github.com/mholt/caddy/caddyhttp/proxy.(*ReverseProxy).ServeHTTP+0x134      /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/proxy/reverseproxy.go:330
#   0xa4702f    github.com/mholt/caddy/caddyhttp/proxy.Proxy.ServeHTTP.func2+0x8f       /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/proxy/proxy.go:246
#   0xa3d835    github.com/mholt/caddy/caddyhttp/proxy.Proxy.ServeHTTP+0x335            /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/proxy/proxy.go:247
#   0x9a0750    github.com/mholt/caddy/caddyhttp/basicauth.BasicAuth.ServeHTTP+0x460        /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/basicauth/basicauth.go:101
#   0x9380b4    github.com/pyed/ipfilter.IPFilter.ServeHTTP+0x244               /tmp/gopath_04-26-0306.471772998/src/github.com/pyed/ipfilter/ipfilter.go:214
#   0x9b87ed    github.com/mholt/caddy/caddyhttp/errors.ErrorHandler.ServeHTTP+0xfd     /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/errors/errors.go:50
#   0x9c9ff5    github.com/mholt/caddy/caddyhttp/header.Headers.ServeHTTP+0x545         /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/header/header.go:62
#   0x9c646b    github.com/mholt/caddy/caddyhttp/gzip.Gzip.ServeHTTP+0x34b          /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/gzip/gzip.go:90
#   0x9221ff    github.com/mholt/caddy/caddyhttp/httpserver.(*Server).serveHTTP+0x2df       /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/server.go:434
#   0x921dfe    github.com/mholt/caddy/caddyhttp/httpserver.(*Server).ServeHTTP+0x2ce       /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/server.go:370
#   0x914a20    github.com/mholt/caddy/caddyhttp/httpserver.(*tlsHandler).ServeHTTP+0x250   /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/mitm.go:111
#   0x6b2a1b    net/http.serverHandler.ServeHTTP+0xbb                       /usr/local/go/src/net/http/server.go:2694
#   0x6aed20    net/http.(*conn).serve+0x650                            /usr/local/go/src/net/http/server.go:1830

1 @ 0x42d07a 0x43ce60 0x7f42a5 0x45ab71
#   0x7f42a4    github.com/mholt/caddy/caddytls.maintainAssets+0x154    /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddytls/maintain.go:68

1 @ 0x42d07a 0x43ce60 0xa471be 0x45ab71
#   0xa471bd    github.com/mholt/caddy/caddyhttp/proxy.createUpstreamRequest.func1+0xdd /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/proxy/proxy.go:306

1 @ 0xa338b8 0xa336c0 0xa30204 0xa3ba48 0xa3bd31 0xa3c50f 0x6afd04 0x6b1970 0xa3c03e 0xa4e408 0xa4fdb1 0x9a0751 0x9a289b 0x9380b5 0x93ac87 0x9b87ee 0x9bab1b 0x9c9ff6 0x9cafb1 0x9c66b8 0x9c91b1 0x922200 0x921dff 0x914a21 0x6b2a1c 0x6b4c6a 0x6d7db3 0x6d0aad 0x68b709 0x45ab71
#   0xa338b7    runtime/pprof.writeRuntimeProfile+0x97                      /usr/local/go/src/runtime/pprof/pprof.go:679
#   0xa336bf    runtime/pprof.writeGoroutine+0x9f                       /usr/local/go/src/runtime/pprof/pprof.go:641
#   0xa30203    runtime/pprof.(*Profile).WriteTo+0x3e3                      /usr/local/go/src/runtime/pprof/pprof.go:310
#   0xa3ba47    net/http/pprof.handler.ServeHTTP+0x1b7                      /usr/local/go/src/net/http/pprof/pprof.go:237
#   0xa3bd30    net/http/pprof.Index+0x1d0                          /usr/local/go/src/net/http/pprof/pprof.go:248
#   0xa3c50e    github.com/mholt/caddy/caddyhttp/pprof.NewMux.func1+0x8e            /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/pprof/pprof.go:54
#   0x6afd03    net/http.HandlerFunc.ServeHTTP+0x43                     /usr/local/go/src/net/http/server.go:1947
#   0x6b196f    net/http.(*ServeMux).ServeHTTP+0x12f                        /usr/local/go/src/net/http/server.go:2337
#   0xa3c03d    github.com/mholt/caddy/caddyhttp/pprof.(*Handler).ServeHTTP+0x8d        /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/pprof/pprof.go:38
#   0xa4e407    github.com/mholt/caddy/caddyhttp/redirect.Redirect.ServeHTTP+0x417      /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/redirect/redirect.go:47
#   0x9a0750    github.com/mholt/caddy/caddyhttp/basicauth.BasicAuth.ServeHTTP+0x460        /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/basicauth/basicauth.go:101
#   0x9380b4    github.com/pyed/ipfilter.IPFilter.ServeHTTP+0x244               /tmp/gopath_04-26-0306.471772998/src/github.com/pyed/ipfilter/ipfilter.go:214
#   0x9b87ed    github.com/mholt/caddy/caddyhttp/errors.ErrorHandler.ServeHTTP+0xfd     /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/errors/errors.go:50
#   0x9c9ff5    github.com/mholt/caddy/caddyhttp/header.Headers.ServeHTTP+0x545         /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/header/header.go:62
#   0x9c66b7    github.com/mholt/caddy/caddyhttp/gzip.Gzip.ServeHTTP+0x597          /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/gzip/gzip.go:56
#   0x9221ff    github.com/mholt/caddy/caddyhttp/httpserver.(*Server).serveHTTP+0x2df       /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/server.go:434
#   0x921dfe    github.com/mholt/caddy/caddyhttp/httpserver.(*Server).ServeHTTP+0x2ce       /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/server.go:370
#   0x914a20    github.com/mholt/caddy/caddyhttp/httpserver.(*tlsHandler).ServeHTTP+0x250   /tmp/gopath_04-26-0306.471772998/src/github.com/mholt/caddy/caddyhttp/httpserver/mitm.go:111
#   0x6b2a1b    net/http.serverHandler.ServeHTTP+0xbb                       /usr/local/go/src/net/http/server.go:2694
#   0x6b4c69    net/http.initNPNRequest.ServeHTTP+0x99                      /usr/local/go/src/net/http/server.go:3260
#   0x6d0aac    net/http.(Handler).ServeHTTP-fm+0x4c                        /usr/local/go/src/net/http/h2_bundle.go:5475
#   0x68b708    net/http.(*http2serverConn).runHandler+0x88                 /usr/local/go/src/net/http/h2_bundle.go:5760

curl https://host.example.com/debug/vars


Click to expand response...

{
  "Goroutines": 3555,
  "cmdline": [
    "/usr/bin/caddy",
    "-root=/var/tmp",
    "-log=/var/log/caddy/caddy.log",
    "-conf=/etc/caddy/Caddyfile"
  ],
  "memstats": {
    "Alloc": 29567176,
    "TotalAlloc": 174794152,
    "Sys": 69695736,
    "Lookups": 11174,
    "Mallocs": 1225500,
    "Frees": 1114452,
    "HeapAlloc": 29567176,
    "HeapSys": 48463872,
    "HeapIdle": 15409152,
    "HeapInuse": 33054720,
    "HeapReleased": 0,
    "HeapObjects": 111048,
    "StackInuse": 15499264,
    "StackSys": 15499264,
    "MSpanInuse": 640984,
    "MSpanSys": 704512,
    "MCacheInuse": 5208,
    "MCacheSys": 16384,
    "BuckHashSys": 1477371,
    "GCSys": 2396160,
    "OtherSys": 1138173,
    "NextGC": 51904208,
    "LastGC": 1524803568804732564,
    "PauseTotalNs": 20525013,
    "PauseNs": [
        207806,,211018,133635,59398,1377454,111506,315252,182524,339058,163018,139277,339289,72460,386367,308197,191225,86095,173617,12845279,133276,1120079,153201,799887,114661,181086,104838,275510,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
    ],
    "PauseEnd": [
        1524802735908187477,1524802737021783012,1524802740118320252,1524802741053060155,1524802743190075214,1524802748149034961,1524802753457904248,1524802764660244755,1524802773425709518,1524802785410604413,1524802800342029324,1524802811453891476,1524802814802060612,1524802818463240148,1524802823958555322,1524802849231497183,1524802886207957822,1524802899165080483,1524802937576302471,1524802970661278987,1524803022011219947,1524803121971043160,1524803220363450363,1524803340388220939,1524803419391875290,1524803490547667882,1524803568804732564,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
    ],
    "NumGC": 27,
    "NumForcedGC": 0,
    "GCCPUFraction": 0.00005044976863015633,
    "EnableGC": true,
    "DebugGC": false,
    "BySize": [
        {"Size":0,"Mallocs":0,"Frees":0},
        {"Size":8,"Mallocs":13185,"Frees":9356},
        {"Size":16,"Mallocs":424494,"Frees":400958},
        {"Size":32,"Mallocs":86556,"Frees":72802},
        {"Size":48,"Mallocs":128000,"Frees":108529},
        {"Size":64,"Mallocs":30976,"Frees":20831},
        {"Size":80,"Mallocs":16965,"Frees":16655},
        {"Size":96,"Mallocs":61066,"Frees":44435},
        {"Size":112,"Mallocs":8876,"Frees":8664},
        {"Size":128,"Mallocs":60810,"Frees":56924},
        {"Size":144,"Mallocs":13550,"Frees":9866},
        {"Size":160,"Mallocs":7038,"Frees":6857},
        {"Size":176,"Mallocs":2079,"Frees":1943},
        {"Size":192,"Mallocs":3542,"Frees":3490},
        {"Size":208,"Mallocs":1189,"Frees":1114},
        {"Size":224,"Mallocs":1848,"Frees":1801},
        {"Size":240,"Mallocs":2437,"Frees":671},
        {"Size":256,"Mallocs":12258,"Frees":12084},
        {"Size":288,"Mallocs":5520,"Frees":3688},
        {"Size":320,"Mallocs":1801,"Frees":1762},
        {"Size":352,"Mallocs":7895,"Frees":7764},
        {"Size":384,"Mallocs":4132,"Frees":502},
        {"Size":416,"Mallocs":104,"Frees":89},
        {"Size":448,"Mallocs":37,"Frees":25},
        {"Size":480,"Mallocs":2133,"Frees":377},
        {"Size":512,"Mallocs":4645,"Frees":4589},
        {"Size":576,"Mallocs":2620,"Frees":2577},
        {"Size":640,"Mallocs":2099,"Frees":336},
        {"Size":704,"Mallocs":2054,"Frees":2026},
        {"Size":768,"Mallocs":67,"Frees":65},
        {"Size":896,"Mallocs":767,"Frees":729},
        {"Size":1024,"Mallocs":805,"Frees":741},
        {"Size":1152,"Mallocs":326,"Frees":307},
        {"Size":1280,"Mallocs":85,"Frees":78},
        {"Size":1408,"Mallocs":36,"Frees":27},
        {"Size":1536,"Mallocs":17,"Frees":16},
        {"Size":1792,"Mallocs":150,"Frees":139},
        {"Size":2048,"Mallocs":177,"Frees":142},
        {"Size":2304,"Mallocs":115,"Frees":108},
        {"Size":2688,"Mallocs":169,"Frees":163},
        {"Size":3072,"Mallocs":171,"Frees":166},
        {"Size":3200,"Mallocs":16,"Frees":14},
        {"Size":3456,"Mallocs":13,"Frees":13},
        {"Size":4096,"Mallocs":4138,"Frees":546},
        {"Size":4864,"Mallocs":541,"Frees":536},
        {"Size":5376,"Mallocs":6,"Frees":2},
        {"Size":6144,"Mallocs":75,"Frees":63},
        {"Size":6528,"Mallocs":14,"Frees":14},
        {"Size":6784,"Mallocs":0,"Frees":0},
        {"Size":6912,"Mallocs":0,"Frees":0},
        {"Size":8192,"Mallocs":75,"Frees":69},
        {"Size":9472,"Mallocs":17,"Frees":14},
        {"Size":9728,"Mallocs":0,"Frees":0},
        {"Size":10240,"Mallocs":2,"Frees":2},
        {"Size":10880,"Mallocs":2,"Frees":2},
        {"Size":12288,"Mallocs":54,"Frees":54},
        {"Size":13568,"Mallocs":25,"Frees":25},
        {"Size":14336,"Mallocs":0,"Frees":0},
        {"Size":16384,"Mallocs":18,"Frees":17},
        {"Size":18432,"Mallocs":7,"Frees":5},
        {"Size":19072,"Mallocs":0,"Frees":0}
    ]
  }
}

I'm noticing the exactly the same issue, the go_goroutine reported by Prometheus never goes down for any HTTP/HTTPS connections proxied by Caddy 0.10.14.

Obersevations:

  1. Keep refreshing any web page proxied the go_goroutine can go up over 200 (can be even more but not tried)
  2. go_goroutine backs to normal (~15) immediately if I do systemctl restart caddy

image

  1. Reverted to 0.10.12 fixed the problem.

@Unknwon @seelensonne Thank you both for the fantastic follow-up!! Can you please try this PR and see if it fixes your issue, I highly suspect it will: https://github.com/mholt/caddy/pull/2134

If it does, I'll prioritize getting it merged and getting a new release out.

PR #2134 seems to fix the problem. Thank you so much, @crvv and @mholt!

Below is what Prometheus says about the node_filefd_allocated metric after the patch was deployed around the 3 minute mark (i.e., normal fluctuation as opposed to linear increase caused by 0.10.14):

node_filefd_allocated

For reference:

# Download Caddy and plugins
go get github.com/mholt/caddy/caddy
go get github.com/caddyserver/builds
go get github.com/pyed/ipfilter          # `http.ipfilter` plugin
go get github.com/miekg/caddy-prometheus # `http.prometheus` plugin
cd $GOPATH/src/github.com/mholt/caddy/caddy
git diff caddymain/run.go
diff --git a/caddy/caddymain/run.go b/caddy/caddymain/run.go
index ddc50aa..386240d 100644
--- a/caddy/caddymain/run.go
+++ b/caddy/caddymain/run.go
@@ -35,6 +35,8 @@ import (

        "github.com/mholt/caddy/caddytls"
        // This is where other plugins get plugged in (imported)
+       _ "github.com/miekg/caddy-prometheus"
+       _ "github.com/pyed/ipfilter"
 )

 func init() {
# Apply PR #2134 and build
git fetch origin pull/2134/head:pr2134
git checkout pr2134
go run build.go --goos=linux --goarch=amd64

Phew. That's great to see! Thanks for testing it out, and thanks so much for the patch, @crvv -- I will try to get this in a release ASAP. (In the midst of switching research jobs right now.)

Thanks for the investigations guys. I spent a whole hour trying to figure out why my service was leaking file descriptors.

Was this page helpful?
0 / 5 - 0 ratings