NOTIMP reponse to Route53 ACME challenge

jcnix · September 12, 2024, 5:43am

1. The problem I’m having:

My domain is in AWS Route53, so I’ve installed the route53 module and created the IAM policy provided by the module. I’ve created an IAM user with that policy and created an access key which I entered into in the Caddyfile.

When I start Caddy, I get the error output below. I don’t see any logs pertaining to authentication with AWS, no TXT record gets created in Route53. According to IAM my access key has never been used despite my repeated attempts. It looks like to me based on the NOTIMP response code that it is attempting to complete the ACME challenge before updating the DNS record in route53.

2. Error messages and/or full log output:

{"level":"info","ts":1726107594.125152,"msg":"using config from file","file":"/etc/caddy/Caddyfile"}

{"level":"info","ts":1726107594.126035,"msg":"adapted config to JSON","adapter":"caddyfile"}

{"level":"warn","ts":1726107594.1260412,"msg":"Caddyfile input is not formatted; run 'caddy fmt --overwrite' to fix inconsistencies","adapter":"caddyfile","file":"/etc/caddy/Caddyfile","line":10}

{"level":"info","ts":1726107594.1267316,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}

{"level":"info","ts":1726107594.1269312,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc00056bb80"}

{"level":"info","ts":1726107594.1270711,"logger":"http.auto_https","msg":"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}

{"level":"info","ts":1726107594.1270812,"logger":"http.auto_https","msg":"enabling automatic HTTP->HTTPS redirects","server_name":"srv0"}

{"level":"debug","ts":1726107594.1270974,"logger":"http.auto_https","msg":"adjusted config","tls":{"automation":{"policies":[{"subjects":["test.jcnix.xyz"]},{"subjects":["jcnix.xyz"]},{}]}},"http":{"servers":{"remaining_auto_https_redirects":{"listen":[":80"],"routes":[{},{}]},"srv0":{"listen":[":443"],"routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"reverse_proxy","upstreams":[{"dial":"systemd-jellyfin:8096"}]}]}]}],"terminal":true},{"terminal":true}],"tls_connection_policies":[{}],"automatic_https":{}}}}}

{"level":"warn","ts":1726107594.1271873,"logger":"pki.ca.local","msg":"installing root certificate (you might be prompted for password)","path":"storage:pki/authorities/local/root.crt"}

{"level":"info","ts":1726107594.1274602,"msg":"warning: \"certutil\" is not available, install \"certutil\" with \"apt install libnss3-tools\" or \"yum install nss-tools\" and try again"}

{"level":"info","ts":1726107594.1274655,"msg":"define JAVA_HOME environment variable to use the Java trust"}

{"level":"info","ts":1726107594.1511183,"msg":"certificate installed properly in linux trusts"}

{"level":"info","ts":1726107594.1513503,"logger":"http","msg":"enabling HTTP/3 listener","addr":":443"}

{"level":"info","ts":1726107594.1514704,"msg":"failed to sufficiently increase receive buffer size (was: 208 kiB, wanted: 7168 kiB, got: 416 kiB). See https://github.com/quic-go/quic-go/wiki/UDP-Buffer-Sizes for details."}

{"level":"debug","ts":1726107594.1523438,"logger":"http","msg":"starting server loop","address":"[::]:443","tls":true,"http3":true}

{"level":"info","ts":1726107594.1523824,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}

{"level":"debug","ts":1726107594.152454,"logger":"http","msg":"starting server loop","address":"[::]:80","tls":false,"http3":false}

{"level":"info","ts":1726107594.152468,"logger":"http.log","msg":"server running","name":"remaining_auto_https_redirects","protocols":["h1","h2","h3"]}

{"level":"info","ts":1726107594.152473,"logger":"http","msg":"enabling automatic TLS certificate management","domains":["test.jcnix.xyz","jcnix.xyz"]}

{"level":"warn","ts":1726107594.1529422,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [test.jcnix.xyz]: no OCSP server specified in certificate","identifiers":["test.jcnix.xyz"]}

{"level":"debug","ts":1726107594.1529565,"logger":"tls.cache","msg":"added certificate to cache","subjects":["test.jcnix.xyz"],"expiration":1726149721,"managed":true,"issuer_key":"local","hash":"64bd6122fe94cb573c3544a90e288b479636da51095f19eb3d1629fbbfc2574f","cache_size":1,"cache_capacity":10000}

{"level":"debug","ts":1726107594.152978,"logger":"events","msg":"event","name":"cached_managed_cert","id":"0de5a3d2-1083-4a2c-a4bd-b89d0734489c","origin":"tls","data":{"sans":["test.jcnix.xyz"]}}

{"level":"info","ts":1726107594.1532779,"msg":"autosaved config (load with --resume flag)","file":"/config/caddy/autosave.json"}

{"level":"info","ts":1726107594.1532857,"msg":"serving initial configuration"}

{"level":"info","ts":1726107594.1533391,"logger":"tls.obtain","msg":"acquiring lock","identifier":"jcnix.xyz"}

{"level":"info","ts":1726107594.1558082,"logger":"tls","msg":"storage cleaning happened too recently; skipping for now","storage":"FileStorage:/data/caddy","instance":"13500e40-6a7d-4089-8522-40be552ffe0d","try_again":1726193994.155807,"try_again_in":86399.99999973}

{"level":"info","ts":1726107594.155852,"logger":"tls","msg":"finished cleaning storage units"}

{"level":"info","ts":1726107594.158775,"logger":"tls.obtain","msg":"lock acquired","identifier":"jcnix.xyz"}

{"level":"info","ts":1726107594.1588323,"logger":"tls.obtain","msg":"obtaining certificate","identifier":"jcnix.xyz"}

{"level":"debug","ts":1726107594.158864,"logger":"events","msg":"event","name":"cert_obtaining","id":"cc53d8c6-24e6-424e-9ddf-f922f02509a5","origin":"tls","data":{"identifier":"jcnix.xyz"}}

{"level":"debug","ts":1726107594.1589837,"logger":"tls.obtain","msg":"trying issuer 1/1","issuer":"acme-v02.api.letsencrypt.org-directory"}

{"level":"info","ts":1726107594.1592069,"logger":"tls.issuance.acme","msg":"waiting on internal rate limiter","identifiers":["jcnix.xyz"],"ca":"https://acme-v02.api.letsencrypt.org/directory","account":""}

{"level":"info","ts":1726107594.1592138,"logger":"tls.issuance.acme","msg":"done waiting on internal rate limiter","identifiers":["jcnix.xyz"],"ca":"https://acme-v02.api.letsencrypt.org/directory","account":""}

{"level":"info","ts":1726107594.1592224,"logger":"tls.issuance.acme","msg":"using ACME account","account_id":"https://acme-v02.api.letsencrypt.org/acme/acct/1941784616","account_contact":[]}

{"level":"debug","ts":1726107594.3262126,"logger":"tls.issuance.acme.acme_client","msg":"http request","method":"GET","url":"https://acme-v02.api.letsencrypt.org/directory","headers":{"User-Agent":["Caddy/2.8.4 CertMagic acmez (linux; amd64)"]},"response_headers":{"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["746"],"Content-Type":["application/json"],"Date":["Thu, 12 Sep 2024 02:19:54 GMT"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]},"status_code":200}

{"level":"debug","ts":1726107594.3263958,"logger":"tls.issuance.acme.acme_client","msg":"creating order","account":"https://acme-v02.api.letsencrypt.org/acme/acct/1941784616","identifiers":["jcnix.xyz"]}

{"level":"debug","ts":1726107594.374934,"logger":"tls.issuance.acme.acme_client","msg":"http request","method":"HEAD","url":"https://acme-v02.api.letsencrypt.org/acme/new-nonce","headers":{"User-Agent":["Caddy/2.8.4 CertMagic acmez (linux; amd64)"]},"response_headers":{"Cache-Control":["public, max-age=0, no-cache"],"Date":["Thu, 12 Sep 2024 02:19:54 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0Nvv4YSt7168x8zd8yxDjsxn9opP4cU0agCnsQ4B39TsQkPElio"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]},"status_code":200}

{"level":"debug","ts":1726107594.473353,"logger":"tls.issuance.acme.acme_client","msg":"http request","method":"POST","url":"https://acme-v02.api.letsencrypt.org/acme/new-order","headers":{"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.8.4 CertMagic acmez (linux; amd64)"]},"response_headers":{"Boulder-Requester":["1941784616"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["335"],"Content-Type":["application/json"],"Date":["Thu, 12 Sep 2024 02:19:54 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-v02.api.letsencrypt.org/acme/order/1941784616/304399491346"],"Replay-Nonce":["UAMvsxnwCbbkjexPTD0W02srKAEYq8DoyTljhFC7mw5rfVVZaVY"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]},"status_code":201}

{"level":"debug","ts":1726107594.5267632,"logger":"tls.issuance.acme.acme_client","msg":"http request","method":"POST","url":"https://acme-v02.api.letsencrypt.org/acme/authz-v3/402505097626","headers":{"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.8.4 CertMagic acmez (linux; amd64)"]},"response_headers":{"Boulder-Requester":["1941784616"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["793"],"Content-Type":["application/json"],"Date":["Thu, 12 Sep 2024 02:19:54 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["UAMvsxnwxHa0vkw9DefznsreeOCdzgD90fkP-jVjXXZvRxFtpTI"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]},"status_code":200}

{"level":"debug","ts":1726107594.526975,"logger":"tls.issuance.acme.acme_client","msg":"no solver configured","challenge_type":"tls-alpn-01"}

{"level":"debug","ts":1726107594.5269842,"logger":"tls.issuance.acme.acme_client","msg":"no solver configured","challenge_type":"http-01"}

{"level":"info","ts":1726107594.5269883,"logger":"tls.issuance.acme.acme_client","msg":"trying to solve challenge","identifier":"jcnix.xyz","challenge_type":"dns-01","ca":"https://acme-v02.api.letsencrypt.org/directory"}

{"level":"error","ts":1726107594.595694,"logger":"tls.issuance.acme.acme_client","msg":"cleaning up solver","identifier":"jcnix.xyz","challenge_type":"dns-01","error":"no memory of presenting a DNS record for \"_acme-challenge.jcnix.xyz\" (usually OK if presenting also failed)"}

{"level":"debug","ts":1726107594.6506388,"logger":"tls.issuance.acme.acme_client","msg":"http request","method":"POST","url":"https://acme-v02.api.letsencrypt.org/acme/authz-v3/402505097626","headers":{"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.8.4 CertMagic acmez (linux; amd64)"]},"response_headers":{"Boulder-Requester":["1941784616"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["797"],"Content-Type":["application/json"],"Date":["Thu, 12 Sep 2024 02:19:54 GMT"],"Link":["<https://acme-v02.api.letsencrypt.or
ory>;rel=\"index\""],"Replay-Nonce":["0Nvv4YStTlFdHBCIkIMZTc-_RHd8AM6umKHN5jX0yu8d5TNdjiw"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]},"status_code":200}

{"level":"error","ts":1726107594.6507387,"logger":"tls.obtain","msg":"could not get certificate from issuer","identifier":"jcnix.xyz","issuer":"acme-v02.api.letsencrypt.org-directory","error":"[jcnix.xyz] solving challenges: presenting for challenge: could not determine zone for domain \"_acme-challenge.jcnix.xyz\": unexpected response code 'NOTIMP' for _acme-challenge.jcnix.xyz. (order=https://acme-v02.api.letsencrypt.org/acme/order/1941784616/304399491346) (ca=https://acme-v02.api.letsencrypt.org/directory)"}

{"level":"debug","ts":1726107594.6507828,"logger":"events","msg":"event","name":"cert_failed","id":"b0d287a6-777d-45a6-a8a3-6833e81b46db","origin":"tls","data":{"error":{},"identifier":"jcnix.xyz","issuers":["acme-v02.api.letsencrypt.org-directory"],"renewal":false}}

{"level":"error","ts":1726107594.6507962,"logger":"tls.obtain","msg":"will retry","error":"[jcnix.xyz] Obtain: [jcnix.xyz] solving challenges: presenting for challenge: could not determine zone for domain \"_acme-challenge.jcnix.xyz\": unexpected response code 'NOTIMP' for _acme-challenge.jcnix.xyz. (order=https://acme-v02.api.letsencrypt.org/acme/order/1941784616/304399491346) (ca=https://acme-v02.api.letsencrypt.org/directory)","attempt":1,"retrying_in":60,"elapsed":0.49201344,"max_duration":2592000}

3. Caddy version:

2.8.4

4. How I installed and ran Caddy:

Built a caddy image with below containerfile

FROM docker.io/library/caddy:2-builder AS builder

RUN xcaddy build \
    --with github.com/caddy-dns/route53

FROM docker.io/library/caddy:2

COPY --from=builder /usr/bin/caddy /usr/bin/caddy

a. System environment:

Podman container in CoreOS (Fedora 40)

b. Command:

systemctl start caddy

c. Service/unit/compose file:

[Unit]
Description=Caddy
After=local-fs.target

[Container]
Image=caddy.build
PublishPort=80:80
PublishPort=443:443
PublishPort=443:443/udp
Volume=caddy_config:/config:z
Volume=caddy_data:/data:z
Volume=/media/nas/docker/caddy/Caddyfile:/etc/caddy/Caddyfile:z
Network=proxy.network

[Install]
WantedBy=multi-user.target default.target

d. My complete Caddy config:

{
        debug
}

jcnix.xyz {
        tls {
                dns route53 {
                        access_key_id "..."
                        secret_access_key "..."
                        hosted_zone_id "..."
                        region "us-east-1"
                        max_wait_dur 120
                        wait_for_propagation true
                        max_retries 10
                }
        }
}

5. Links to relevant resources:

francislavoie · September 12, 2024, 9:24am

That’s weird. Your DNS resolver doesn’t support a query for an SOA record it seems. You can override the resolvers with resolvers 1.1.1.1 (right after your dns config) to have it use Cloudflare’s DNS servers instead of your own local resolvers to do propagation checks.

jcnix · September 12, 2024, 10:24pm

Awesome, that worked right away. I can see in CloudTrail it creates the TXT record then deletes and HTTPS is working now. Thank you.

system · October 12, 2024, 10:25pm

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.