panic in Caddy plugin
knadh opened this issue · 6 comments
Hi @darkweak. The following configuration runs fine and after an arbitrary time handling traffic, panics and crashes Caddy. I'm using the latest build created with xcaddy build --with github.com/darkweak/souin/plugins/caddy --with github.com/darkweak/souin
$ ./caddy --version
v2.7.6 h1:w0NymbG2m9PcvKWsrXO6EEkY9Ru4FJK8uQbYcev1p3A=
{
order cache before rewrite
cache {
allowed_http_verbs GET
ttl 86400s
cache_name mysite
badger {
path /var/lib/caddy/cache
}
regex {
exclude /tl/*
exclude /atl/*
}
}
}
http://mysite.com {
cache
### Static file downloads
handle_path /files* {
root * /home/site/www/files
file_server
}
@r1 path_regexp params /old/path/(.*)/?
redir @r1 /new/path/{re.params.1} permanent
redir /open /p/open permanent
redir /open/ /p/open permanent
reverse_proxy /tl/* localhost:8123
reverse_proxy /atl/* localhost:8123
reverse_proxy localhost:9000
encode gzip
tls {
on_demand
}
}
fatal error: concurrent map writes
goroutine 11034729 [running]:
github.com/caddyserver/caddy/v2.(*Replacer).Set(...)
github.com/caddyserver/caddy/v2@v2.7.6/replacer.go:68
github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*Handler).ServeHTTP.func1()
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/reverseproxy/reverseproxy.go:433 +0x139
github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*Handler).ServeHTTP(0xc00020cf00, {0x25ba230, 0xc01e9613b0}, 0xc0219fdd00, {0x25ab900, 0x22f9340})
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/reverseproxy/reverseproxy.go:454 +0x44c
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1({0x25ba230?, 0xc01e9613b0?}, 0x25ab900?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:331 +0x3a
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x25ab900?, {0x25ba230?, 0xc01e9613b0?}, 0xc00067f300?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp.RouteList.Compile.wrapRoute.func1.1({0x25ba230, 0xc01e9613b0}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:300 +0x2c9
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x25c08c0?, {0x25ba230?, 0xc01e9613b0?}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp.RouteList.Compile.wrapRoute.func1.1({0x25ba230, 0xc01e9613b0}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:268 +0x264
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x25c08c0?, {0x25ba230?, 0xc01e9613b0?}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp.RouteList.Compile.wrapRoute.func1.1({0x25ba230, 0xc01e9613b0}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:268 +0x264
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x25c08c0?, {0x25ba230?, 0xc01e9613b0?}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp.RouteList.Compile.wrapRoute.func1.1({0x25ba230, 0xc01e9613b0}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:268 +0x264
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x25c08c0?, {0x25ba230?, 0xc01e9613b0?}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp.RouteList.Compile.wrapRoute.func1.1({0x25ba230, 0xc01e9613b0}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:268 +0x264
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x25c08c0?, {0x25ba230?, 0xc01e9613b0?}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp.RouteList.Compile.wrapRoute.func1.1({0x25ba230, 0xc01e9613b0}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:268 +0x264
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x25c08c0?, {0x25ba230?, 0xc01e9613b0?}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp.RouteList.Compile.wrapRoute.func1.1({0x25ba230, 0xc01e9613b0}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:268 +0x264
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x25c08c0?, {0x25ba230?, 0xc01e9613b0?}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp.RouteList.Compile.wrapRoute.func1.1({0x25ba230, 0xc01e9613b0}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:268 +0x264
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x25c08c0?, {0x25ba230?, 0xc01e9613b0?}, 0xe?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp.RouteList.Compile.wrapRoute.func1.1({0x25ba230, 0xc01e9613b0}, 0xc01e061040?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:268 +0x264
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc02106e410?, {0x25ba230?, 0xc01e9613b0?}, 0x4?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/caddyserver/caddy/v2/modules/caddyhttp/encode.(*Encode).ServeHTTP(0xc00036a180, {0x25b9c80, 0xc0203e6940}, 0xc0219fdd00, {0x25ab900, 0xc01b19d020})
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/encode/encode.go:138 +0x283
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1({0x25b9c80?, 0xc0203e6940?}, 0x0?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/routes.go:331 +0x3a
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0x82?, {0x25b9c80?, 0xc0203e6940?}, 0xc01ee4aa70?)
github.com/caddyserver/caddy/v2@v2.7.6/modules/caddyhttp/caddyhttp.go:58 +0x29
github.com/darkweak/souin/plugins/caddy.(*SouinCaddyMiddleware).ServeHTTP.func1({0x25b9c80?, 0xc0203e6940?}, 0x4e61c5?)
github.com/darkweak/souin/plugins/caddy@v0.0.0-20231130105936-40a16bffcd67/httpcache.go:85 +0x33
github.com/darkweak/souin/pkg/middleware.(*SouinBaseHandler).Upstream.func1()
github.com/darkweak/souin@v1.6.44/pkg/middleware/middleware.go:300 +0x7f
golang.org/x/sync/singleflight.(*Group).doCall.func2(0xc017dc3cc6, 0xc01e961360, 0x7fc8ebf965b8?)
golang.org/x/sync@v0.5.0/singleflight/singleflight.go:198 +0x64
golang.org/x/sync/singleflight.(*Group).doCall(0x1d47580?, 0xc00055c7e0?, {0xc01bf79180?, 0x35?}, 0x40e65a?)
golang.org/x/sync@v0.5.0/singleflight/singleflight.go:200 +0x96
golang.org/x/sync/singleflight.(*Group).Do(0xc0006b4138, {0xc01bf79180, 0x35}, 0x15?)
golang.org/x/sync@v0.5.0/singleflight/singleflight.go:113 +0x15a
github.com/darkweak/souin/pkg/middleware.(*SouinBaseHandler).Upstream(0xc0006b4000, 0xc0203e6940, 0xc0214a2500, 0xc01b19d1a0, 0xc015b15230, {0xc01bf79180, 0x35})
github.com/darkweak/souin@v1.6.44/pkg/middleware/middleware.go:298 +0x246
github.com/darkweak/souin/pkg/middleware.(*SouinBaseHandler).ServeHTTP.func4()
github.com/darkweak/souin@v1.6.44/pkg/middleware/middleware.go:623 +0x38
created by github.com/darkweak/souin/pkg/middleware.(*SouinBaseHandler).ServeHTTP in goroutine 11034627
github.com/darkweak/souin@v1.6.44/pkg/middleware/middleware.go:622 +0x114d
goroutine 1 [select (no cases), 397 minutes]:
github.com/caddyserver/caddy/v2/cmd.cmdRun({0x0?})
github.com/caddyserver/caddy/v2@v2.7.6/cmd/commandfuncs.go:283 +0xc18
github.com/caddyserver/caddy/v2/cmd.init.1.func2.WrapCommandFuncForCobra.func1(0xc000005500, {0x20635a8?, 0x4?, 0x2063584?})
github.com/caddyserver/caddy/v2@v2.7.6/cmd/cobra.go:137 +0x2f
github.com/spf13/cobra.(*Command).execute(0xc000005500, {0xc000559350, 0x3, 0x3})
github.com/spf13/cobra@v1.7.0/command.go:940 +0x87c
github.com/spf13/cobra.(*Command).ExecuteC(0x3667120)
github.com/spf13/cobra@v1.7.0/command.go:1068 +0x3a5
github.com/spf13/cobra.(*Command).Execute(...)
github.com/spf13/cobra@v1.7.0/command.go:992
github.com/caddyserver/caddy/v2/cmd.Main()
github.com/caddyserver/caddy/v2@v2.7.6/cmd/main.go:66 +0x5b
main.main()
caddy/main.go:12 +0xf
goroutine 8 [select]:
github.com/golang/glog.(*fileSink).flushDaemon(0x3689038)
github.com/golang/glog@v1.1.2/glog_file.go:351 +0xb9
created by github.com/golang/glog.init.1 in goroutine 1
github.com/golang/glog@v1.1.2/glog_file.go:166 +0x135
goroutine 13 [select, 397 minutes]:
github.com/caddyserver/certmagic.(*RingBufferRateLimiter).permit(0xc000142500)
github.com/caddyserver/certmagic@v0.20.0/ratelimiter.go:217 +0x86
github.com/caddyserver/certmagic.(*RingBufferRateLimiter).loop(0xc000142500)
github.com/caddyserver/certmagic@v0.20.0/ratelimiter.go:89 +0x8b
created by github.com/caddyserver/certmagic.NewRateLimiter in goroutine 1
github.com/caddyserver/certmagic@v0.20.0/ratelimiter.go:45 +0x13c
goroutine 14 [chan receive, 397 minutes]:
github.com/caddyserver/caddy/v2.trapSignalsCrossPlatform.func1()
github.com/caddyserver/caddy/v2@v2.7.6/sigtrap.go:43 +0xd8
created by github.com/caddyserver/caddy/v2.trapSignalsCrossPlatform in goroutine 1
github.com/caddyserver/caddy/v2@v2.7.6/sigtrap.go:38 +0x1a
goroutine 15 [chan receive, 397 minutes]:
github.com/caddyserver/caddy/v2.trapSignalsPosix.func1()
github.com/caddyserver/caddy/v2@v2.7.6/sigtrap_posix.go:35 +0xfa
created by github.com/caddyserver/caddy/v2.trapSignalsPosix in goroutine 1
github.com/caddyserver/caddy/v2@v2.7.6/sigtrap_posix.go:31 +0x1a
goroutine 19 [syscall, 397 minutes]:
os/signal.signal_recv()
runtime/sigqueue.go:152 +0x29
os/signal.loop()
os/signal/signal_unix.go:23 +0x13
created by os/signal.Notify.func1.1 in goroutine 14
os/signal/signal.go:151 +0x1f
goroutine 20 [select]:
github.com/dgraph-io/badger/v3.(*DB).updateSize(0xc00070cd80, 0xc0005420f0)
github.com/dgraph-io/badger/v3@v3.2103.5/db.go:1171 +0x145
created by github.com/dgraph-io/badger/v3.Open in goroutine 1
github.com/dgraph-io/badger/v3@v3.2103.5/db.go:331 +0xe56
goroutine 36 [IO wait, 397 minutes]:
internal/poll.runtime_pollWait(0x7fc8a53c5f10, 0x72)
runtime/netpoll.go:343 +0x85
internal/poll.(*pollDesc).wait(0xc000634b00?, 0x4161e5?, 0x0)
internal/poll/fd_poll_runtime.go:84 +0x27
internal/poll.(*pollDesc).waitRead(...)
internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Accept(0xc000634b00)
internal/poll/fd_unix.go:611 +0x2ac
net.(*netFD).accept(0xc000634b00)
net/fd_unix.go:172 +0x29
net.(*TCPListener).accept(0xc00053d8e0)
net/tcpsock_posix.go:152 +0x1e
net.(*TCPListener).Accept(0xc00053d8e0)
net/tcpsock.go:315 +0x30
net/http.(*Server).Serve(0xc000364960, {0x7fc8a5131258, 0xc00053d900})
net/http/server.go:3056 +0x364
github.com/caddyserver/caddy/v2.replaceLocalAdminServer.func2()
github.com/caddyserver/caddy/v2@v2.7.6/admin.go:449 +0xc8
created by github.com/caddyserver/caddy/v2.replaceLocalAdminServer in goroutine 1
github.com/caddyserver/caddy/v2@v2.7.6/admin.go:445 +0x4a6
goroutine 37 [select, 9 minutes]:
github.com/caddyserver/certmagic.(*Cache).maintainAssets(0xc000634b80, 0x0)
github.com/caddyserver/certmagic@v0.20.0/maintain.go:69 +0x305
created by github.com/caddyserver/certmagic.NewCache in goroutine 1
github.com/caddyserver/certmagic@v0.20.0/cache.go:127 +0x1f6
goroutine 38 [select]:
github.com/dgraph-io/badger/v3/y.(*WaterMark).process(0xc00056a2d0, 0xc00056a2a0)
github.com/dgraph-io/badger/v3@v3.2103.5/y/watermark.go:214 +0x285
created by github.com/dgraph-io/badger/v3/y.(*WaterMark).Init in goroutine 1
github.com/dgraph-io/badger/v3@v3.2103.5/y/watermark.go:72 +0xa7
goroutine 39 [select]:
github.com/dgraph-io/badger/v3/y.(*WaterMark).process(0xc00056a300, 0xc00056a2a0)
github.com/dgraph-io/badger/v3@v3.2103.5/y/watermark.go:214 +0x285
created by github.com/dgraph-io/badger/v3/y.(*WaterMark).Init in goroutine 1
github.com/dgraph-io/badger/v3@v3.2103.5/y/watermark.go:72 +0xa7
goroutine 40 [select]:
github.com/dgraph-io/ristretto/z.(*AllocatorPool).freeupAllocators(0xc000028120)
github.com/dgraph-io/ristretto@v0.1.1/z/allocator.go:385 +0x11f
created by github.com/dgraph-io/ristretto/z.NewAllocatorPool in goroutine 1
github.com/dgraph-io/ristretto@v0.1.1/z/allocator.go:324 +0xb9
goroutine 41 [select, 397 minutes]:
github.com/dgraph-io/ristretto.(*defaultPolicy).processItems(0xc00035e1c0)
github.com/dgraph-io/ristretto@v0.1.1/policy.go:102 +0x85
created by github.com/dgraph-io/ristretto.newDefaultPolicy in goroutine 1
github.com/dgraph-io/ristretto@v0.1.1/policy.go:86 +0x139
goroutine 42 [select]:
github.com/dgraph-io/ristretto.(*Cache).processItems(0xc000700b80)
github.com/dgraph-io/ristretto@v0.1.1/cache.go:452 +0x149
created by github.com/dgraph-io/ristretto.NewCache in goroutine 1
github.com/dgraph-io/ristretto@v0.1.1/cache.go:207 +0x645
goroutine 43 [select]:
github.com/dgraph-io/badger/v3.(*DB).monitorCache(0xc00070cd80, 0xc000519b90)
github.com/dgraph-io/badger/v3@v3.2103.5/db.go:469 +0x170
created by github.com/dgraph-io/badger/v3.Open in goroutine 1
github.com/dgraph-io/badger/v3@v3.2103.5/db.go:311 +0xc49
goroutine 44 [select]:
github.com/dgraph-io/badger/v3.(*levelsController).runCompactor(0xc00027e5b0, 0x0, 0xc000519bc0)
github.com/dgraph-io/badger/v3@v3.2103.5/levels.go:508 +0x2e9
created by github.com/dgraph-io/badger/v3.(*levelsController).startCompact in goroutine 1
github.com/dgraph-io/badger/v3@v3.2103.5/levels.go:354 +0x4b
goroutine 45 [select]:
github.com/dgraph-io/badger/v3.(*levelsController).runCompactor(0xc00027e5b0, 0x1, 0xc000519bc0)
github.com/dgraph-io/badger/v3@v3.2103.5/levels.go:508 +0x2e9
created by github.com/dgraph-io/badger/v3.(*levelsController).startCompact in goroutine 1
github.com/dgraph-io/badger/v3@v3.2103.5/levels.go:354 +0x4b
goroutine 46 [select]:
github.com/dgraph-io/badger/v3.(*levelsController).runCompactor(0xc00027e5b0, 0x2, 0xc000519bc0)
github.com/dgraph-io/badger/v3@v3.2103.5/levels.go:508 +0x2e9
created by github.com/dgraph-io/badger/v3.(*levelsController).startCompact in goroutine 1
github.com/dgraph-io/badger/v3@v3.2103.5/levels.go:354 +0x4b
goroutine 47 [select]:
github.com/dgraph-io/badger/v3.(*levelsController).runCompactor(0xc00027e5b0, 0x3, 0xc000519bc0)
github.com/dgraph-io/badger/v3@v3.2103.5/levels.go:508 +0x2e9
created by github.com/dgraph-io/badger/v3.(*levelsController).startCompact in goroutine 1
github.com/dgraph-io/badger/v3@v3.2103.5/levels.go:354 +0x4b
goroutine 48 [chan receive, 397 minutes]:
github.com/dgraph-io/badger/v3.(*DB).flushMemtable(0xc00070cd80, 0xc00056a2a0?)
github.com/dgraph-io/badger/v3@v3.2103.5/db.go:1078 +0xa5
github.com/dgraph-io/badger/v3.Open.func5()
....
Hi @knadh thank you for your issue. The panic comes from the singleflight package, I have to check why that happens, which "map" is concurrently accessed/written. That's a high priority bugfix.
It would be great to have a reproducible test case 🙂
This is from a site that receives few a thousand requests per minute. Have been unable to pinpoint what triggers this, unfortunately. Sometimes it's a few seconds between crashes, sometimes it's half an hour. I've disabled caching altogether.
I will use the stress tests to debug that then.
@knadh
try changing to nutsdb or redis, crash caddy should not occur. I tested under heavy load.
With this config
cache {
nuts {
path /tmp/nuts-path
}
}