Add admin public_keys through API leads to connection reset

[Desnoo]

Add new public_keys for admin access through API leads to hangup of connection reset.
I try to automate the certificate generation for public_keys so that the certificate will be renewed before it expires.
It works but I receive errors in my nodejs service because of this, because the connection resets. Is there a way for caddy to wait for the request to be answered and then reload the config? Or is there some other better way?

Caddy Version

Caddy Docker image v2.4.1
Modules:

• TLS Consul
• jsonc-adapter

How to Reproduce

1. Start Caddy with secure admin endpoint (mTls)
2. Do a post request to config/admin/remote/access_control/0/public_keys/... to add another trusted cert
3. The caddy server reloads the config and resets open connections

Logs

The logs:

{"level":"info","ts":1622564377.7767856,"logger":"admin.api","msg":"received request","method":"POST","host":"server-09.admin.iroin.io:2021","uri":"/config/admin/remote/access_control/0/public_keys/...","remote_addr":"93.209.12.145:54716","headers":{"Accept-Encoding":["gzip, deflate"],"Connection":["close"],"Content-Length":["1258"],"Content-Type":["application/json"]},"secure":true,"verified_chains":1}
{"level":"info","ts":1622564377.7791572,"logger":"admin","msg":"admin endpoint started","address":"tcp/localhost:2019","enforce_origin":false,"origins":["localhost:2019","[::1]:2019","127.0.0.1:2019"]}
{"level":"info","ts":1622564377.7792363,"logger":"caddy.storage.consul","msg":"TLS storage is using Consul at %!c(string=server_09_consul_consul-node1:8500)s"}
{"level":"info","ts":1622564377.7808118,"logger":"admin","msg":"stopped previous server","address":"tcp/localhost:2019"}
{"level":"warn","ts":1622564377.7862308,"logger":"pki.ca.local-consul","msg":"installing root certificate (you might be prompted for password)","path":"storage:pki/authorities/local-consul/root.crt"}
{"level":"info","ts":1622564377.7862842,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc000193e30"}

[francislavoie]

Are you using Caddy to proxy to your nodejs service which is doing the request to the admin endpoint? If so, then deadlocks are expected. You should only send requests to the admin endpoint from outside of the context of Caddy, so you should do that in an asynchronous job queue or something like that.

If you mean that other connections are being closed when Caddy reloads, that's also expected. There's a configurable grace_period option on the HTTP server which you can use to smooth this over. See https://caddyserver.com/docs/json/apps/http/

[Desnoo]

Thanks for your answer.
No, it is a direct request with no proxy included. The issue is that the connection which changes the admin public_keys is reset/closed. I don't know if this is expected behavior.

I will play around with the grace_period.

Edit:
The grace_period setting did not help for this use case.

Edit2:
As a side note, the delete route has the same behavior. When I try to delete the old public_keys value by the index.

[Desnoo]

Ok I think I tracked down the issue. The connection is not reset, this was some side effect because I was deleting the old public_keys immediately after I added the new one. For this request I used the newly registered cert.

Sorry for this first false flag. And I think this might be the issue. I don't know if I should create a new issue for this?

If I add a new entry to public_keys it will be saved and caddy will reload and starts the secure admin remote control endpoint. But when I request this endpoint with the newly added cert I will get a connection reset error.
The error I receiv is this:

{"level":"debug","ts":1622651275.4135008,"logger":"admin.remote","msg":"http: panic serving <server_ipv4>:6688: close of closed channel\ngoroutine 133 [running]:\nnet/http.(*conn).serve.func1(0xc000742be0)\n\tnet/http/server.go:1824 +0x153\npanic(0x160e9a0, 0x1d89160)\n\truntime/panic.go:971 +0x499\ngithub.com/caddyserver/certmagic.(*Cache).Stop(0xc00021a000)\n\tgithub.com/caddyserver/[email protected]/cache.go:131 +0x2f\ngithub.com/caddyserver/caddy/v2.manageIdentity(0x1dc3770, 0xc0007dee80, 0xc0004f4f30, 0xc00109aa50, 0x0, 0x0, 0x0, 0xc00109aa50, 0x0, 0x0)\n\tgithub.com/caddyserver/caddy/[email protected]/admin.go:406 +0x2b0\ngithub.com/caddyserver/caddy/v2.finishSettingUp(0x1dc3770, 0xc0007dee80, 0xc0004f4f30, 0xc00109aa50, 0x0, 0x0, 0x0, 0xc00109aa50, 0x0, 0x0)\n\tgithub.com/caddyserver/caddy/[email protected]/caddy.go:466 +0x74\ngithub.com/caddyserver/caddy/v2.run(0xc00109aa50, 0x3301, 0x0, 0x0)\n\tgithub.com/caddyserver/caddy/[email protected]/caddy.go:457 +0x3e5\ngithub.com/caddyserver/caddy/v2.unsyncedDecodeAndRun(0xc000362000, 0x33d8, 0x3500, 0x1, 0xc0004f4db0, 0x0)\n\tgithub.com/caddyserver/caddy/[email protected]/caddy.go:276 +0x10f\ngithub.com/caddyserver/caddy/v2.changeConfig(0xc0004125a0, 0x4, 0xc0004125a5, 0x35, 0xc00103a000, 0x4f0, 0x600, 0x400, 0x0, 0x0)\n\tgithub.com/caddyserver/caddy/[email protected]/caddy.go:168 +0x4e5\ngithub.com/caddyserver/caddy/v2.handleConfig(0x1dbcfb0, 0xc0007d8d68, 0xc001026100, 0x0, 0x0)\n\tgithub.com/caddyserver/caddy/[email protected]/admin.go:864 +0x445\ngithub.com/caddyserver/caddy/v2.AdminHandlerFunc.ServeHTTP(0x18de788, 0x1dbcfb0, 0xc0007d8d68, 0xc001026100, 0x18, 0xc0004125a5)\n\tgithub.com/caddyserver/caddy/[email protected]/admin.go:1122 +0x44\ngithub.com/caddyserver/caddy/v2.AdminConfig.newAdminHandler.func2.1(0x1dbcfb0, 0xc0007d8d68, 0xc001026100)\n\tgithub.com/caddyserver/caddy/[email protected]/admin.go:204 +0x94\nnet/http.HandlerFunc.ServeHTTP(0xc000242bd0, 0x1dbcfb0, 0xc0007d8d68, 0xc001026100)\n\tnet/http/server.go:2069 +0x44\ngithub.com/caddyserver/caddy/v2.instrumentHandlerCounter.func1(0x1dbe8a0, 0xc0007208c0, 0xc001026100)\n\tgithub.com/caddyserver/caddy/[email protected]/metrics.go:46 +0xad\nnet/http.HandlerFunc.ServeHTTP(0xc000ad0560, 0x1dbe8a0, 0xc0007208c0, 0xc001026100)\n\tnet/http/server.go:2069 +0x44\nnet/http.(*ServeMux).ServeHTTP(0xc000a40b40, 0x1dbe8a0, 0xc0007208c0, 0xc001026100)\n\tnet/http/server.go:2448 +0x1ad\ngithub.com/caddyserver/caddy/v2.adminHandler.serveHTTP(0xc000a40b40, 0x0, 0x0, 0x0, 0x0, 0xc0010f4000, 0x1dbe8a0, 0xc0007208c0, 0xc001026100)\n\tgithub.com/caddyserver/caddy/[email protected]/admin.go:713 +0x105\ngithub.com/caddyserver/caddy/v2.adminHandler.ServeHTTP(0xc000a40b40, 0x0, 0x0, 0x0, 0x0, 0xc0010f4000, 0x1dbe8a0, 0xc0007208c0, 0xc001026100)\n\tgithub.com/caddyserver/caddy/[email protected]/admin.go:665 +0x5d9\nnet/http.serverHandler.ServeHTTP(0xc00112c8c0, 0x1dbe8a0, 0xc0007208c0, 0xc001026100)\n\tnet/http/server.go:2887 +0xa3\nnet/http.(*conn).serve(0xc000742be0, 0x1dc3818, 0xc0007debc0)\n\tnet/http/server.go:1952 +0x8cd\ncreated by net/http.(*Server).Serve\n\tnet/http/server.go:3013 +0x39b"}

But when I restart the caddy server all works fine.

[francislavoie]

http: panic serving <server_ipv4>:6688: close of closed channel

That's interesting. Definitely looks like a bug there. /cc @mholt

[mholt]

Thanks, will look into it when I get a chance 👍 I have a hunch as to what causes it.

[mholt]

@Desnoo Based on my hunch, the commit in the fix-admin-cert-cache branch might fix it: https://github.com/caddyserver/caddy/tree/fix-admin-cert-cache -- but I've been pretty busy today and haven't had a chance to test it. Could you give it a try and see how it goes? (I might be totally off base, but in my head the logic of the change makes sense.)

[Desnoo]

@mholt I did test it and it works perfectly fine now 👍🏻 . Thank you!
Will close it with this comment, if it is ok.