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

[pv2b]

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.

[wer]

Hi,

I can confirm this issue in OPNsense 19.7.7-amd64


Before getting there I had to fix the syntax of the generated pf rules in
/var/etc/acme-client/configs/xxxx/acme_anchor_rules which are generated in the
/usr/local/opnsense/scripts/OPNsense/AcmeClient/certhelper.php file:

Line 57:
-$anchor_rules .= "rdr pass inet proto tcp from any to ${ip} port 80 -> 127.0.0.1 port ${local_http_port}\n";
+$anchor_rules .= "rdr pass on inet proto tcp from any to ${ip} port 80 -> 127.0.0.1 port ${local_http_port}\n";

But still, acme does not work... 

Kind Regards,
Wer

[fabian]

you may have a port conflict with the web interface of OPNsense.

[pv2b]

you may have a port conflict with the web interface of OPNsense.

What do you mean by "port conflict"?

Under the validation method, "OPNsense Web Service (automatic port forward)" is used as the HTTP Service. I would therefore expect that it would just use the same web server as the actual WebConfigurator?

[fabian]

No, you cannot use any port already in use, so you must move the web interface to another port and if you use HTTPS, you must disable the automatic redirect rule.

[wer]

Found a solution:

After removing all acme parts from the gateway and reinstalling it, the problem was still present.

Even tough the default local port 43580 is not in use (netstat -an | grep LISTEN) I have changed the local port to 4358 and additionally I have disabled the http->https redirection of the GUI.
Doing so, I was able to renew the certs on 2 of my systems....  Happy again...