caddypki: Load intermediate for signing on-the-fly

[francislavoie]

Fixes #4517

Big thanks to @maraino for adding an API in smallstep/certificates so that we can fix this

[francislavoie]

So apparently this still isn't working yet.

The callback does get called, but it still provides the old value. Is it because we need to use a pointer receiver for NewAuthority? I'm thinking that's the problem. Does anyone see a different issue?

[mholt]

After discussing with @francislavoie in Slack, I also feel confident that a pointer is necessary here, @ronau -- I think the latest patch has potential to fix the problem unless there's something else going on.

Basically, the closure has access to the original copy of ca since it's not a pointer, but as a pointer, ca is the only copy, and ca.inter gets updated when the intermediate is renewed, as opposed to accessing an old copy of it. It's not obvious a pointer is necessary though since this method doesn't mutate ca directly.

Can you please try it and let us know? Thanks!

[ronau]

Thanks a lot for the explanation!!
The new build is running now. So in a few days I can report back.

[francislavoie]

Re pointer receiver stuff, played around with this playground to prove it to myself that a pointer is needed on the function if a closure defined within reads from the struct: https://go.dev/play/p/9GWIdVOTA6j

[mholt]

This is probably the last remaining big fix I'd like to get in before the release candidate, once we have confirmation it works. 🤞

[ronau]

A quick update:

Until now the intermediate cert has not been renewed (validity: "not_before":"2022-04-06 16:37:55 +0000 UTC","not_after":"2022-04-13 16:37:55 +0000 UTC"), which seems a bit strange to me. I would have expected it to have been renewed in the meantime.

Most recent backend certificate re-issue took place at 16:28 today

2022-04-11T16:28:04.512694975Z 2022/04/11 16:28:04 {"identifier":{"type":"dns","value":"ncweb"},"status":"valid","challenges":[{"type":"dns-01","status":"pending","token":"MAFCg5kMaQ94WVxkWaTWy5o9mbQYVD8A","url":"https://proxy/acme/local/challenge/ql2YjMQYVGN8cXC5xEyv9JmMyG1q7fTn/LFkeRjli23D3rQeCQmf1LvoRQitp77nX"},{"type":"http-01","status":"pending","token":"MAFCg5kMaQ94WVxkWaTWy5o9mbQYVD8A","url":"https://proxy/acme/local/challenge/ql2YjMQYVGN8cXC5xEyv9JmMyG1q7fTn/b770zULYMA4qhWFgjHhMWpNpFnCaDPCz"},{"type":"tls-alpn-01","status":"valid","token":"MAFCg5kMaQ94WVxkWaTWy5o9mbQYVD8A","validated":"2022-04-11T16:28:04Z","url":"https://proxy/acme/local/challenge/ql2YjMQYVGN8cXC5xEyv9JmMyG1q7fTn/biiXZ6CHfEOsTB6bJp9lsO2qU7p1BbtN"}],"wildcard":false,"expires":"2022-04-12T16:28:04Z"}
2022-04-11T16:28:04.540063089Z {"level":"debug","ts":1649694484.5395138,"logger":"pki.ca.local","msg":"using intermediate signer","serial":"131921930849369217822990708607228533826","not_before":"2022-04-06 16:37:55 +0000 UTC","not_after":"2022-04-13 16:37:55 +0000 UTC"}
2022-04-11T16:28:04.560927841Z 2022/04/11 16:28:04 {"id":"ITT10RE2SjGROaph8fauc74B0L548tnU","status":"valid","expires":"2022-04-12T16:28:04Z","identifiers":[{"type":"dns","value":"ncweb"}],"notBefore":"2022-04-11T16:27:04Z","notAfter":"2022-04-12T04:28:04Z","authorizations":["https://proxy/acme/local/authz/ql2YjMQYVGN8cXC5xEyv9JmMyG1q7fTn"],"finalize":"https://proxy/acme/local/order/ITT10RE2SjGROaph8fauc74B0L548tnU/finalize","certificate":"https://proxy/acme/local/certificate/EpB4XMNxcKvFrr2wGoi2KpN6Qa7e9bIg"}

I will wait until tomorrow noon. By then the intermediate for sure should have been renewed, I suppose.
Then I will restart both the frontend and the backend Caddyserver.

Maybe you can reopen the topic over there at the community forum?

[mholt]

Great, thanks for the update. I suppose it's been 4-ish days since it was issued, and 2/3 through its lifetime would be about 4.6 days, so... yeah, hopefully by tomorrow afternoon. Maybe just a smidgin too early... thanks for keeping us posted! (Forum topic reopened btw.)

[francislavoie]

Maybe you can reopen the topic over there at the community forum?

Sorry about that, I reopened it and picked "in two weeks" thinking that would be enough time to do a round of testing 😂 guess it didn't work the first time.

Your testing is super appreciated @ronau, thank you!

[ronau]

Ok, so yesterday I didn't manage to have a look.

Anyway, I've got some good news.

Here's the most recent renewal of the intermediate cert:

2022-04-12T07:07:54.048745920Z {"level":"info","ts":1649747274.0444179,"logger":"pki","msg":"intermediate expires soon; renewing","ca":"local","time_remaining":120600.955587527}
2022-04-12T07:07:54.050287506Z {"level":"info","ts":1649747274.0500102,"logger":"pki","msg":"renewed intermediate","ca":"local","new_expiration":1650352074}
// "new_expiration":1650352074  --> Tue Apr 19 07:07:54 2022 UTC

About an hour later, the acme server reissued the backend caddy's certificate, this time with the new intermediate:

2022-04-12T08:28:04.507624329Z 2022/04/12 08:28:04 {"identifier":{"type":"dns","value":"ncweb"},"status":"valid","challenges":[{"type":"dns-01","status":"pending","token":"zegOBYXjMY48ilWYT9EM9kuSKqGK9BNq","url":"https://proxy/acme/local/challenge/UyFrjLuKuAoGqN33ceUb9UlalBYmKH5z/CKmJj2P8zJs9RzMLkX88MOj7aAUITX3i"},{"type":"http-01","status":"pending","token":"zegOBYXjMY48ilWYT9EM9kuSKqGK9BNq","url":"https://proxy/acme/local/challenge/UyFrjLuKuAoGqN33ceUb9UlalBYmKH5z/mxboo6kGWQbBkBbdmRphYaNtOHba5DwD"},{"type":"tls-alpn-01","status":"valid","token":"zegOBYXjMY48ilWYT9EM9kuSKqGK9BNq","validated":"2022-04-12T08:28:04Z","url":"https://proxy/acme/local/challenge/UyFrjLuKuAoGqN33ceUb9UlalBYmKH5z/Ho0KMzMtyIMHcQSMbLOsMt1GYR77n4bI"}],"wildcard":false,"expires":"2022-04-13T08:28:04Z"}
2022-04-12T08:28:04.533885727Z {"level":"debug","ts":1649752084.5334518,"logger":"pki.ca.local","msg":"using intermediate signer","serial":"66872705317182381873319979057422166194","not_before":"2022-04-12 07:07:54 +0000 UTC","not_after":"2022-04-19 07:07:54 +0000 UTC"}
2022-04-12T08:28:04.552909529Z 2022/04/12 08:28:04 {"id":"iyh5mQuRMxoQHREHnh80P8BcrOD5iO3l","status":"valid","expires":"2022-04-13T08:28:04Z","identifiers":[{"type":"dns","value":"ncweb"}],"notBefore":"2022-04-12T08:27:04Z","notAfter":"2022-04-12T20:28:04Z","authorizations":["https://proxy/acme/local/authz/UyFrjLuKuAoGqN33ceUb9UlalBYmKH5z"],"finalize":"https://proxy/acme/local/order/iyh5mQuRMxoQHREHnh80P8BcrOD5iO3l/finalize","certificate":"https://proxy/acme/local/certificate/Lqdb4L0XwhXPKTnNKDYavo313p8ZO2T4"}

So seems like the fix really did it!!!

[francislavoie]

🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉

Thanks so much for your patience with this @ronau!

We'll get this merged in for v2.5.0 (but first I might remove some of the debug logs, maybe I'll keep them, idk, WDYT @mholt)

[mholt]

LGTM. Thank you very much for your testing, @ronau , and for the patch, @francislavoie -- nice job figuring out the pointer receiver. And thanks to the Smallstep team for their support.

Francis, we can merge this but I do want to add a comment explaining the nuance of using a pointer receiver here if that's alright.