Thanks for your replies Francis and Dave!
The container accessibility is less of an issue as I’m running it in --network host
mode anyways.
Regarding idle timeout I’d prefer to keep using a Caddyfile, the JSON equivalent is not very user friendly in comparison.
So I followed your advice to check some stats:
pprof
$ docker exec -it caddy sh
$ apk add --update go
$ go tool pprof 127.0.0.1:2019/debug/pprof/heap
(pprof) top
Showing nodes accounting for 426.85MB, 90.56% of 471.35MB total
Dropped 57 nodes (cum <= 2.36MB)
Showing top 10 nodes out of 97
flat flat% sum% cum cum%
177.89MB 37.74% 37.74% 177.89MB 37.74% crypto/tls.(*halfConn).encrypt
140.84MB 29.88% 67.62% 285.17MB 60.50% net/http.(*http2Framer).WriteDataPadded
32.52MB 6.90% 74.52% 32.52MB 6.90% vendor/golang.org/x/net/http2/hpack.(*headerFieldTable).addEntry
19.02MB 4.04% 78.56% 19.02MB 4.04% bytes.makeSlice
16.50MB 3.50% 82.06% 41.51MB 8.81% net/http.(*http2Server).ServeConn
12.01MB 2.55% 84.61% 12.01MB 2.55% crypto/tls.Server
7.53MB 1.60% 86.20% 7.53MB 1.60% bufio.NewReaderSize
7MB 1.49% 87.69% 7.50MB 1.59% net/http.(*http2serverConn).canonicalHeader
7MB 1.49% 89.17% 7MB 1.49% runtime.malg
6.53MB 1.38% 90.56% 6.53MB 1.38% bufio.NewWriterSize
Note that it says something about 471.35MB total
, while docker stats
shows already more than 800 MB for the Caddy container (started ~24h ago). Or is the profile one just the total allocations from a limited duration like 10s or something?
Another one:
(pprof) top 20 -cum
Showing nodes accounting for 337.73MB, 71.65% of 471.35MB total
Dropped 57 nodes (cum <= 2.36MB)
Showing top 20 nodes out of 97
flat flat% sum% cum cum%
0 0% 0% 296.17MB 62.83% net/http.(*http2serverConn).writeFrameAsync
0 0% 0% 285.17MB 60.50% net/http.(*http2Framer).WriteData (inline)
140.84MB 29.88% 29.88% 285.17MB 60.50% net/http.(*http2Framer).WriteDataPadded
0 0% 29.88% 285.17MB 60.50% net/http.(*http2writeData).writeFrame
0 0% 29.88% 177.89MB 37.74% crypto/tls.(*Conn).writeRecordLocked
177.89MB 37.74% 67.62% 177.89MB 37.74% crypto/tls.(*halfConn).encrypt
0 0% 67.62% 177.39MB 37.63% bufio.(*Writer).Write
0 0% 67.62% 177.39MB 37.63% crypto/tls.(*Conn).Write
0 0% 67.62% 144.33MB 30.62% net/http.(*http2Framer).endWrite
0 0% 67.62% 144.33MB 30.62% net/http.(*http2bufferedWriter).Write
1.50MB 0.32% 67.94% 87.74MB 18.61% net/http.(*conn).serve
16.50MB 3.50% 71.44% 41.51MB 8.81% net/http.(*http2Server).ServeConn
0 0% 71.44% 41.51MB 8.81% net/http.http2ConfigureServer.func1
1MB 0.21% 71.65% 38.53MB 8.17% net/http.(*http2serverConn).readFrames
0 0% 71.65% 37.53MB 7.96% net/http.(*http2Framer).ReadFrame
0 0% 71.65% 34.06MB 7.23% github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).enforcementHandler
0 0% 71.65% 34.06MB 7.23% github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).wrapPrimaryRoute.func1
0 0% 71.65% 34.06MB 7.23% github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Subroute).ServeHTTP
0 0% 71.65% 34.06MB 7.23% github.com/caddyserver/caddy/v2/modules/caddyhttp.(*metricsInstrumentedHandler).ServeHTTP
0 0% 71.65% 34.06MB 7.23% github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP
Caddy metrics
I’m not sure what I personally could see from periodically getting data from the metrics endpoint other than that the memory usage is constantly increasing, but maybe a snapshot of just now makes you see something interesting?
$ docker exec -it caddy sh
$ apk add --update curl
$ curl "localhost:2019/metrics"
# HELP go_build_info Build information about the main Go module.
# TYPE go_build_info gauge
go_build_info{checksum="",path="caddy",version="(devel)"} 1
# HELP go_gc_duration_seconds A summary of the pause duration of garbage collection cycles.
# TYPE go_gc_duration_seconds summary
go_gc_duration_seconds{quantile="0"} 0.000874646
go_gc_duration_seconds{quantile="0.25"} 0.001226682
go_gc_duration_seconds{quantile="0.5"} 0.001450993
go_gc_duration_seconds{quantile="0.75"} 0.00208208
go_gc_duration_seconds{quantile="1"} 0.015850969
go_gc_duration_seconds_sum 1.610284799
go_gc_duration_seconds_count 791
# HELP go_goroutines Number of goroutines that currently exist.
# TYPE go_goroutines gauge
go_goroutines 21619
# HELP go_info Information about the Go environment.
# TYPE go_info gauge
go_info{version="go1.15.2"} 1
# HELP go_memstats_alloc_bytes Number of bytes allocated and still in use.
# TYPE go_memstats_alloc_bytes gauge
go_memstats_alloc_bytes 5.19931992e+08
# HELP go_memstats_alloc_bytes_total Total number of bytes allocated, even if freed.
# TYPE go_memstats_alloc_bytes_total counter
go_memstats_alloc_bytes_total 2.0389939544e+10
# HELP go_memstats_buck_hash_sys_bytes Number of bytes used by the profiling bucket hash table.
# TYPE go_memstats_buck_hash_sys_bytes gauge
go_memstats_buck_hash_sys_bytes 1.779018e+06
# HELP go_memstats_frees_total Total number of frees.
# TYPE go_memstats_frees_total counter
go_memstats_frees_total 1.58289168e+08
# HELP go_memstats_gc_cpu_fraction The fraction of this program's available CPU time used by the GC since the program started.
# TYPE go_memstats_gc_cpu_fraction gauge
go_memstats_gc_cpu_fraction 0.0007892310368506903
# HELP go_memstats_gc_sys_bytes Number of bytes used for garbage collection system metadata.
# TYPE go_memstats_gc_sys_bytes gauge
go_memstats_gc_sys_bytes 3.3228432e+07
# HELP go_memstats_heap_alloc_bytes Number of heap bytes allocated and still in use.
# TYPE go_memstats_heap_alloc_bytes gauge
go_memstats_heap_alloc_bytes 5.19931992e+08
# HELP go_memstats_heap_idle_bytes Number of heap bytes waiting to be used.
# TYPE go_memstats_heap_idle_bytes gauge
go_memstats_heap_idle_bytes 6.3791104e+07
# HELP go_memstats_heap_inuse_bytes Number of heap bytes that are in use.
# TYPE go_memstats_heap_inuse_bytes gauge
go_memstats_heap_inuse_bytes 5.31832832e+08
# HELP go_memstats_heap_objects Number of allocated objects.
# TYPE go_memstats_heap_objects gauge
go_memstats_heap_objects 1.48127e+06
# HELP go_memstats_heap_released_bytes Number of heap bytes released to OS.
# TYPE go_memstats_heap_released_bytes gauge
go_memstats_heap_released_bytes 5.8384384e+07
# HELP go_memstats_heap_sys_bytes Number of heap bytes obtained from system.
# TYPE go_memstats_heap_sys_bytes gauge
go_memstats_heap_sys_bytes 5.95623936e+08
# HELP go_memstats_last_gc_time_seconds Number of seconds since 1970 of last garbage collection.
# TYPE go_memstats_last_gc_time_seconds gauge
go_memstats_last_gc_time_seconds 1.6024421545144086e+09
# HELP go_memstats_lookups_total Total number of pointer lookups.
# TYPE go_memstats_lookups_total counter
go_memstats_lookups_total 0
# HELP go_memstats_mallocs_total Total number of mallocs.
# TYPE go_memstats_mallocs_total counter
go_memstats_mallocs_total 1.59770438e+08
# HELP go_memstats_mcache_inuse_bytes Number of bytes in use by mcache structures.
# TYPE go_memstats_mcache_inuse_bytes gauge
go_memstats_mcache_inuse_bytes 3472
# HELP go_memstats_mcache_sys_bytes Number of bytes used for mcache structures obtained from system.
# TYPE go_memstats_mcache_sys_bytes gauge
go_memstats_mcache_sys_bytes 16384
# HELP go_memstats_mspan_inuse_bytes Number of bytes in use by mspan structures.
# TYPE go_memstats_mspan_inuse_bytes gauge
go_memstats_mspan_inuse_bytes 5.2734e+06
# HELP go_memstats_mspan_sys_bytes Number of bytes used for mspan structures obtained from system.
# TYPE go_memstats_mspan_sys_bytes gauge
go_memstats_mspan_sys_bytes 5.40672e+06
# HELP go_memstats_next_gc_bytes Number of heap bytes when next garbage collection will take place.
# TYPE go_memstats_next_gc_bytes gauge
go_memstats_next_gc_bytes 9.902528e+08
# HELP go_memstats_other_sys_bytes Number of bytes used for other system allocations.
# TYPE go_memstats_other_sys_bytes gauge
go_memstats_other_sys_bytes 4.19239e+06
# HELP go_memstats_stack_inuse_bytes Number of bytes in use by the stack allocator.
# TYPE go_memstats_stack_inuse_bytes gauge
go_memstats_stack_inuse_bytes 2.76791296e+08
# HELP go_memstats_stack_sys_bytes Number of bytes obtained from system for stack allocator.
# TYPE go_memstats_stack_sys_bytes gauge
go_memstats_stack_sys_bytes 2.76791296e+08
# HELP go_memstats_sys_bytes Number of bytes obtained from system.
# TYPE go_memstats_sys_bytes gauge
go_memstats_sys_bytes 9.17038176e+08
# HELP go_threads Number of OS threads created.
# TYPE go_threads gauge
go_threads 12
# HELP process_cpu_seconds_total Total user and system CPU time spent in seconds.
# TYPE process_cpu_seconds_total counter
process_cpu_seconds_total 2590.51
# HELP process_max_fds Maximum number of open file descriptors.
# TYPE process_max_fds gauge
process_max_fds 1.048576e+06
# HELP process_open_fds Number of open file descriptors.
# TYPE process_open_fds gauge
process_open_fds 11997
# HELP process_resident_memory_bytes Resident memory size in bytes.
# TYPE process_resident_memory_bytes gauge
process_resident_memory_bytes 8.80504832e+08
# HELP process_start_time_seconds Start time of the process since unix epoch in seconds.
# TYPE process_start_time_seconds gauge
process_start_time_seconds 1.60234782852e+09
# HELP process_virtual_memory_bytes Virtual memory size in bytes.
# TYPE process_virtual_memory_bytes gauge
process_virtual_memory_bytes 1.597468672e+09
# HELP process_virtual_memory_max_bytes Maximum amount of virtual memory available in bytes.
# TYPE process_virtual_memory_max_bytes gauge
process_virtual_memory_max_bytes -1
# HELP promhttp_metric_handler_requests_in_flight Current number of scrapes being served.
# TYPE promhttp_metric_handler_requests_in_flight gauge
promhttp_metric_handler_requests_in_flight 1
# HELP promhttp_metric_handler_requests_total Total number of scrapes by HTTP status code.
# TYPE promhttp_metric_handler_requests_total counter
promhttp_metric_handler_requests_total{code="200"} 1
promhttp_metric_handler_requests_total{code="500"} 0
promhttp_metric_handler_requests_total{code="503"} 0
Guess
From the two stats there’s one that pops out: The HTTP/2 TLS encryption and data writing. Or does that look normal?
Let me know if I can deliver any other stats, or run any specific commands to get more info on why the memory usage is so high!
Like how do I find out how many connections there are from Cloudflare to Caddy?