Messages

16

19.7 Legacy Series / os-acme-client (Let's Encrypt) - HTTP-01 validation not responding to acme chall

« on: December 06, 2019, 11:27:09 am »

Hello!

I'm trying to get the os-acme-client plugin to work in order to enable me to generate an SSL certificate. I plan on using this SSL certificate for the WebConfigurator and the postfix plugin. Right now I'm stuck with it not working. It appears to fail on the HTTP-01 validation part. Here's the output of acme.sh.log:

Code: [Select]

[Fri Dec  6 11:11:49 CET 2019] Using stage ACME_DIRECTORY: https://acme-staging-v02.api.letsencrypt.org/directory
[Fri Dec  6 11:11:49 CET 2019] ACME_DIRECTORY='https://acme-staging-v02.api.letsencrypt.org/directory'
[Fri Dec  6 11:11:49 CET 2019] DOMAIN_PATH='/var/etc/acme-client/home/xxxx.xxxx.xxxx.xxxx'
[Fri Dec  6 11:11:50 CET 2019] Using ACME_DIRECTORY: https://acme-staging-v02.api.letsencrypt.org/directory
[Fri Dec  6 11:11:50 CET 2019] _init api for server: https://acme-staging-v02.api.letsencrypt.org/directory
[Fri Dec  6 11:11:50 CET 2019] GET
[Fri Dec  6 11:11:50 CET 2019] url='https://acme-staging-v02.api.letsencrypt.org/directory'
[Fri Dec  6 11:11:50 CET 2019] timeout=
[Fri Dec  6 11:11:50 CET 2019] _CURL='curl -L --silent --dump-header /var/etc/acme-client/home/http.header  -g '
[Fri Dec  6 11:11:50 CET 2019] ret='0'
[Fri Dec  6 11:11:50 CET 2019] ACME_KEY_CHANGE='https://acme-staging-v02.api.letsencrypt.org/acme/key-change'
[Fri Dec  6 11:11:50 CET 2019] ACME_NEW_AUTHZ
[Fri Dec  6 11:11:50 CET 2019] ACME_NEW_ORDER='https://acme-staging-v02.api.letsencrypt.org/acme/new-order'
[Fri Dec  6 11:11:50 CET 2019] ACME_NEW_ACCOUNT='https://acme-staging-v02.api.letsencrypt.org/acme/new-acct'
[Fri Dec  6 11:11:50 CET 2019] ACME_REVOKE_CERT='https://acme-staging-v02.api.letsencrypt.org/acme/revoke-cert'
[Fri Dec  6 11:11:50 CET 2019] ACME_AGREEMENT='https://letsencrypt.org/documents/LE-SA-v1.2-November-15-2017.pdf'
[Fri Dec  6 11:11:50 CET 2019] ACME_NEW_NONCE='https://acme-staging-v02.api.letsencrypt.org/acme/new-nonce'
[Fri Dec  6 11:11:50 CET 2019] ACME_VERSION='2'
[Fri Dec  6 11:11:50 CET 2019] Le_NextRenewTime
[Fri Dec  6 11:11:51 CET 2019] _on_before_issue
[Fri Dec  6 11:11:51 CET 2019] _chk_main_domain='xxxx.xxxx.xxxx.xxxx'
[Fri Dec  6 11:11:51 CET 2019] _chk_alt_domains
[Fri Dec  6 11:11:51 CET 2019] Le_LocalAddress
[Fri Dec  6 11:11:51 CET 2019] d='xxxx.xxxx.xxxx.xxxx'
[Fri Dec  6 11:11:51 CET 2019] Check for domain='xxxx.xxxx.xxxx.xxxx'
[Fri Dec  6 11:11:51 CET 2019] _currentRoot='/var/etc/acme-client/challenges'
[Fri Dec  6 11:11:51 CET 2019] d
[Fri Dec  6 11:11:51 CET 2019] _saved_account_key_hash is not changed, skip register account.
[Fri Dec  6 11:11:51 CET 2019] Read key length:4096
[Fri Dec  6 11:11:51 CET 2019] _createcsr
[Fri Dec  6 11:11:51 CET 2019] Single domain='xxxx.xxxx.xxxx.xxxx'
[Fri Dec  6 11:11:51 CET 2019] Getting domain auth token for each domain
[Fri Dec  6 11:11:51 CET 2019] d
[Fri Dec  6 11:11:51 CET 2019] url='https://acme-staging-v02.api.letsencrypt.org/acme/new-order'
[Fri Dec  6 11:11:51 CET 2019] payload='{"identifiers": [{"type":"dns","value":"xxxx.xxxx.xxxx.xxxx"}]}'
[Fri Dec  6 11:11:51 CET 2019] RSA key
[Fri Dec  6 11:11:55 CET 2019] HEAD
[Fri Dec  6 11:11:55 CET 2019] _post_url='https://acme-staging-v02.api.letsencrypt.org/acme/new-nonce'
[Fri Dec  6 11:11:55 CET 2019] _CURL='curl -L --silent --dump-header /var/etc/acme-client/home/http.header  -g  -I  '
[Fri Dec  6 11:11:56 CET 2019] _ret='0'
[Fri Dec  6 11:11:56 CET 2019] POST
[Fri Dec  6 11:11:56 CET 2019] _post_url='https://acme-staging-v02.api.letsencrypt.org/acme/new-order'
[Fri Dec  6 11:11:56 CET 2019] _CURL='curl -L --silent --dump-header /var/etc/acme-client/home/http.header  -g '
[Fri Dec  6 11:11:56 CET 2019] _ret='0'
[Fri Dec  6 11:11:56 CET 2019] code='201'
[Fri Dec  6 11:11:56 CET 2019] Le_LinkOrder='https://acme-staging-v02.api.letsencrypt.org/acme/order/11730069/64725734'
[Fri Dec  6 11:11:56 CET 2019] Le_OrderFinalize='https://acme-staging-v02.api.letsencrypt.org/acme/finalize/11730069/64725734'
[Fri Dec  6 11:11:56 CET 2019] url='https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/25578479'
[Fri Dec  6 11:11:56 CET 2019] payload
[Fri Dec  6 11:11:57 CET 2019] POST
[Fri Dec  6 11:11:57 CET 2019] _post_url='https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/25578479'
[Fri Dec  6 11:11:57 CET 2019] _CURL='curl -L --silent --dump-header /var/etc/acme-client/home/http.header  -g '
[Fri Dec  6 11:11:57 CET 2019] _ret='0'
[Fri Dec  6 11:11:57 CET 2019] code='200'
[Fri Dec  6 11:11:57 CET 2019] d='xxxx.xxxx.xxxx.xxxx'
[Fri Dec  6 11:11:57 CET 2019] Getting webroot for domain='xxxx.xxxx.xxxx.xxxx'
[Fri Dec  6 11:11:57 CET 2019] _w='/var/etc/acme-client/challenges'
[Fri Dec  6 11:11:57 CET 2019] _currentRoot='/var/etc/acme-client/challenges'
[Fri Dec  6 11:11:57 CET 2019] entry='"type":"http-01","status":"pending","url":"https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA","token":"ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE"'
[Fri Dec  6 11:11:57 CET 2019] token='ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE'
[Fri Dec  6 11:11:57 CET 2019] uri='https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA'
[Fri Dec  6 11:11:57 CET 2019] keyauthorization='ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE.8P8EUCx8vW70bIDfd3neQhhfOrfPj2UOg3MZ7k-rUf8'
[Fri Dec  6 11:11:57 CET 2019] dvlist='xxxx.xxxx.xxxx.xxxx#ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE.8P8EUCx8vW70bIDfd3neQhhfOrfPj2UOg3MZ7k-rUf8#https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA#http-01#/var/etc/acme-client/challenges'
[Fri Dec  6 11:11:57 CET 2019] d
[Fri Dec  6 11:11:57 CET 2019] vlist='xxxx.xxxx.xxxx.xxxx#ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE.8P8EUCx8vW70bIDfd3neQhhfOrfPj2UOg3MZ7k-rUf8#https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA#http-01#/var/etc/acme-client/challenges,'
[Fri Dec  6 11:11:57 CET 2019] d='xxxx.xxxx.xxxx.xxxx'
[Fri Dec  6 11:11:57 CET 2019] ok, let's start to verify
[Fri Dec  6 11:11:58 CET 2019] Verifying: xxxx.xxxx.xxxx.xxxx
[Fri Dec  6 11:11:58 CET 2019] d='xxxx.xxxx.xxxx.xxxx'
[Fri Dec  6 11:11:58 CET 2019] keyauthorization='ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE.8P8EUCx8vW70bIDfd3neQhhfOrfPj2UOg3MZ7k-rUf8'
[Fri Dec  6 11:11:58 CET 2019] uri='https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA'
[Fri Dec  6 11:11:58 CET 2019] _currentRoot='/var/etc/acme-client/challenges'
 [Fri Dec  6 11:11:58 CET 2019] wellknown_path='/var/etc/acme-client/challenges/.well-known/acme-challenge'
[Fri Dec  6 11:11:58 CET 2019] writing token:ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE to /var/etc/acme-client/challenges/.well-known/acme-challenge/ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE
[Fri Dec  6 11:11:58 CET 2019] Changing owner/group of .well-known to root:wheel
[Fri Dec  6 11:11:58 CET 2019] url='https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA'
[Fri Dec  6 11:11:58 CET 2019] payload='{}'
[Fri Dec  6 11:11:58 CET 2019] POST
[Fri Dec  6 11:11:58 CET 2019] _post_url='https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA'
[Fri Dec  6 11:11:58 CET 2019] _CURL='curl -L --silent --dump-header /var/etc/acme-client/home/http.header  -g '
[Fri Dec  6 11:11:58 CET 2019] _ret='0'
[Fri Dec  6 11:11:58 CET 2019] code='200'
[Fri Dec  6 11:11:58 CET 2019] trigger validation code: 200
[Fri Dec  6 11:11:58 CET 2019] sleep 2 secs to verify
[Fri Dec  6 11:12:00 CET 2019] checking
[Fri Dec  6 11:12:00 CET 2019] url='https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA'
[Fri Dec  6 11:12:00 CET 2019] payload
[Fri Dec  6 11:12:01 CET 2019] POST
[Fri Dec  6 11:12:01 CET 2019] _post_url='https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA'
[Fri Dec  6 11:12:01 CET 2019] _CURL='curl -L --silent --dump-header /var/etc/acme-client/home/http.header  -g '
[Fri Dec  6 11:12:01 CET 2019] _ret='0'
[Fri Dec  6 11:12:01 CET 2019] code='200'
[Fri Dec  6 11:12:01 CET 2019] xxxx.xxxx.xxxx.xxxx:Verify error:Invalid response from https://xxxx.xxxx.xxxx.xxxx/?url=/.well-known/acme-challenge/ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE [xxxx:xxxx:xxxx::xxxx]:
[Fri Dec  6 11:12:01 CET 2019] pid
[Fri Dec  6 11:12:01 CET 2019] No need to restore nginx, skip.
[Fri Dec  6 11:12:01 CET 2019] _clearupdns
[Fri Dec  6 11:12:01 CET 2019] dns_entries
[Fri Dec  6 11:12:01 CET 2019] skip dns.
[Fri Dec  6 11:12:01 CET 2019] _on_issue_err
[Fri Dec  6 11:12:01 CET 2019] Please check log file for more details: /var/log/acme.sh.log
[Fri Dec  6 11:12:01 CET 2019] url='https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA'
[Fri Dec  6 11:12:01 CET 2019] payload='{}'
[Fri Dec  6 11:12:02 CET 2019] POST
[Fri Dec  6 11:12:02 CET 2019] _post_url='https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/25578479/T3trFA'
[Fri Dec  6 11:12:02 CET 2019] _CURL='curl -L --silent --dump-header /var/etc/acme-client/home/http.header  -g '
[Fri Dec  6 11:12:02 CET 2019] _ret='0'
[Fri Dec  6 11:12:02 CET 2019] code='400'

I would like to highlight this particular log line:

Code: [Select]

[Fri Dec  6 11:12:01 CET 2019] xxxx.xxxx.xxxx.xxxx:Verify error:Invalid response from https://xxxx.xxxx.xxxx.xxxx/?url=/.well-known/acme-challenge/ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE [xxxx:xxxx:xxxx::xxxx]:

To me this appears to show that Let's Encrypt's servers are ending up at https://xxxx.xxxx.xxxx.xxxx/?url=/.well-known/acme-challenge/ZjTUcsz8vjlno3PCnuiHfAyERnmNnZJUFV9bpmaKtmE but getting an invalid response. The fact that it's trying to access the acme-challenge over https, and the bogus ?url= part, indicates some kind of redirect that's happening in the OPNsense webconfigurator. This further indicates that a hole is being poked in the firewall correctly.

See attachment to see my validation configuration. I've also tried auto discover IP's but for now I've just hard-coded the IPv4 and IPv6 addresses of the firewall.