Not working with acme.sh

[LOENS2]

Hi there.

I use this acme server in my homelab environment and just stumbled across a problem with acme.sh. But see for yourself:

[Sun Dec 18 11:40:55 CET 2022] Lets find script dir.
[Sun Dec 18 11:40:55 CET 2022] _SCRIPT_='/root/.acme.sh/acme.sh'
[Sun Dec 18 11:40:55 CET 2022] _script='/root/.acme.sh/acme.sh'
[Sun Dec 18 11:40:55 CET 2022] _script_home='/root/.acme.sh'
[Sun Dec 18 11:40:55 CET 2022] Using config home:/root/.acme.sh
https://github.com/acmesh-official/acme.sh
v3.0.5
[Sun Dec 18 11:40:55 CET 2022] Using server: acme.loens2.com
[Sun Dec 18 11:40:55 CET 2022] Running cmd: issue
[Sun Dec 18 11:40:55 CET 2022] _main_domain='test.test'
[Sun Dec 18 11:40:55 CET 2022] _alt_domains='no'
[Sun Dec 18 11:40:55 CET 2022] Using config home:/root/.acme.sh
[Sun Dec 18 11:40:55 CET 2022] ACME_DIRECTORY='acme.loens2.com'
[Sun Dec 18 11:40:55 CET 2022] DOMAIN_PATH='/root/.acme.sh/test.test'
[Sun Dec 18 11:40:55 CET 2022] Le_NextRenewTime
[Sun Dec 18 11:40:55 CET 2022] Using ACME_DIRECTORY: acme.loens2.com
[Sun Dec 18 11:40:55 CET 2022] _init api for server: acme.loens2.com
[Sun Dec 18 11:40:55 CET 2022] GET
[Sun Dec 18 11:40:55 CET 2022] url='acme.loens2.com'
[Sun Dec 18 11:40:55 CET 2022] timeout=
[Sun Dec 18 11:40:55 CET 2022] _CURL='curl --silent --dump-header /root/.acme.sh/http.header  -L  -g '
[Sun Dec 18 11:40:55 CET 2022] ret='0'
[Sun Dec 18 11:40:55 CET 2022] ACME_KEY_CHANGE
[Sun Dec 18 11:40:55 CET 2022] ACME_NEW_AUTHZ
[Sun Dec 18 11:40:55 CET 2022] ACME_NEW_ORDER='http://acme.loens2.com/new-order'
[Sun Dec 18 11:40:55 CET 2022] ACME_NEW_ACCOUNT='http://acme.loens2.com/new-account'
[Sun Dec 18 11:40:55 CET 2022] ACME_REVOKE_CERT
[Sun Dec 18 11:40:55 CET 2022] ACME_AGREEMENT
[Sun Dec 18 11:40:55 CET 2022] ACME_NEW_NONCE='http://acme.loens2.com/new-nonce'
[Sun Dec 18 11:40:55 CET 2022] Using CA: acme.loens2.com
[Sun Dec 18 11:40:55 CET 2022] _on_before_issue
[Sun Dec 18 11:40:55 CET 2022] _chk_main_domain='test.test'
[Sun Dec 18 11:40:55 CET 2022] _chk_alt_domains
[Sun Dec 18 11:40:55 CET 2022] Le_LocalAddress
[Sun Dec 18 11:40:55 CET 2022] d='test.test'
[Sun Dec 18 11:40:55 CET 2022] Check for domain='test.test'
[Sun Dec 18 11:40:55 CET 2022] _currentRoot='no'
[Sun Dec 18 11:40:55 CET 2022] Standalone mode.
[Sun Dec 18 11:40:55 CET 2022] _checkport='80'
[Sun Dec 18 11:40:55 CET 2022] _checkaddr
[Sun Dec 18 11:40:55 CET 2022] Using: ss
[Sun Dec 18 11:40:55 CET 2022] d
[Sun Dec 18 11:40:55 CET 2022] _saved_account_key_hash is not changed, skip register account.
[Sun Dec 18 11:40:55 CET 2022] Read key length:2048
[Sun Dec 18 11:40:55 CET 2022] _createcsr
[Sun Dec 18 11:40:55 CET 2022] Single domain='test.test'
[Sun Dec 18 11:40:55 CET 2022] Getting domain auth token for each domain
[Sun Dec 18 11:40:55 CET 2022] d
[Sun Dec 18 11:40:55 CET 2022] url='http://acme.loens2.com/new-order'
[Sun Dec 18 11:40:55 CET 2022] payload='{"identifiers": [{"type":"dns","value":"test.test"}]}'
[Sun Dec 18 11:40:55 CET 2022] RSA key
[Sun Dec 18 11:40:55 CET 2022] HEAD
[Sun Dec 18 11:40:55 CET 2022] _post_url='http://acme.loens2.com/new-nonce'
[Sun Dec 18 11:40:55 CET 2022] _CURL='curl --silent --dump-header /root/.acme.sh/http.header  -L  -g  -I  '
[Sun Dec 18 11:40:55 CET 2022] _ret='0'
[Sun Dec 18 11:40:55 CET 2022] POST
[Sun Dec 18 11:40:55 CET 2022] _post_url='http://acme.loens2.com/new-order'
[Sun Dec 18 11:40:55 CET 2022] _CURL='curl --silent --dump-header /root/.acme.sh/http.header  -L  -g '
[Sun Dec 18 11:40:55 CET 2022] _ret='0'
[Sun Dec 18 11:40:55 CET 2022] code='201'
[Sun Dec 18 11:40:55 CET 2022] Le_LinkOrder='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw'
[Sun Dec 18 11:40:55 CET 2022] Le_OrderFinalize='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/finalize'
[Sun Dec 18 11:40:55 CET 2022] url='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g'
[Sun Dec 18 11:40:55 CET 2022] payload
[Sun Dec 18 11:40:55 CET 2022] POST
[Sun Dec 18 11:40:55 CET 2022] _post_url='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g'
[Sun Dec 18 11:40:55 CET 2022] _CURL='curl --silent --dump-header /root/.acme.sh/http.header  -L  -g '
[Sun Dec 18 11:40:55 CET 2022] _ret='0'
[Sun Dec 18 11:40:55 CET 2022] code='200'
[Sun Dec 18 11:40:55 CET 2022] d='test.test'
[Sun Dec 18 11:40:55 CET 2022] Getting webroot for domain='test.test'
[Sun Dec 18 11:40:55 CET 2022] _w='no'
[Sun Dec 18 11:40:55 CET 2022] _currentRoot='no'
[Sun Dec 18 11:40:55 CET 2022] entry='"type":"http-01","token":"pAFAKLCP1mfmrWg9JUdctnLu2GDrbLYRJXJ177bk21csnz-JCNb8Qs8R3lmeveOd","status":"pending","url":"http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ"'
[Sun Dec 18 11:40:55 CET 2022] token='pAFAKLCP1mfmrWg9JUdctnLu2GDrbLYRJXJ177bk21csnz-JCNb8Qs8R3lmeveOd'
[Sun Dec 18 11:40:55 CET 2022] uri='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ'
[Sun Dec 18 11:40:55 CET 2022] keyauthorization='pAFAKLCP1mfmrWg9JUdctnLu2GDrbLYRJXJ177bk21csnz-JCNb8Qs8R3lmeveOd.FG6-J0vpiqAyTkYO7NB7Hhr0CnFoCwaSgeqE5u9EasU'
[Sun Dec 18 11:40:55 CET 2022] dvlist='test.test#pAFAKLCP1mfmrWg9JUdctnLu2GDrbLYRJXJ177bk21csnz-JCNb8Qs8R3lmeveOd.FG6-J0vpiqAyTkYO7NB7Hhr0CnFoCwaSgeqE5u9EasU#http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ#http-01#no'
[Sun Dec 18 11:40:55 CET 2022] d
[Sun Dec 18 11:40:55 CET 2022] vlist='test.test#pAFAKLCP1mfmrWg9JUdctnLu2GDrbLYRJXJ177bk21csnz-JCNb8Qs8R3lmeveOd.FG6-J0vpiqAyTkYO7NB7Hhr0CnFoCwaSgeqE5u9EasU#http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ#http-01#no,'
[Sun Dec 18 11:40:55 CET 2022] d='test.test'
[Sun Dec 18 11:40:55 CET 2022] ok, let's start to verify
[Sun Dec 18 11:40:55 CET 2022] Verifying: test.test
[Sun Dec 18 11:40:55 CET 2022] d='test.test'
[Sun Dec 18 11:40:55 CET 2022] keyauthorization='pAFAKLCP1mfmrWg9JUdctnLu2GDrbLYRJXJ177bk21csnz-JCNb8Qs8R3lmeveOd.FG6-J0vpiqAyTkYO7NB7Hhr0CnFoCwaSgeqE5u9EasU'
[Sun Dec 18 11:40:55 CET 2022] uri='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ'
[Sun Dec 18 11:40:55 CET 2022] _currentRoot='no'
[Sun Dec 18 11:40:55 CET 2022] Standalone mode server
[Sun Dec 18 11:40:55 CET 2022] content='pAFAKLCP1mfmrWg9JUdctnLu2GDrbLYRJXJ177bk21csnz-JCNb8Qs8R3lmeveOd.FG6-J0vpiqAyTkYO7NB7Hhr0CnFoCwaSgeqE5u9EasU'
[Sun Dec 18 11:40:55 CET 2022] ncaddr
[Sun Dec 18 11:40:55 CET 2022] startserver: 2170
[Sun Dec 18 11:40:55 CET 2022] Le_HTTPPort='80'
[Sun Dec 18 11:40:55 CET 2022] Le_Listen_V4
[Sun Dec 18 11:40:55 CET 2022] Le_Listen_V6
[Sun Dec 18 11:40:55 CET 2022] _content_len='108'
[Sun Dec 18 11:40:55 CET 2022] _NC='socat TCP-LISTEN:80,crlf,reuseaddr,fork'
[Sun Dec 18 11:40:56 CET 2022] serverproc='3064'
[Sun Dec 18 11:40:56 CET 2022] url='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ'
[Sun Dec 18 11:40:56 CET 2022] payload='{}'
[Sun Dec 18 11:40:56 CET 2022] POST
[Sun Dec 18 11:40:56 CET 2022] _post_url='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ'
[Sun Dec 18 11:40:56 CET 2022] _CURL='curl --silent --dump-header /root/.acme.sh/http.header  -L  -g '
[Sun Dec 18 11:40:56 CET 2022] _ret='0'
[Sun Dec 18 11:40:56 CET 2022] code='200'
[Sun Dec 18 11:40:56 CET 2022] trigger validation code: 200
[Sun Dec 18 11:40:56 CET 2022] Processing, The CA is processing your order, please just wait. (1/30)
[Sun Dec 18 11:40:56 CET 2022] sleep 2 secs to verify again
[Sun Dec 18 11:40:59 CET 2022] checking
[Sun Dec 18 11:40:59 CET 2022] url='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ'
[Sun Dec 18 11:40:59 CET 2022] payload
[Sun Dec 18 11:40:59 CET 2022] POST
[Sun Dec 18 11:40:59 CET 2022] _post_url='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ'
[Sun Dec 18 11:40:59 CET 2022] _CURL='curl --silent --dump-header /root/.acme.sh/http.header  -L  -g '
[Sun Dec 18 11:40:59 CET 2022] _ret='0'
[Sun Dec 18 11:40:59 CET 2022] code='409'
[Sun Dec 18 11:40:59 CET 2022] test.test:Verify error:{"type":"urn:ietf:params:acme:error:malformed","detail":"The order used in this request did not have the expected status 'Pending' but had 'Ready'."}
[Sun Dec 18 11:40:59 CET 2022] Skip for removelevel:
[Sun Dec 18 11:40:59 CET 2022] pid='3064'
[Sun Dec 18 11:40:59 CET 2022] No need to restore nginx, skip.
[Sun Dec 18 11:40:59 CET 2022] _clearupdns
[Sun Dec 18 11:40:59 CET 2022] dns_entries
[Sun Dec 18 11:40:59 CET 2022] skip dns.
[Sun Dec 18 11:40:59 CET 2022] _on_issue_err
[Sun Dec 18 11:40:59 CET 2022] Please add '--debug' or '--log' to check more details.
[Sun Dec 18 11:40:59 CET 2022] See: https://github.com/acmesh-official/acme.sh/wiki/How-to-debug-acme.sh
[Sun Dec 18 11:40:59 CET 2022] url='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ'
[Sun Dec 18 11:40:59 CET 2022] payload='{}'
[Sun Dec 18 11:40:59 CET 2022] POST
[Sun Dec 18 11:40:59 CET 2022] _post_url='http://acme.loens2.com/order/PmGuXwClD0in8liQDZEOIw/auth/fySczzPIu0-0CYhhPQIL8g/chall/lR9H5m5zO0-Rvar-iuiigQ'
[Sun Dec 18 11:40:59 CET 2022] _CURL='curl --silent --dump-header /root/.acme.sh/http.header  -L  -g '
[Sun Dec 18 11:40:59 CET 2022] _ret='0'
[Sun Dec 18 11:40:59 CET 2022] code='409'
[Sun Dec 18 11:41:00 CET 2022] Diagnosis versions:
openssl:openssl
OpenSSL 1.1.1f  31 Mar 2020
apache:
apache doesn't exist.
nginx:
nginx doesn't exist.
socat:
socat by Gerhard Rieger and contributors - see www.dest-unreach.org
socat version 1.7.3.3 on Oct 26 2019 17:42:04
   running on Linux version #1 SMP Wed Nov 23 01:01:46 UTC 2022, release 5.15.79.1-microsoft-standard-WSL2, machine x86_64
features:
  #define WITH_STDIO 1
  #define WITH_FDNUM 1
  #define WITH_FILE 1
  #define WITH_CREAT 1
  #define WITH_GOPEN 1
  #define WITH_TERMIOS 1
  #define WITH_PIPE 1
  #define WITH_UNIX 1
  #define WITH_ABSTRACT_UNIXSOCKET 1
  #define WITH_IP4 1
  #define WITH_IP6 1
  #define WITH_RAWIP 1
  #define WITH_GENERICSOCKET 1
  #define WITH_INTERFACE 1
  #define WITH_TCP 1
  #define WITH_UDP 1
  #define WITH_SCTP 1
  #define WITH_LISTEN 1
  #define WITH_SOCKS4 1
  #define WITH_SOCKS4A 1
  #define WITH_PROXY 1
  #define WITH_SYSTEM 1
  #define WITH_EXEC 1
  #undef WITH_READLINE
  #define WITH_TUN 1
  #define WITH_PTY 1
  #define WITH_OPENSSL 1
  #undef WITH_FIPS
  #define WITH_LIBWRAP 1
  #define WITH_SYCLS 1
  #define WITH_FILAN 1
  #define WITH_RETRY 1
  #define WITH_MSGLEVEL 0 /*debug*/

acme.loens2.com is my local acme server. As you can see, the script fails with error "The order used in this request did not have the expected status 'Pending' but had 'Ready'.". Unfortunately I have to use acme.sh because it's the only one supported by OPNsense. On my other Servers with certbot, everything works as expected.

[glatzert]

Hm - this is an interesting behaviour of acme.sh, since you are meant to poll the authorization (as opposed to the challenge) to get the state of the authorization (see https://www.rfc-editor.org/rfc/rfc8555#section-7.5.1, Page 55, more or less on top). Reading the log it tries to poll on the challenge, which I think is "undefined" in RFC 8555.

Since it's a common tool and the expected response is not something too uncommon, I think it's okay to adjust the code of the ACME-Server to check, if that challenge is okay to use as a response. It's a minor change, so expect it to be available before christmas.

[LOENS2]

Awesome! I already assumed that this is a problem with acme.sh, but they probably wont change their code anway, so I didn't create an issue there. Thank you very much.

[glatzert]

I hope this solves the problem ;)