lego tries to read non-CNAMED record with LEGO_EXPERIMENTAL_CNAME_SUPPORT enabled

appliedprivacy commented 1 year ago

Welcome

[X] Yes, I'm using a binary release within 2 latest releases.
[X] Yes, I've searched similar issues on GitHub and didn't find any.
[X] Yes, I've included all information below (version, config, etc).

What did you expect to see?

Lego should be able to renew the certificate without errors and without trying to get the non-CNAMED target via the DNS provider API.

The hostname for the certificate is bender-doh.applied-privacy.net (and others).

There is a CNAME for that host points to: _acme-challenge.bender-doh.applied-privacy.net. -> bender-doh.acme-dns-challenge.applied-privacy.net.

The DNS API token is authorized to read and write under acme-dns-challenge.applied-privacy.net. but NOT under bender-doh.applied-privacy.net.

This setup worked for a long time (>1y), but now we got the following error:

[bender-doh.applied-privacy.net] [bender-doh.applied-privacy.net] acme: error presenting token: desec: failed to get records: domainName=applied-privacy.net, recordName=_acme-challenge.bender-doh: 403: body: {"detail":"You do not have permission to perform this action."}

which implies that lego attempts to read _acme-challenge.bender-doh.applied-privacy.net via the DNS provider API, but is not authorized to do so.

If we run lego multiple times (with the same script) it works sometimes.

What did you see instead?

error:

[bender-doh.applied-privacy.net] [bender-doh.applied-privacy.net] acme: error presenting token: desec: failed to get records: domainName=applied-privacy.net, recordName=_acme-challenge.bender-doh: 403: body: {"detail":"You do not have permission to perform this action."}

How do you use lego?

Binary

Reproduction steps

Unfortunately we have no clear reproducer as it works sometimes and sometimes it results in the error mentioned above.

Version of lego

lego version 4.9.0 freebsd/amd64

Logs

This is how lego is invoked (script skeleton is shipped on FreeBSD with the lego package) by the weekly job: ``` EMAIL="redacted" BASEDIR="/usr/local/etc/lego" SSLDIR="/usr/local/etc/ssl/lego" DOMAINSFILE="${BASEDIR}/domains.txt" if [ -z "${EMAIL}" ]; then echo "Please set EMAIL to a valid address in ${BASEDIR}/lego.sh" exit 1 fi if [ ! -e "${DOMAINSFILE}" ]; then echo "Please create ${DOMAINSFILE} as specified in ${BASEDIR}/lego.sh" exit 1 fi if [ "$1" = "run" ]; then command="run" else command="renew --days 30" fi run_or_renew() { DESEC_TTL=1 \ DESEC_TOKEN_FILE=${BASEDIR}/desec_token \ LEGO_EXPERIMENTAL_CNAME_SUPPORT=true \ /usr/local/bin/lego -a --path "${SSLDIR}" \ --email="${EMAIL}" \ $(printf -- "-d %s " $line) \ --dns desec \ --server https://acme-v02.api.letsencrypt.org/directory \ $1 \ --preferred-chain="ISRG Root X1" } while read line <&3; do if [ "$command" = "run" ]; then run_or_renew "$command" else output=$(run_or_renew "$command") || (echo "$output" && exit 1) fi done 3<"${DOMAINSFILE}" ```

Go environment (if applicable)

No response

ldez commented 1 year ago

Hello,

since 4.9.0, the LEGO_EXPERIMENTAL_CNAME_SUPPORT has been dropped and the CNAME support has been activated by default.

But currently, some providers don't support it, I created a PR to fix some of them https://github.com/go-acme/lego/pull/1735

~~What provider do you use?~~

ldez commented 1 year ago

I think you are using desec, this provider is already working with CNAME.

To find the "real" domain, lego will perform recursively CNAME calls. So your problem can be related to DNS propagation or to network issues.

appliedprivacy commented 1 year ago

Hi, thanks for the fast reply! Yes, we use desec.io as DNS provider.

To find the "real" domain, lego will perform recursively CNAME calls.

This is done via DNS not via the API, right? I'm not sure why lego tries to access the rrecord entry for _acme-challenge.bender-doh. applied-privacy.net. using the desec API if that has a CNAME to bender-doh.acme-dns-challenge.applied-privacy.net.

To summarize: I would assume that the procedure is like this:

lego performs a DNS lookup for _acme-challenge.bender-doh. applied-privacy.net. -> lego gets a CNAME response pointing to bender-doh.acme-dns-challenge.applied-privacy.net.
after confirming that _acme-challenge.bender-doh.acme-dns-challenge.applied-privacy.net. has no CNAME, lego uses the DNS API token to update the DNS record

but since the error message says that lego tried to access _acme-challenge.bender-doh. applied-privacy.net the above described understanding must be wrong? Why does lego attempt to access _acme-challenge.bender-doh. applied-privacy.net via the DNS provider API? Is this something that changed betwen 4.8 and 4.9?

The CNAME _acme-challenge.bender-doh.applied-privacy.net. -> bender-doh.acme-dns-challenge.applied-privacy.net. is static (is there all the time), so at least this one is unlikely related to DNS propagation?

ldez commented 1 year ago

This is done via DNS not via the API, right?

Yes it's only DNS calls

I would assume that the procedure is like this:

It's not possible with lego: lego always uses the same domain.

Some error messages use the "original" domain but the "original" domain is never used with the desec API or the ACME API.

ldez commented 1 year ago

to summarize the algo:

before all API calls
the "orginal" domain (example.com) is append to _acme-challenge. to create a FQDN (_acme-challenge.example.com)
The FQDN is used to look for CNAME (DNS call only)
when the CNAMEs are resolved, we get the "real" domain (example.net)

When we have to "real" domain, we use it to perform API calls to DeSec and ACME servers.

In the following error message:

desec: failed to get records: domainName=applied-privacy.net, recordName=_acme-challenge.bender-doh: 403: body: {"detail":"You do not have permission to perform this action."}

domainName=applied-privacy.net is the "real" domain (not the "original" domain")

If lego use that domain it's only related to DNS calls (not API calls), so my bet is on your DNS (local or remote) or on a network issue that impacts DNS calls.

ldez commented 1 year ago

Is this something that changed betwen 4.8 and 4.9?

The basic algorithm didn't really change, we just added a recursivity on CNAME calls.

Since the 4.9.0, we improved this part (the recursivity), and when the PR will be merged I will create a v4.9.1. I don't think this change will have an impact in your context.

appliedprivacy commented 1 year ago

Thanks for your reply.

To avoid confusion around the "real" and "original" wording:

user wants a certificate for www.example.com
_acme-challenge.www.example.com is a CNAME pointing to www.acme.example.com
_acme-challenge.www.example.com is original
www.acme.example.com is real

To better diagnose these issues it would be nice if lego were to log these steps and the DNS answers it got, that would allow for direct confirmation of your suspicion. Verbosity is already tracked in #1039

So we will wait for a more verbose output and see what the log says this happens next time. Thanks!

IvanLi-CN commented 1 year ago

Suppose my domain name is example.com and I set *.example.com to point to the CNAME of example.com. Then getChallengeFqdn finds this and changes the fqdn to example.com..

Now I can't issue the certificate correctly because the DNS checks for @.example.com. but sets the TXT record on example.com.example.com..

I'm using AliDNS, and currently I'm forcing the RecordName to @ and it's verified and issued a certificate. https://github.com/go-acme/lego/compare/master...IvanLi-CN:lego:fix/alidns-zone

appliedprivacy commented 1 year ago

a quick recap:

the current assumption by @ldez is that there is a transient DNS resolution failure that causes this problem
following this assumption lego continues its procedures as if there was no CNAME and fails to update the non-CNAME target because it is not authorized to do so in the used DNS provider

(the used script is included in full in the first comment of this issue)

example with error

The following example shows the output of a failed renewal attempt, the used script is pasted in full in the first comment of this issue. Note the lack of this message in the log: Found CNAME entry for "_acme-challenge.bender-doh.applied-privacy.net.": "bender-doh.acme-dns-challenge.applied-privacy.net."

sudo -u _lego /usr/local/etc/lego/lego.sh
00:53:45 [INFO] [doh.applied-privacy.net] acme: Trying renewal with 550 hours remaining
00:53:45 [INFO] renewal: random delay of 2m46.908217756s

00:56:32 [INFO] [doh.applied-privacy.net, bender-doh.applied-privacy.net, bender-dot.applied-privacy.net, doh.appliedprivacy.net, dot.applied-privacy.net, dot1.applied-privacy.net, dot1.appliedprivacy.net] acme: Obtaining bundled SAN certificate
00:56:33 [INFO] [bender-doh.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464077
00:56:33 [INFO] [bender-dot.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464087
00:56:33 [INFO] [doh.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464097
00:56:33 [INFO] [doh.appliedprivacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464107
00:56:33 [INFO] [dot.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464117
00:56:33 [INFO] [dot1.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/190217785897
00:56:33 [INFO] [dot1.appliedprivacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/190217785907
00:56:33 [INFO] [doh.applied-privacy.net] acme: authorization already valid; skipping challenge
00:56:33 [INFO] [dot1.applied-privacy.net] acme: authorization already valid; skipping challenge
00:56:33 [INFO] [doh.appliedprivacy.net] acme: authorization already valid; skipping challenge
00:56:33 [INFO] [dot.applied-privacy.net] acme: authorization already valid; skipping challenge
00:56:33 [INFO] [dot1.appliedprivacy.net] acme: authorization already valid; skipping challenge
00:56:33 [INFO] [bender-doh.applied-privacy.net] acme: Could not find solver for: tls-alpn-01
00:56:33 [INFO] [bender-doh.applied-privacy.net] acme: Could not find solver for: http-01
00:56:33 [INFO] [bender-doh.applied-privacy.net] acme: use dns-01 solver
00:56:33 [INFO] [bender-dot.applied-privacy.net] acme: Could not find solver for: tls-alpn-01
00:56:33 [INFO] [bender-dot.applied-privacy.net] acme: Could not find solver for: http-01
00:56:33 [INFO] [bender-dot.applied-privacy.net] acme: use dns-01 solver
00:56:33 [INFO] [bender-doh.applied-privacy.net] acme: Preparing to solve DNS-01
00:56:33 [DEBUG] GET https://desec.io/api/v1/domains/applied-privacy.net/rrsets/_acme-challenge.bender-doh/TXT/
00:56:33 [INFO] [bender-dot.applied-privacy.net] acme: Preparing to solve DNS-01
00:56:33 [DEBUG] GET https://desec.io/api/v1/domains/applied-privacy.net/rrsets/_acme-challenge.bender-dot/TXT/
00:56:34 [INFO] [bender-doh.applied-privacy.net] acme: Cleaning DNS-01 challenge
00:56:34 [INFO] Found CNAME entry for "_acme-challenge.bender-doh.applied-privacy.net.": "bender-doh.acme-dns-challenge.applied-privacy.net."
00:56:34 [DEBUG] GET https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/bender-doh/TXT/
00:56:34 [WARN] [bender-doh.applied-privacy.net] acme: cleaning up failed: desec: failed to get records: domainName=acme-dns-challenge.applied-privacy.net, recordName=bender-doh: 404: Not found. 
00:56:34 [INFO] [bender-dot.applied-privacy.net] acme: Cleaning DNS-01 challenge
00:56:34 [INFO] Found CNAME entry for "_acme-challenge.bender-dot.applied-privacy.net.": "bender-dot.acme-dns-challenge.applied-privacy.net."
00:56:34 [DEBUG] GET https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/bender-dot/TXT/
00:56:34 [WARN] [bender-dot.applied-privacy.net] acme: cleaning up failed: desec: failed to get records: domainName=acme-dns-challenge.applied-privacy.net, recordName=bender-dot: 404: Not found. 
00:56:34 [INFO] Skipping deactivating of valid auth: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464077
00:56:34 [INFO] Skipping deactivating of valid auth: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464087
00:56:34 [INFO] Skipping deactivating of valid auth: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464097
00:56:34 [INFO] Skipping deactivating of valid auth: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464107
00:56:35 [INFO] Skipping deactivating of valid auth: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464117
00:56:35 [INFO] Deactivating auth: https://acme-v02.api.letsencrypt.org/acme/authz-v3/190217785897
00:56:35 [INFO] Deactivating auth: https://acme-v02.api.letsencrypt.org/acme/authz-v3/190217785907
00:56:35 error: one or more domains had a problem:
[bender-doh.applied-privacy.net] [bender-doh.applied-privacy.net] acme: error presenting token: desec: failed to get records: domainName=applied-privacy.net, recordName=_acme-challenge.bender-doh: 403: body: {"detail":"You do not have permission to perform this action."}
[bender-dot.applied-privacy.net] [bender-dot.applied-privacy.net] acme: error presenting token: desec: failed to get records: domainName=applied-privacy.net, recordName=_acme-challenge.bender-dot: 403: body: {"detail":"You do not have permission to perform this action."}

working example a few moments later

Especially note Found CNAME entry for..

sudo -u _lego /usr/local/etc/lego/lego.sh
01:00:17 [INFO] [doh.applied-privacy.net] acme: Trying renewal with 550 hours remaining
01:00:17 [INFO] renewal: random delay of 11.117880257s
01:00:28 [INFO] [doh.applied-privacy.net, bender-doh.applied-privacy.net, bender-dot.applied-privacy.net, doh.appliedprivacy.net, dot.applied-privacy.net, dot1.applied-privacy.net, dot1.appliedprivacy.net] acme: Obtaining bundled SAN certificate
01:00:30 [INFO] [bender-doh.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464077
01:00:30 [INFO] [bender-dot.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464087
01:00:30 [INFO] [doh.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464097
01:00:30 [INFO] [doh.appliedprivacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464107
01:00:30 [INFO] [dot.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/189490464117
01:00:30 [INFO] [dot1.applied-privacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/190218672307
01:00:30 [INFO] [dot1.appliedprivacy.net] AuthURL: https://acme-v02.api.letsencrypt.org/acme/authz-v3/190218672317
01:00:30 [INFO] [doh.applied-privacy.net] acme: authorization already valid; skipping challenge
01:00:30 [INFO] [dot1.appliedprivacy.net] acme: authorization already valid; skipping challenge
01:00:30 [INFO] [doh.appliedprivacy.net] acme: authorization already valid; skipping challenge
01:00:30 [INFO] [dot.applied-privacy.net] acme: authorization already valid; skipping challenge
01:00:30 [INFO] [dot1.applied-privacy.net] acme: authorization already valid; skipping challenge
01:00:30 [INFO] [bender-doh.applied-privacy.net] acme: Could not find solver for: tls-alpn-01
01:00:30 [INFO] [bender-doh.applied-privacy.net] acme: Could not find solver for: http-01
01:00:30 [INFO] [bender-doh.applied-privacy.net] acme: use dns-01 solver
01:00:30 [INFO] [bender-dot.applied-privacy.net] acme: Could not find solver for: tls-alpn-01
01:00:30 [INFO] [bender-dot.applied-privacy.net] acme: Could not find solver for: http-01
01:00:30 [INFO] [bender-dot.applied-privacy.net] acme: use dns-01 solver
01:00:30 [INFO] [bender-doh.applied-privacy.net] acme: Preparing to solve DNS-01
01:00:30 [INFO] Found CNAME entry for "_acme-challenge.bender-doh.applied-privacy.net.": "bender-doh.acme-dns-challenge.applied-privacy.net."
01:00:30 [DEBUG] GET https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/bender-doh/TXT/
01:00:30 [DEBUG] POST https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/
01:00:30 [INFO] [bender-dot.applied-privacy.net] acme: Preparing to solve DNS-01
01:00:30 [INFO] Found CNAME entry for "_acme-challenge.bender-dot.applied-privacy.net.": "bender-dot.acme-dns-challenge.applied-privacy.net."
01:00:30 [DEBUG] GET https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/bender-dot/TXT/
01:00:30 [DEBUG] POST https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/
01:00:30 [INFO] [bender-doh.applied-privacy.net] acme: Trying to solve DNS-01
01:00:30 [INFO] Found CNAME entry for "_acme-challenge.bender-doh.applied-privacy.net.": "bender-doh.acme-dns-challenge.applied-privacy.net."
01:00:30 [INFO] [bender-doh.applied-privacy.net] acme: Checking DNS record propagation using [127.0.0.1:53]
01:00:32 [INFO] Wait for propagation [timeout: 1m0s, interval: 2s]
01:00:38 [INFO] [bender-doh.applied-privacy.net] The server validated our request
01:00:38 [INFO] [bender-dot.applied-privacy.net] acme: Trying to solve DNS-01
01:00:38 [INFO] Found CNAME entry for "_acme-challenge.bender-dot.applied-privacy.net.": "bender-dot.acme-dns-challenge.applied-privacy.net."
01:00:38 [INFO] [bender-dot.applied-privacy.net] acme: Checking DNS record propagation using [127.0.0.1:53]
01:00:40 [INFO] Wait for propagation [timeout: 1m0s, interval: 2s]
01:00:46 [INFO] [bender-dot.applied-privacy.net] The server validated our request
01:00:46 [INFO] [bender-doh.applied-privacy.net] acme: Cleaning DNS-01 challenge
01:00:46 [INFO] Found CNAME entry for "_acme-challenge.bender-doh.applied-privacy.net.": "bender-doh.acme-dns-challenge.applied-privacy.net."
01:00:46 [DEBUG] GET https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/bender-doh/TXT/
01:00:46 [DEBUG] PATCH https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/bender-doh/TXT/
01:00:46 [INFO] [bender-dot.applied-privacy.net] acme: Cleaning DNS-01 challenge
01:00:46 [INFO] Found CNAME entry for "_acme-challenge.bender-dot.applied-privacy.net.": "bender-dot.acme-dns-challenge.applied-privacy.net."
01:00:46 [DEBUG] GET https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/bender-dot/TXT/
01:00:46 [DEBUG] PATCH https://desec.io/api/v1/domains/acme-dns-challenge.applied-privacy.net/rrsets/bender-dot/TXT/
01:00:46 [INFO] [doh.applied-privacy.net, bender-doh.applied-privacy.net, bender-dot.applied-privacy.net, doh.appliedprivacy.net, dot.applied-privacy.net, dot1.applied-privacy.net, dot1.appliedprivacy.net] acme: Validations succeeded; requesting certificates

Would it be possible to add some log output that shows the CNAME DNS check result to confirm that this is a transient DNS failure or is this already planed as part of #1039?

ldez commented 1 year ago

If you don't have "Found CNAME entry ..." log, it's because of one of the following cases:

there is no CNAME
there is an error when during the call to resolve the CNAME
the CNAME points to the domain that contains the CNAME (a loop)

So for me, as you have:

no "Found CNAME entry ..."
and "403: body: {"detail": "You do not have permission to perform this action."}"

the problem is related to your DNS.

Adding logs will not provide something more precise than what you already have.

appliedprivacy commented 1 year ago

Thanks for your prompt reply!

Adding logs will not provide something more precise than what you already have.

I see your point there, the only difference is that it would also be clear to the user that the absence of a specific log line means X without requiring to ask you, the developer, especially if they do not have access to a good log sample. Thanks!

go-acme / lego