search

caddyserver / caddy

Fast and extensible multi-platform HTTP/1-2-3 web server with automatic HTTPS
https://caddyserver.com
Apache License 2.0
58.52k stars 4.04k forks source link

Failed DNS challenge (DNS-01) on Caddy >=v2.8.0 #6557

Open MyAnoneNeko opened 2 months ago

MyAnoneNeko commented 2 months ago

1. Environment

1a. Operating system and version

Windows 10

1b. Caddy version (run caddy version or paste commit SHA)

v2.8.4 h1:q3pe0wpBj1OcHFZ3n/1nl4V4bxBrYoSoab7rL9BMYNk=

1c. Go version (if building Caddy from source; run go version)

go version go1.23.0 windows/amd64

2. Description

2a. What happens (briefly explain what is wrong)

Caddy v2.8.4 fails DNS challenge on subdomain zone.

2b. Why it's a bug (if it's not obvious)

If I downgrade to Caddy v2.7.6, Caddy is able to pass DNS challenge. The earliest version I observed this issue is on Caddy v2.8.0. I noticed in the logs when Caddy fails DNS challenge, there is no wait between waiting for solver before continuing and done waiting for solver. When Caddy passed DNS challenge, the wait is over a minute.

2c. Log output

Failed to pass challenge to obtain certificate

>caddy run
2024/09/02 16:50:53.646 INFO    using adjacent Caddyfile
2024/09/02 16:50:53.648 INFO    adapted config to JSON  {"adapter": "caddyfile"}
2024/09/02 16:50:53.653 INFO    admin   admin endpoint started  {"address": "localhost:2019", "enforce_origin": false, "origins": ["//127.0.0.1:2019", "//localhost:2019", "//[::1]:2019"]}
2024/09/02 16:50:53.653 INFO    tls.cache.maintenance   started background certificate maintenance      {"cache": "0xc0002ed480"}
2024/09/02 16:50:53.653 INFO    http.auto_https server is listening only on the HTTPS port but has no TLS co
                                                {"server_name": "srv0", "https_port": 443}
2024/09/02 16:50:53.654 INFO    http.auto_https enabling automatic HTTP->HTTPS redirects        {"server_name": "srv0"}
2024/09/02 16:50:53.654 DEBUG   http.auto_https adjusted config {"tls": {"automation":{"policies":[{"subjects":["*.ip.geah.dedyn.io"]},{}]}}, "http": {"servers":{"remaining_auto_https_redirects":{"listen":[":80"],"routes":[{},{}]},"srv0":{"listen":[":443"],"routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"body":"git gud","close":true,"handler":"static_response","status_code":403}]}]}]}]}],"terminal":true}],"tls_connection_policies":[{}],"automatic_https":{}}}}}
2024/09/02 16:50:53.655 INFO    http    enabling HTTP/3 listener        {"addr": ":443"}
2024/09/02 16:50:53.655 DEBUG   http    starting server loop    {"address": "[::]:443", "tls": true, "http3": true}
2024/09/02 16:50:53.656 INFO    http.log        server running  {"name": "srv0", "protocols": ["h1", "h2", "h3"]}
2024/09/02 16:50:53.656 DEBUG   http    starting server loop    {"address": "[::]:80", "tls": false, "http3": false}
2024/09/02 16:50:53.656 INFO    http.log        server running  {"name": "remaining_auto_https_redirects", "protocols": ["h1", "h2", "h3"]}
2024/09/02 16:50:53.656 INFO    http    enabling automatic TLS certificate management   {"domains": ["*.ip.geah.dedyn.io"]}
2024/09/02 16:50:53.657 INFO    autosaved config (load with --resume flag)      {"file": "C:\\Users\\USER\\AppData\\Roaming\\Caddy\\autosave.json"}
2024/09/02 16:50:53.657 INFO    serving initial configuration
2024/09/02 16:50:53.658 INFO    tls.obtain      acquiring lock  {"identifier": "*.ip.geah.dedyn.io"}
2024/09/02 16:50:53.660 INFO    tls     cleaning storage unit   {"storage": "FileStorage:C:\\Users\\USER\\AppData\\Roaming\\Caddy"}
2024/09/02 16:50:53.660 INFO    tls     finished cleaning storage units
2024/09/02 16:50:53.663 INFO    tls.obtain      lock acquired   {"identifier": "*.ip.geah.dedyn.io"}
2024/09/02 16:50:53.664 INFO    tls.obtain      obtaining certificate   {"identifier": "*.ip.geah.dedyn.io"}

2024/09/02 16:50:53.664 DEBUG   events  event   {"name": "cert_obtaining", "id": "86910c76-a410-494b-a58c-3cd6a8f2f528", "origin": "tls", "data": {"identifier":"*.ip.geah.dedyn.io"}}
2024/09/02 16:50:53.665 DEBUG   tls.obtain      trying issuer 1/1       {"issuer": "acme-staging-v02.api.letsencrypt.org-directory"}
2024/09/02 16:50:53.840 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "GET", "url": "https://acme-staging-v02.api.letsencrypt.org/directory", "headers": {"User-Agent":["Caddy/2.8.4 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["820"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 16:50:53 GMT"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 16:50:53.885 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "HEAD", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-nonce", "headers": {"User-Agent":["Caddy/2.8.4 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Date":["Mon, 02 Sep 2024 16:50:53 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["vfo-J0TvQH5xrufsp6UPS0JkhFILMFJcxlaDyMgC9_5DcpUqvVM"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 16:50:53.948 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-acct", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.8.4 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161747223"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["266"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 16:50:53 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://letsencrypt.org/documents/LE-SA-v1.4-April-3-2024.pdf>;rel=\"terms-of-service\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/acct/161747223"],"Replay-Nonce":["VFujB6i1a6ggKMnolL_sC3DYH_jRgYBlp2bHgIpyMyKD4V3c5Lk"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 201}
2024/09/02 16:50:53.950 INFO    tls.issuance.acme       waiting on internal rate limiter        {"identifiers": ["*.ip.geah.dedyn.io"], "ca": "https://acme-staging-v02.api.letsencrypt.org/directory", "account": ""}
2024/09/02 16:50:53.950 INFO    tls.issuance.acme       done waiting on internal rate limiter   {"identifiers": ["*.ip.geah.dedyn.io"], "ca": "https://acme-staging-v02.api.letsencrypt.org/directory", "account": ""}
2024/09/02 16:50:53.951 INFO    tls.issuance.acme       using ACME account      {"account_id": "https://acme-staging-v02.api.letsencrypt.org/acme/acct/161747223", "account_contact": []}
2024/09/02 16:50:53.951 DEBUG   tls.issuance.acme.acme_client   creating order  {"account": "https://acme-staging-v02.api.letsencrypt.org/acme/acct/161747223", "identifiers": ["*.ip.geah.dedyn.io"]}
2024/09/02 16:50:54.036 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-order", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.8.4 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161747223"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["357"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 16:50:54 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/order/161747223/18823269933"],"Replay-Nonce":["vfo-J0TvGi4ytZ7PSNCAMAW5bgQ2Fc4DgnsqDMlQvdaATYX_AX4"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 201}
2024/09/02 16:50:54.091 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/13841942583", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.8.4 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161747223"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["397"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 16:50:54 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["VFujB6i1Amy-eaXIDw8ISLDiC1LpSyZTTBazKvDb-vbAZz1DRmg"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 16:50:54.092 INFO    tls.issuance.acme.acme_client   trying to solve challenge       {"identifier": "*.ip.geah.dedyn.io", "challenge_type": "dns-01", "ca": "https://acme-staging-v02.api.letsencrypt.org/directory"}
2024/09/02 16:50:55.340 DEBUG   tls.issuance.acme.acme_client   waiting for solver before continuing    {"identifier": "*.ip.geah.dedyn.io", "challenge_type": "dns-01"}
2024/09/02 16:50:55.340 DEBUG   tls.issuance.acme.acme_client   done waiting for solver {"identifier": "*.ip.geah.dedyn.io", "challenge_type": "dns-01"}
2024/09/02 16:50:55.341 ERROR   tls.issuance.acme.acme_client   cleaning up solver      {"identifier": "*.ip.geah.dedyn.io", "challenge_type": "dns-01", "error": "no memory of presenting a DNS record for \"_acme-challenge.ip.geah.dedyn.io\" (usually OK if presenting also failed)"}
2024/09/02 16:50:55.398 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/13841942583", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.8.4 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161747223"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["401"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 16:50:55 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["vfo-J0TvBRkESp3By7BnE5HU_PJ4_sPfSSFT-h_ivU495WT3Cfo"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 16:50:55.398 ERROR   tls.obtain      could not get certificate from issuer   {"identifier": "*.ip.geah.dedyn.io", "issuer": "acme-staging-v02.api.letsencrypt.org-directory", "error": "[*.ip.geah.dedyn.io] solving challenges: waiting for solver certmagic.solverWrapper to be ready: no memory of presenting a DNS record for \"_acme-challenge.ip.geah.dedyn.io\" (usually OK if presenting also failed) (order=https://acme-staging-v02.api.letsencrypt.org/acme/order/161747223/18823269933) (ca=https://acme-staging-v02.api.letsencrypt.org/directory)"}
2024/09/02 16:50:55.398 DEBUG   events  event   {"name": "cert_failed", "id": "5958c392-b3c6-4e9a-870b-478ccaaf2570", "origin": "tls", "data": {"error":{},"identifier":"*.ip.geah.dedyn.io","issuers":["acme-staging-v02.api.letsencrypt.org-directory"],"renewal":false}}
2024/09/02 16:50:55.399 ERROR   tls.obtain      will retry      {"error": "[*.ip.geah.dedyn.io] Obtain: [*.ip.geah.dedyn.io] solving challenges: waiting for solver certmagic.solverWrapper to be ready: no memory of presenting a DNS record for \"_acme-challenge.ip.geah.dedyn.io\" (usually OK if presenting also failed) (order=https://acme-staging-v02.api.letsencrypt.org/acme/order/161747223/18823269933) (ca=https://acme-staging-v02.api.letsencrypt.org/directory)", "attempt": 1, "retrying_in": 60, "elapsed": 1.7349832, "max_duration": 2592000}
2024/09/02 16:51:40.563 INFO    shutting down   {"signal": "SIGINT"}
2024/09/02 16:51:40.563 WARN    exiting; byeee!! �     {"signal": "SIGINT"}
2024/09/02 16:51:40.563 INFO    http    servers shutting down with eternal grace period
2024/09/02 16:51:40.563 INFO    tls.obtain      releasing lock  {"identifier": "*.ip.geah.dedyn.io"}
2024/09/02 16:51:40.564 INFO    admin   stopped previous server {"address": "localhost:2019"}
2024/09/02 16:51:40.564 INFO    shutdown complete       {"signal": "SIGINT", "exit_code": 0)

Successfully pass challenge and obtained certificate

>caddy run
2024/09/02 05:20:05.288 INFO    using adjacent Caddyfile
2024/09/02 05:20:05.295 INFO    admin   admin endpoint started  {"address": "localhost:2019", "enforce_origin": false, "origins": ["//localhost:2019", "//[::1]:2019", "//127.0.0.1:2019"]}
2024/09/02 05:20:05.296 INFO    tls.cache.maintenance   started background certificate maintenance      {"cache": "0xc0005ab480"}
2024/09/02 05:20:05.296 INFO    http.auto_https server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS {"server_name": "srv0", "https_port": 443}
2024/09/02 05:20:05.296 INFO    http.auto_https enabling automatic HTTP->HTTPS redirects        {"server_name": "srv0"}
2024/09/02 05:20:05.297 DEBUG   http.auto_https adjusted config {"tls": {"automation":{"policies":[{"subjects":["*.ip.geah.dedyn.io"]},{}]}}, "http": {"servers":{"remaining_auto_https_redirects":{"listen":[":80"],"routes":[{},{}]},"srv0":{"listen":[":443"],"routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"body":"git gud","close":true,"handler":"static_response","status_code":403}]}]}]}]}],"terminal":true}],"tls_connection_policies":[{}],"automatic_https":{}}}}}
2024/09/02 05:20:05.297 INFO    http    enabling HTTP/3 listener        {"addr": ":443"}
2024/09/02 05:20:05.297 WARN    tls     unable to get instance ID; storage clean stamps will be incomplete      {"error": "open C:\\Users\\USER\\AppData\\Roaming\\Caddy\\instance.uuid: The system cannot find the path specified."}
2024/09/02 05:20:05.298 DEBUG   http    starting server loop    {"address": "[::]:443", "tls": true, "http3": true}
2024/09/02 05:20:05.298 INFO    http.log        server running  {"name": "srv0", "protocols": ["h1", "h2", "h3"]}
2024/09/02 05:20:05.298 DEBUG   http    starting server loop    {"address": "[::]:80", "tls": false, "http3": false}
2024/09/02 05:20:05.299 INFO    http.log        server running  {"name": "remaining_auto_https_redirects", "protocols": ["h1", "h2", "h3"]}
2024/09/02 05:20:05.299 INFO    http    enabling automatic TLS certificate management   {"domains": ["*.ip.geah.dedyn.io"]}
2024/09/02 05:20:05.299 INFO    autosaved config (load with --resume flag)      {"file": "C:\\Users\\USER\\AppData\\Roaming\\Caddy\\autosave.json"}
2024/09/02 05:20:05.300 INFO    serving initial configuration
2024/09/02 05:20:05.300 INFO    tls.obtain      acquiring lock  {"identifier": "*.ip.geah.dedyn.io"}
2024/09/02 05:20:05.300 INFO    watcher watching config file for changes        {"config_file": "Caddyfile"}
2024/09/02 05:20:05.304 INFO    tls     cleaning storage unit   {"storage": "FileStorage:C:\\Users\\USER\\AppData\\Roaming\\Caddy"}
2024/09/02 05:20:05.305 INFO    tls     finished cleaning storage units
2024/09/02 05:20:05.305 INFO    tls.obtain      lock acquired   {"identifier": "*.ip.geah.dedyn.io"}
2024/09/02 05:20:05.306 INFO    tls.obtain      obtaining certificate   {"identifier": "*.ip.geah.dedyn.io"}
2024/09/02 05:20:05.306 DEBUG   events  event   {"name": "cert_obtaining", "id": "36dd48a4-919f-4a07-b7e3-c12a61c22a96", "origin": "tls", "data": {"identifier":"*.ip.geah.dedyn.io"}}
2024/09/02 05:20:05.307 DEBUG   tls.obtain      trying issuer 1/2       {"issuer": "acme-staging-v02.api.letsencrypt.org-directory"}
2024/09/02 05:20:05.470 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "GET", "url": "https://acme-staging-v02.api.letsencrypt.org/directory", "headers": {"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["820"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:20:05 GMT"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:20:05.525 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "HEAD", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-nonce", "headers": {"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Date":["Mon, 02 Sep 2024 05:20:05 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["VFujB6i1d9ehmEMmF8EB95Vw8wxfWMEF0s-peIw0NU9epMbUS6Y"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:20:05.591 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-acct", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161669393"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["266"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:20:05 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://letsencrypt.org/documents/LE-SA-v1.4-April-3-2024.pdf>;rel=\"terms-of-service\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/acct/161669393"],"Replay-Nonce":["vfo-J0Tv4prHuLR6zuPw4OuVJ4OUvh9MZzzl8u0q4hJigI6fcAo"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 201}
2024/09/02 05:20:05.592 INFO    tls.issuance.acme       waiting on internal rate limiter        {"identifiers": ["*.ip.geah.dedyn.io"], "ca": "https://acme-staging-v02.api.letsencrypt.org/directory", "account": ""}
2024/09/02 05:20:05.592 INFO    tls.issuance.acme       done waiting on internal rate limiter   {"identifiers": ["*.ip.geah.dedyn.io"], "ca": "https://acme-staging-v02.api.letsencrypt.org/directory", "account": ""}
2024/09/02 05:20:05.676 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-order", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161669393"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["357"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:20:05 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/order/161669393/18811694783"],"Replay-Nonce":["vfo-J0TvmabhkVZRQoTpJG8Pl-ld02Zyg65RFxWGE--BJ-oMuOE"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 201}
2024/09/02 05:20:05.791 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/13835066543", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161669393"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["397"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:20:05 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["VFujB6i1N07SCijzyVA4f-mJdy_J5c1b1b1v2SAkacfjsx1yATA"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:20:05.791 INFO    tls.issuance.acme.acme_client   trying to solve challenge       {"identifier": "*.ip.geah.dedyn.io", "challenge_type": "dns-01", "ca": "https://acme-staging-v02.api.letsencrypt.org/directory"}
2024/09/02 05:20:06.547 DEBUG   tls.issuance.acme.acme_client   waiting for solver before continuing    {"identifier": "*.ip.geah.dedyn.io", "challenge_type": "dns-01"}
2024/09/02 05:21:28.591 DEBUG   tls.issuance.acme.acme_client   done waiting for solver {"identifier": "*.ip.geah.dedyn.io", "challenge_type": "dns-01"}
2024/09/02 05:21:28.656 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/13835066543/l5zY5Q", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161669393"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["193"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:21:28 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/13835066543>;rel=\"up\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/13835066543/l5zY5Q"],"Replay-Nonce":["VFujB6i1FuonwB0Ad1i7MrVnXg5P6zUOreeNCFYQt5PGgXqGx3Q"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:21:28.657 DEBUG   tls.issuance.acme.acme_client   challenge accepted      {"identifier": "*.ip.geah.dedyn.io", "challenge_type": "dns-01"}
2024/09/02 05:21:28.961 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/13835066543", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161669393"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["397"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:21:29 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["VFujB6i1rQFmHc9GIMsMcWsuQofYcRDTvMSLH88xQ_SAjfqX-cc"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:21:29.268 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/13835066543", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161669393"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["397"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:21:29 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["VFujB6i1PMTCcP4YDdSMyQ4m6opnd9ZgLQ_c4wXC45Ha5jTR5pE"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:21:29.575 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/13835066543", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161669393"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["397"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:21:29 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["vfo-J0Tv-Ze7_7w-dFyhZD9kF_H66EqSOkASFP7NXybJGx5WTD4"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:21:29.878 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/13835066543", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161669393"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["534"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:21:29 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["vfo-J0TvH--HoR23df5j_rfeoZrqhq4eMO9-mIiFAoyf1KoJBD8"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:21:29.878 ERROR   tls.issuance.acme.acme_client   cleaning up solver      {"identifier": "*.ip.geah.dedyn.io", "challenge_type": "dns-01", "error": "no memory of presenting a DNS record for \"_acme-challenge.ip.geah.dedyn.io\" (usually OK if presenting also failed)"}
2024/09/02 05:21:29.878 INFO    tls.issuance.acme.acme_client   authorization finalized {"identifier": "*.ip.geah.dedyn.io", "authz_status": "valid"}
2024/09/02 05:21:29.879 INFO    tls.issuance.acme.acme_client   validations succeeded; finalizing order {"order": "https://acme-staging-v02.api.letsencrypt.org/acme/order/161669393/18811694783"}
2024/09/02 05:21:29.949 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/finalize/161669393/18811694783", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Boulder-Requester":["161669393"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["360"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:21:30 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/order/161669393/18811694783"],"Replay-Nonce":["vfo-J0TvQqvI18PyiSgCAwW4SPiliviBVo-QbFQaaZLzuieUdYU"],"Retry-After":["3"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:21:33.006 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/order/161669393/18811694783", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["467"],"Content-Type":["application/json"],"Date":["Mon, 02 Sep 2024 05:21:33 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["vfo-J0Tvkd6ulExgzy2YKkfplV7gryWOBAezwazWd5d-Y11XbDg"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:21:33.061 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/cert/2b856c3d027bec65f8797b37884a1ba5115a", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["2998"],"Content-Type":["application/pem-certificate-chain"],"Date":["Mon, 02 Sep 2024 05:21:33 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://acme-staging-v02.api.letsencrypt.org/acme/cert/2b856c3d027bec65f8797b37884a1ba5115a/1>;rel=\"alternate\""],"Replay-Nonce":["VFujB6i1CeNE9oWwxy-6iBIEoYIY1LnuHUa6Rz0G-gOHP7qHIVM"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:21:33.116 DEBUG   tls.issuance.acme.acme_client   http request    {"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/cert/2b856c3d027bec65f8797b37884a1ba5115a/1", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.7.6 CertMagic acmez (windows; amd64)"]}, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["2437"],"Content-Type":["application/pem-certificate-chain"],"Date":["Mon, 02 Sep 2024 05:21:33 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://acme-staging-v02.api.letsencrypt.org/acme/cert/2b856c3d027bec65f8797b37884a1ba5115a/0>;rel=\"alternate\""],"Replay-Nonce":["VFujB6i12Uj5qkPPqQcpi8Kq8jKyvfLR78HbZLwYpFvGavW9jlw"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}, "status_code": 200}
2024/09/02 05:21:33.117 INFO    tls.issuance.acme.acme_client   successfully downloaded available certificate chains    {"count": 2, "first_url": "https://acme-staging-v02.api.letsencrypt.org/acme/cert/2b856c3d027bec65f8797b37884a1ba5115a"}
2024/09/02 05:21:33.119 INFO    tls.obtain      certificate obtained successfully       {"identifier": "*.ip.geah.dedyn.io"}
2024/09/02 05:21:33.119 DEBUG   events  event   {"name": "cert_obtained", "id": "d29118d4-f640-4b0c-ab01-8becdc49d05b", "origin": "tls", "data": {"certificate_path":"certificates/acme-staging-v02.api.letsencrypt.org-directory/wildcard_.ip.geah.dedyn.io/wildcard_.ip.geah.dedyn.io.crt","identifier":"*.ip.geah.dedyn.io","issuer":"acme-staging-v02.api.letsencrypt.org-directory","metadata_path":"certificates/acme-staging-v02.api.letsencrypt.org-directory/wildcard_.ip.geah.dedyn.io/wildcard_.ip.geah.dedyn.io.json","private_key_path":"certificates/acme-staging-v02.api.letsencrypt.org-directory/wildcard_.ip.geah.dedyn.io/wildcard_.ip.geah.dedyn.io.key","renewal":false,"storage_path":"certificates/acme-staging-v02.api.letsencrypt.org-directory/wildcard_.ip.geah.dedyn.io"}}
2024/09/02 05:21:33.120 INFO    tls.obtain      releasing lock  {"identifier": "*.ip.geah.dedyn.io"}
2024/09/02 05:21:33.121 DEBUG   tls     loading managed certificate     {"domain": "*.ip.geah.dedyn.io", "expiration": "2024/12/01 04:23:00.000", "issuer_key": "acme-staging-v02.api.letsencrypt.org-directory", "storage": "FileStorage:C:\\Users\\USER\\AppData\\Roaming\\Caddy"}
2024/09/02 05:21:33.408 DEBUG   tls.cache       added certificate to cache      {"subjects": ["*.ip.geah.dedyn.io"], "expiration": "2024/12/01 04:23:00.000", "managed": true, "issuer_key": "acme-staging-v02.api.letsencrypt.org-directory", "hash": "bbd212a372acf61c035935f0a7352b7c1993f73130b1c592d1f34eccca7bbf88", "cache_size": 1, "cache_capacity": 10000}
2024/09/02 05:21:33.408 DEBUG   events  event   {"name": "cached_managed_cert", "id": "744a8476-ad70-41b6-8f64-811899842e06", "origin": "tls", "data": {"sans":["*.ip.geah.dedyn.io"]}}
2024/09/02 05:22:07.600 INFO    shutting down   {"signal": "SIGINT"}
2024/09/02 05:22:07.600 WARN    exiting; byeee!! �     {"signal": "SIGINT"}
2024/09/02 05:22:07.600 INFO    http    servers shutting down with eternal grace period
2024/09/02 05:22:07.601 INFO    admin   stopped previous server {"address": "localhost:2019"}
2024/09/02 05:22:07.601 INFO    shutdown complete       {"signal": "SIGINT", "exit_code": 0}

2d. Workaround(s)

xcaddy build v2.7.6 --with github.com/caddy-dns/desec

2e. Relevant links

Zonefile for my domains: geah.dedyn.io

*.geah.dedyn.io.    3600    IN  CNAME   geah.dedyn.io.
geah.dedyn.io.  60  IN  A   100.79.138.97
geah.dedyn.io.  3600    IN  NS  ns1.desec.io.
geah.dedyn.io.  3600    IN  NS  ns2.desec.org.
geah.dedyn.io.  300 IN  SOA get.desec.io. get.desec.io. 2024090230 86400 3600 2419200 3600
ip.geah.dedyn.io.   3600    IN  NS  ns-aws.sslip.io.
ip.geah.dedyn.io.   3600    IN  NS  ns-azure.sslip.io.
ip.geah.dedyn.io.   3600    IN  NS  ns-gce.sslip.io.
_acme-challenge.ip.geah.dedyn.io.   3600    IN  DS  52775 13 2 4c370a229f860f38058a0706c6cb897ce0e184118d87e1a39943376df3c74580
_acme-challenge.ip.geah.dedyn.io.   3600    IN  NS  ns1.desec.io.

_acme-challenge.ip.geah.dedyn.io

_acme-challenge.ip.geah.dedyn.io.   3600    IN  NS  ns1.desec.io.
_acme-challenge.ip.geah.dedyn.io.   300 IN  SOA get.desec.io. get.desec.io. 2024090253 86400 3600 2419200 3600

3. Tutorial (minimal steps to reproduce the bug)

  1. xcaddy build --with github.com/caddy-dns/desec
  2. Create Caddyfile (remove DELETE THIS within token) 
    
{
debug
acme_ca https://acme-staging-v02.api.letsencrypt.org/directory
}
# Wildcard DNS for any IP Address method
*.ip.geah.dedyn.io {
tls {
    dns desec {
        token "JhnM6BVwDELETEq7Dp3HBUtDweKeTHIScmsWGY"
    }
    propagation_delay 80s
}
# Fallback for otherwise unhandled domains
handle {
    respond "git gud" 403 {
        close
    }
}
}

3. `caddy run`
mholt commented 2 months ago

Interesting, that's very odd!

Does this only happen with Desec? I'd be curious if you happen to be able to test another (similar?) domain on another DNS provider (I appreciate that you gave the recipe to reproduce it, I just don't have extra time right now).

MyAnoneNeko commented 2 months ago

Haha! Yeah it's indeed odd. In hindsight, I should have elaborated that the DNS-01 failure is specifically on the subdomain _acme-challenge.ip.geah.dedyn.io which on a separate zone from the apex domain geah.dedyn.io zone. The apex domain passes DNS challenge fine.

Right now I can only see this issue on deSEC since it's the only DNS provider that offers free subdomain setup. Other provider like Cloudflare has it at Enterprise tier pricing! So I can't config 2 separate zones. Let me know if there another provider that offer it for free I can test on.

I hope another member of the org can take a look at this issue.

LGinC commented 1 month ago

Interesting, that's very odd!

Does this only happen with Desec? I'd be curious if you happen to be able to test another (similar?) domain on another DNS provider (I appreciate that you gave the recipe to reproduce it, I just don't have extra time right now).

cloudflare too.

(dns_tls) {
  tls xxx@xx.com {
      dns cloudflare {env.CLOUDFLARE_API_TOKEN}
  }
}

https://*.xxx.xxx.xxx {
  import dns_tls

  @movie host movie.xxx.xxx.xxx
  handle @movie {
    reverse_proxy 192.168.1.100:8096
  }
}
francislavoie commented 1 month ago

@LGinC your config is not evidence of a problem.

LGinC commented 4 weeks ago

@LGinC your config is not evidence of a problem.

my fault, mosdns in my router not work correctly, caddy work fine after stop mosdns.

plittlefield commented 1 week ago

I can confirm that this was an issue for me as well.

I tried to use the dns digitalocean plugin and it flatly refused to obtain certificates using Caddy v2.8.4

I switched to a build with v2.7.6 and it successfully obtained a certificate with dns-01 challenge using the digitalocean API within a few seconds.

mholt commented 1 week ago

I think this is fixed in the latest beta (2.9 beta 3) if you would like to try it and confirm. https://github.com/caddyserver/certmagic/commit/4293198e094ded561f69e2fc3df49d53c3c5cb89