Getting "Unable to update challenge :: authorization must be pending"

Help
1

We’ve recently stopped being able to renew certificates (or even issue new ones). We now get a 400 error from the LE servers (see below) and a “Connection reset by peer” message. We have a traffic manager in the mix front-ending a whole load of domains on 131.111.150.25 (using host header for back-end pool choice). This listens on HTTP and redirects to a listener on HTTPS, except for a few things, including letsencrypt requests (see https://community.pulsesecure.net/t5/Pulse-vADC-Updates/Using-Let-s-Encrypt-certificates-with-Brocade-vADC/ba-p/36046). Other IPs that the traffic manager listens on with the same setup are working perfectly when it comes to LE certificate requests, but 131.111.150.25 fails… but not consistently! Every now and then a certificate renewal will work. but 99 times out of 100 it won’t. Any thoughts appreciated!

My domain is: nwcdevelopment.co.uk

I ran this command: letsencryptforvtm.sh --issue c_nwcdevelopment.co.uk_rsa

It produced this output:

== Info: About to connect() to acme-v02.api.letsencrypt.org port 443 (#0)
== Info:   Trying 172.65.32.248... == Info: connected
== Info: Connected to acme-v02.api.letsencrypt.org (172.65.32.248) port 443 (#0)
== Info: Initializing NSS with certpath: sql:/etc/pki/nssdb
== Info:   CAfile: /etc/pki/tls/certs/ca-bundle.crt
  CApath: none
== Info: SSL connection using TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384
== Info: Server certificate:
== Info:        subject: CN=acme-v01.api.letsencrypt.org
== Info:        start date: Nov 12 19:16:31 2019 GMT
== Info:        expire date: Feb 10 19:16:31 2020 GMT
== Info:        common name: acme-v01.api.letsencrypt.org
== Info:        issuer: CN=Let's Encrypt Authority X3,O=Let's Encrypt,C=US
=> Send header, 222 bytes (0xde)
0000: POST /acme/chall-v3/1779445656/Wzl3Jg HTTP/1.1
0030: User-Agent: acme.sh/2.8.4 (https://github.com/Neilpang/acme.sh)
0071: Host: acme-v02.api.letsencrypt.org
0095: Accept: */*
00a2: Content-Type: application/jose+json
00c7: Content-Length: 689
00dc: 
=> Send data, 689 bytes (0x2b1)
0000: {"protected": "eyJub25jZSI6ICIwMDAxajVId1R2ZjA0VmFXcy11bjhkbDNwN
0040: mR0YWV2ZGcwRlJkTlFWSzZfQ2xfSSIsICJ1cmwiOiAiaHR0cHM6Ly9hY21lLXYwM
0080: i5hcGkubGV0c2VuY3J5cHQub3JnL2FjbWUvY2hhbGwtdjMvMTc3OTQ0NTY1Ni9Xe
00c0: mwzSmciLCAiYWxnIjogIlJTMjU2IiwgImtpZCI6ICJodHRwczovL2FjbWUtdjAyL
0100: mFwaS5sZXRzZW5jcnlwdC5vcmcvYWNtZS9hY2N0LzczOTczNjMzIn0", "payloa
0140: d": "e30", "signature": "eHRMx-tIqe4n245yR4ct8oK3lykv8cTgWaP-x0N
0180: GG9vwAwhPUKaS4ZB92Yqp9pY0j8txx1M1oSz0i9B7kn0PQyz5gF1v-2x8yUTIpS2
01c0: 6FOTZrGBMnS9FYYqZ6fSa8KYZ7IuqlHp64PmVCRZq7UY9Hw7Wx93sU7BBZLzgwal
0200: Uz_bXI2f4aDJjjkV92rXwt47ICf3coYyYka6PdEPdHVK3qQ3_6uZQ63gdGKteHbe
0240: Llgdd6ZjNytuRXXsLLs8KAMInYRu4OyySC2FRqvnMi6An6qUpiJPvb-VejCbkgUA
0280: 3iXZtdADmj2wSatIkceZ13eS4KgscTarYU5-AfE8oG8d3aw"}
<= Recv header, 26 bytes (0x1a)
0000: HTTP/1.1 400 Bad Request
<= Recv header, 15 bytes (0xf)
0000: Server: nginx
<= Recv header, 37 bytes (0x25)
0000: Date: Tue, 17 Dec 2019 13:50:30 GMT
<= Recv header, 40 bytes (0x28)
0000: Content-Type: application/problem+json
<= Recv header, 21 bytes (0x15)
0000: Content-Length: 144
<= Recv header, 24 bytes (0x18)
0000: Connection: keep-alive
<= Recv header, 29 bytes (0x1d)
0000: Boulder-Requester: 73973633
<= Recv header, 44 bytes (0x2c)
0000: Cache-Control: public, max-age=0, no-cache
<= Recv header, 68 bytes (0x44)
0000: Link: <https://acme-v02.api.letsencrypt.org/directory>;rel="inde
0040: x"
<= Recv header, 63 bytes (0x3f)
0000: Replay-Nonce: 0001MxG1t8X9NeRD-zwBd8AMwwVLTn3jia2Ze8N9wQ9EBFU
<= Recv header, 2 bytes (0x2)
0000: 
<= Recv data, 144 bytes (0x90)
0000: {.  "type": "urn:ietf:params:acme:error:malformed",.  "detail": 
0040: "Unable to update challenge :: authorization must be pending",. 
0080:  "status": 400.}
== Info: Connection #0 to host acme-v02.api.letsencrypt.org left intact
== Info: Closing connection #0

My web server is (include version): PulseSecure Traffic Manager v19.1

The operating system my web server runs on is (include version): RHEL6

My hosting provider, if applicable, is: N/A

I can login to a root shell on my machine (yes or no, or I don’t know): Yes

I’m using a control panel to manage my site (no, or provide the name and version of the control panel): No

The version of my client is (e.g. output of certbot --version or certbot-auto --version if you’re using Certbot): acme.sh/v2.8.4

Below is the “debug 2” of attempting to get a renewed certificate (trimmed at the beginning to be allowed to post):

[Tue Dec 17 15:03:20 GMT 2019] Http already initialized.
[Tue Dec 17 15:03:20 GMT 2019] _CURL='curl -L --silent --dump-header /root/.acme.sh/http.header  --trace-ascii /tmp/tmp.hMshVmZGwd  -g '
[Tue Dec 17 15:03:21 GMT 2019] _ret='0'
[Tue Dec 17 15:03:21 GMT 2019] responseHeaders='HTTP/1.1 200 OK
Server: nginx
Date: Tue, 17 Dec 2019 15:03:21 GMT
Content-Type: application/json
Content-Length: 798
Connection: keep-alive
Boulder-Requester: 73973633
Cache-Control: public, max-age=0, no-cache
Link: <https://acme-v02.api.letsencrypt.org/directory>;rel="index"
Replay-Nonce: 0002J_ehmf6GQ-G03t9s3BEJAIMdckfLoqV_VXQ3hRGp8eg
X-Frame-Options: DENY
Strict-Transport-Security: max-age=604800
'
[Tue Dec 17 15:03:21 GMT 2019] code='200'
[Tue Dec 17 15:03:21 GMT 2019] original='{
  "identifier": {
    "type": "dns",
    "value": "nwcdevelopment.co.uk"
  },
  "status": "pending",
  "expires": "2019-12-24T15:03:20Z",
  "challenges": [
    {
      "type": "http-01",
      "status": "pending",
      "url": "https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ",
      "token": "nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"
    },
    {
      "type": "dns-01",
      "status": "pending",
      "url": "https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/44Eg5Q",
      "token": "nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"
    },
    {
      "type": "tls-alpn-01",
      "status": "pending",
      "url": "https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/rN4zIw",
      "token": "nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"
    }
  ]
}'
[Tue Dec 17 15:03:21 GMT 2019] response='{"identifier":{"type":"dns","value":"nwcdevelopment.co.uk"},"status":"pending","expires":"2019-12-24T15:03:20Z","challenges":[{"type":"http-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"dns-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/44Eg5Q","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"tls-alpn-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/rN4zIw","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"}]}'
[Tue Dec 17 15:03:21 GMT 2019] response='{"identifier":{"type":"dns","value":"nwcdevelopment.co.uk"},"status":"pending","expires":"2019-12-24T15:03:20Z","challenges":[{"type":"http-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"dns-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/44Eg5Q","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"tls-alpn-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/rN4zIw","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"}]}'
[Tue Dec 17 15:03:21 GMT 2019] _d='nwcdevelopment.co.uk'
[Tue Dec 17 15:03:21 GMT 2019] _authorizations_map='nwcdevelopment.co.uk,{"identifier":{"type":"dns","value":"nwcdevelopment.co.uk"},"status":"pending","expires":"2019-12-24T15:03:20Z","challenges":[{"type":"http-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"dns-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/44Eg5Q","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"tls-alpn-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/rN4zIw","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"}]}
'
[Tue Dec 17 15:03:21 GMT 2019] d='nwcdevelopment.co.uk'
[Tue Dec 17 15:03:21 GMT 2019] Getting webroot for domain='nwcdevelopment.co.uk'

[Tue Dec 17 15:03:21 GMT 2019] _w='no'

[Tue Dec 17 15:03:21 GMT 2019] _currentRoot='no'
[Tue Dec 17 15:03:21 GMT 2019] _is_idn_d='nwcdevelopment.co.uk'
[Tue Dec 17 15:03:21 GMT 2019] _idn_temp

[Tue Dec 17 15:03:21 GMT 2019] _candindates='nwcdevelopment.co.uk,{"identifier":{"type":"dns","value":"nwcdevelopment.co.uk"},"status":"pending","expires":"2019-12-24T15:03:20Z","challenges":[{"type":"http-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"dns-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/44Eg5Q","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"tls-alpn-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/rN4zIw","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"}]}'
[Tue Dec 17 15:03:21 GMT 2019] response='{"identifier":{"type":"dns","value":"nwcdevelopment.co.uk"},"status":"pending","expires":"2019-12-24T15:03:20Z","challenges":[{"type":"http-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"dns-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/44Eg5Q","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"},{"type":"tls-alpn-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/rN4zIw","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"}]}'

[Tue Dec 17 15:03:21 GMT 2019] entry='"type":"http-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"'
[Tue Dec 17 15:03:21 GMT 2019] token='nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo'

[Tue Dec 17 15:03:21 GMT 2019] uri='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'
[Tue Dec 17 15:03:21 GMT 2019] keyauthorization='nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo.4NBSYUHk2S_IoOg7IlG6dz3EVgB6xqETc6lJA4prcyY'
[Tue Dec 17 15:03:21 GMT 2019] dvlist='nwcdevelopment.co.uk#nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo.4NBSYUHk2S_IoOg7IlG6dz3EVgB6xqETc6lJA4prcyY#https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ#http-01#no'

[Tue Dec 17 15:03:21 GMT 2019] d
[Tue Dec 17 15:03:21 GMT 2019] vlist='nwcdevelopment.co.uk#nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo.4NBSYUHk2S_IoOg7IlG6dz3EVgB6xqETc6lJA4prcyY#https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ#http-01#no,'
[Tue Dec 17 15:03:21 GMT 2019] d='nwcdevelopment.co.uk'
[Tue Dec 17 15:03:21 GMT 2019] ok, let's start to verify
[Tue Dec 17 15:03:21 GMT 2019] Verifying: nwcdevelopment.co.uk

[Tue Dec 17 15:03:21 GMT 2019] d='nwcdevelopment.co.uk'
[Tue Dec 17 15:03:21 GMT 2019] keyauthorization='nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo.4NBSYUHk2S_IoOg7IlG6dz3EVgB6xqETc6lJA4prcyY'
[Tue Dec 17 15:03:21 GMT 2019] uri='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'
[Tue Dec 17 15:03:21 GMT 2019] _currentRoot='no'
[Tue Dec 17 15:03:21 GMT 2019] Standalone mode server
[Tue Dec 17 15:03:21 GMT 2019] content='nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo.4NBSYUHk2S_IoOg7IlG6dz3EVgB6xqETc6lJA4prcyY'
[Tue Dec 17 15:03:21 GMT 2019] ncaddr

[Tue Dec 17 15:03:21 GMT 2019] startserver: 25979
[Tue Dec 17 15:03:21 GMT 2019] Le_HTTPPort='88'
[Tue Dec 17 15:03:21 GMT 2019] Le_Listen_V4

[Tue Dec 17 15:03:21 GMT 2019] Le_Listen_V6

[Tue Dec 17 15:03:21 GMT 2019] _content_len='87'_content_len='87'
[Tue Dec 17 15:03:21 GMT 2019] _NC='socat -d -d -v TCP-LISTEN:88,crlf,reuseaddr,fork'

2019/12/17 15:03:21 socat[27821] N listening on AF=2 0.0.0.0:88
[Tue Dec 17 15:03:22 GMT 2019] serverproc='27821'

[Tue Dec 17 15:03:22 GMT 2019] Trigger domain validation.
[Tue Dec 17 15:03:22 GMT 2019] _t_url='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'

[Tue Dec 17 15:03:22 GMT 2019] _t_key_authz='nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo.4NBSYUHk2S_IoOg7IlG6dz3EVgB6xqETc6lJA4prcyY'
[Tue Dec 17 15:03:22 GMT 2019] _t_vtype='http-01'_t_vtype='http-01'

[Tue Dec 17 15:03:22 GMT 2019] url='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'

[Tue Dec 17 15:03:22 GMT 2019] payload='{}'

[Tue Dec 17 15:03:22 GMT 2019] Use cached jwk for file: /root/.acme.sh/ca/acme-v02.api.letsencrypt.org/account.key

[Tue Dec 17 15:03:22 GMT 2019] Use _CACHED_NONCE='0002J_ehmf6GQ-G03t9s3BEJAIMdckfLoqV_VXQ3hRGp8eg'

[Tue Dec 17 15:03:22 GMT 2019] nonce='0002J_ehmf6GQ-G03t9s3BEJAIMdckfLoqV_VXQ3hRGp8eg'
[Tue Dec 17 15:03:22 GMT 2019] POST
[Tue Dec 17 15:03:22 GMT 2019] _post_url='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'

[Tue Dec 17 15:03:22 GMT 2019] body='{"protected": "eyJub25jZSI6ICIwMDAySl9laG1mNkdRLUcwM3Q5czNCRUpBSU1kY2tmTG9xVl9WWFEzaFJHcDhlZyIsICJ1cmwiOiAiaHR0cHM6Ly9hY21lLXYwMi5hcGkubGV0c2VuY3J5cHQub3JnL2FjbWUvY2hhbGwtdjMvMTc4MDI2OTYyNC9WZTFfYVEiLCAiYWxnIjogIlJTMjU2IiwgImtpZCI6ICJodHRwczovL2FjbWUtdjAyLmFwaS5sZXRzZW5jcnlwdC5vcmcvYWNtZS9hY2N0LzczOTczNjMzIn0", "payload": "e30", "signature": "HaVaBaUmoR2ABQprA1Is5wmPc9_DyBGwr774VxxxMqcj-A-n2Ro1Xh4XxRcpTL5a_QT0YQUQQDtBU4mfCt1N6jyrA7nAlJ9bZTOmBVxNhRCK_mD7mlvM7E82QiHrf1cdoIbCW1yNHyA6FZASwjqBtRVsuE7Zye6KeslE_6B2IVRtBdmoNG7jLN7iDknR_oRa8vDQliORcDUS1BsHUWH-_pEA-4s7kTVgjHm-oZF8i41mKqebbhP2oG1WuWt9JXz41eeb72bKtSbPZIjrFSPVOc0FKq2TcC-WzPoJLiGzjHfjsmrGr2mf3QaloqzVzKmdfdmLdl8wKbC-pYWSct9T7g"}'
[Tue Dec 17 15:03:22 GMT 2019] _postContentType='application/jose+json'
[Tue Dec 17 15:03:22 GMT 2019] Http already initialized.
[Tue Dec 17 15:03:23 GMT 2019] _CURL='curl -L --silent --dump-header /root/.acme.sh/http.header  --trace-ascii /tmp/tmp.hMshVmZGwd  -g '
[Tue Dec 17 15:03:23 GMT 2019] _ret='0'
[Tue Dec 17 15:03:23 GMT 2019] responseHeaders='HTTP/1.1 200 OK
Server: nginx
Date: Tue, 17 Dec 2019 15:03:23 GMT
Content-Type: application/json
Content-Length: 185
Connection: keep-alive
Boulder-Requester: 73973633
Cache-Control: public, max-age=0, no-cache
Link: <https://acme-v02.api.letsencrypt.org/directory>;rel="index"
Link: <https://acme-v02.api.letsencrypt.org/acme/authz-v3/1780269624>;rel="up"
Location: https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ
Replay-Nonce: 0002Vuw5Pl1gCEDGNUu6wduSKk8vJ3HuV6KVzzT3OPs1HKw
X-Frame-Options: DENY
Strict-Transport-Security: max-age=604800
'

[Tue Dec 17 15:03:23 GMT 2019] code='200'
[Tue Dec 17 15:03:23 GMT 2019] original='{
  "type": "http-01",
  "status": "pending",
  "url": "https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ",
  "token": "nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"
}'
[Tue Dec 17 15:03:23 GMT 2019] response='{"type":"http-01","status":"pending","url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo"}'
[Tue Dec 17 15:03:23 GMT 2019] trigger validation code: 200
[Tue Dec 17 15:03:23 GMT 2019] sleep 2 secs to verify
2019/12/17 15:03:23 socat[27821] N accepting connection from AF=2 127.0.0.1:18334 on AF=2 127.0.0.1:88
2019/12/17 15:03:23 socat[27821] N forked off child process 27963
2019/12/17 15:03:23 socat[27821] N listening on AF=2 0.0.0.0:88
2019/12/17 15:03:23 socat[27821] N listening on AF=2 0.0.0.0:88
2019/12/17 15:03:23 socat[27963] N forking off child, using socket for reading and writing
2019/12/17 15:03:23 socat[27963] N forked off child process 27964
2019/12/17 15:03:23 socat[27963] N forked off child process 27964
2019/12/17 15:03:23 socat[27963] N starting data transfer loop with FDs [4,4] and [3,3]
> 2019/12/17 15:03:23.683778  length=358 from=0 to=357
GET ET /.welwell-kknownwn/acacme--chalallengenge/nfmTUu8-G7fmTUu8-G7mMfN-roC_VjnON-roC_VjnObbrNqPXBkfynlDZCl6Vo HTTP/1.NqPXBkfynlDZCl6Vo HTTP/1.1
User-AgUser-Agent: Mozilla/5.0 (compatible; Let's Encrypt validation server; +https://www.letsencrypt.org)
X-Forwarded-For:: Mozilla/5.0 (compatible; Let's Encrypt validation server; +https://www.letsencrypt.org)
X-Forwarded-For: 52.28.236.88
Accept: */*
X-Forwarded-Pro28.236.88
Accept: */*
X-Forwarded-Proto: http
Host: nwcdevelopment.co.uk
X-Cluster-Clie http
Host: nwcdevelopment.co.uk
X-Cluster-Client-Ip: 52.28.236.88
Cop: 52.28.236.88
Connecection: Keep-Alive
Accepn: Keep-Alive
Accept-Encoding: gzip

ncoding: gzip

2019/12/17 15:03:24 socat[27963] N socket 1 (fd 4) is at EOF
< 2019/12/17 15:03:24.687152  length=126 from=0 to=125
HTTP/1.0 200 OK\r
Content-Lentent-Length: : 87\r
\r
\r
nfmnfmTUuu8-G-G7mMfMfN-roroC_VVjnOObbrNrNqPXPXBkfyfynlDDZCll6Voo.4NNBSYYUHkk2S_I_IoOg7g7IlGlG6dz3z3EVggB6xxqETcTc6lJJA4p4prcyYyY2019/12/17 15:03:24 socat[27963] N socket 1 (fd 4) is at EOF
2019/12/17 15:03:24 socat[27963] N socket 1 (fd 4) is at EOF
2019/12/17 15:03:24 socat[27963] N socket 1 (fd 4) is at EOF
2019/12/17 15:03:24 socat[27963] W read(3, 0x237fdf0, 8192): Connection reset by peer
2019/12/17 15:03:24 socat[27963] N socket 2 to socket 1 is in error
2019/12/17 15:03:24 socat[27963] N socket 1 (fd 4) is at EOF
2019/12/17 15:03:24 socat[27963] N socket 2 (fd 3) is at EOF
2019/12/17 15:03:24 socat[27963] N exiting with status 0
[Tue Dec 17 15:03:25 GMT 2019] checking
[Tue Dec 17 15:03:25 GMT 2019] url='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'

[Tue Dec 17 15:03:25 GMT 2019] payload
[Tue Dec 17 15:03:25 GMT 2019] Use cached jwk for file: /root/.acme.sh/ca/acme-v02.api.letsencrypt.org/account.key

[Tue Dec 17 15:03:25 GMT 2019] Use _CACHED_NONCE='0002Vuw5Pl1gCEDGNUu6wduSKk8vJ3HuV6KVzzT3OPs1HKw'

[Tue Dec 17 15:03:25 GMT 2019] nonce='0002Vuw5Pl1gCEDGNUu6wduSKk8vJ3HuV6KVzzT3OPs1HKw'
[Tue Dec 17 15:03:25 GMT 2019] POSTPOST
[Tue Dec 17 15:03:25 GMT 2019] _post_url='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'
[Tue Dec 17 15:03:25 GMT 2019] body='{"protected": "eyJub25jZSI6ICIwMDAyVnV3NVBsMWdDRURHTlV1NndkdVNLazh2SjNIdVY2S1Z6elQzT1BzMUhLdyIsICJ1cmwiOiAiaHR0cHM6Ly9hY21lLXYwMi5hcGkubGV0c2VuY3J5cHQub3JnL2FjbWUvY2hhbGwtdjMvMTc4MDI2OTYyNC9WZTFfYVEiLCAiYWxnIjogIlJTMjU2IiwgImtpZCI6ICJodHRwczovL2FjbWUtdjAyLmFwaS5sZXRzZW5jcnlwdC5vcmcvYWNtZS9hY2N0LzczOTczNjMzIn0", "payload": "", "signature": "ITKHq0exepx2iIGwgCkVn80GgVq1xCNknEtT9l1iF215MXBPkMJ1SuPReXV8gL_1dCMC0HaIY-RVw-vUfTo3UW8bAl-f5VsPYVP9qMTZ8Y8d0pPbxZMD_7pwCVBQD8EbGA3D1l-OfwpK0Yv8AGrOYMVM5TNAtSYPeyQDorrjwUJzBnzmW9XbrPpXKDB8vBz6s03M5suEMh1NNjnU95IN41YwkOCCX8uTq3pKbLSWceKqCskwcmQ3m456clSfmH6gO6F8KbDuj1sJNNozxHFWpcicknfiqxKmTPCaY_WXzED1Lv9EnvPLs6aWKsUc0zkOkBMf3bkLZAAhLFx4XN4vLg"}'
[Tue Dec 17 15:03:25 GMT 2019] _postContentType='application/jose+json'

[Tue Dec 17 15:03:25 GMT 2019] Http already initialized.
[Tue Dec 17 15:03:25 GMT 2019] _CURL='curl -L --silent --dump-header /root/.acme.sh/http.header  --trace-ascii /tmp/tmp.hMshVmZGwd  -g '
[Tue Dec 17 15:03:26 GMT 2019] _ret='0'
[Tue Dec 17 15:03:26 GMT 2019] responseHeaders='HTTP/1.1 200 OK
Server: nginx
Date: Tue, 17 Dec 2019 15:03:26 GMT
Content-Type: application/json
Content-Length: 744
Connection: keep-alive
Boulder-Requester: 73973633
Cache-Control: public, max-age=0, no-cache
Link: <https://acme-v02.api.letsencrypt.org/directory>;rel="index"
Link: <https://acme-v02.api.letsencrypt.org/acme/authz-v3/1780269624>;rel="up"
Location: https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ
Replay-Nonce: 01018huf9VAm56xQTq0RyIVUsltTFU6KF4S3BXBYVHHOvOw
X-Frame-Options: DENY
Strict-Transport-Security: max-age=604800
'

[Tue Dec 17 15:03:26 GMT 2019] code='200'
[Tue Dec 17 15:03:26 GMT 2019] original='{
  "type": "http-01",
  "status": "invalid",
  "error": {
    "type": "urn:ietf:params:acme:error:connection",
    "detail": "Fetching http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo: Connection reset by peer",
    "status": 400
  },
  "url": "https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ",
  "token": "nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo",
  "validationRecord": [
    {
      "url": "http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo",
      "hostname": "nwcdevelopment.co.uk",
      "port": "80",
      "addressesResolved": [
        "131.111.150.25"
      ],
      "addressUsed": "131.111.150.25"
    }
  ]
}'
[Tue Dec 17 15:03:26 GMT 2019] response='{"type":"http-01","status":"invalid","error":{"type":"urn:ietf:params:acme:error:connection","detail":"Fetching http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo: Connection reset by peer","status": 400},"url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo","validationRecord":[{"url":"http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo","hostname":"nwcdevelopment.co.uk","port":"80","addressesResolved":["131.111.150.25"],"addressUsed":"131.111.150.25"}]}'
[Tue Dec 17 15:03:26 GMT 2019] original='{"type":"http-01","status":"invalid","error":{"type":"urn:ietf:params:acme:error:connection","detail":"Fetching http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo: Connection reset by peer","status": 400},"url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo","validationRecord":[{"url":"http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo","hostname":"nwcdevelopment.co.uk","port":"80","addressesResolved":["131.111.150.25"],"addressUsed":"131.111.150.25"}]}'

[Tue Dec 17 15:03:26 GMT 2019] response='{"type":"http-01","status":"invalid","error":{"type":"urn:ietf:params:acme:error:connection","detail":"Fetching http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo: Connection reset by peer","status": 400},"url":"https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ","token":"nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo","validationRecord":[{"url":"http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo","hostname":"nwcdevelopment.co.uk","port":"80","addressesResolved":["131.111.150.25"],"addressUsed":"131.111.150.25"}]}'

[Tue Dec 17 15:03:26 GMT 2019] error='"error":{"type":"urn:ietf:params:acme:error:connection","detail":"Fetching http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo: Connection reset by peer","status": 400'

[Tue Dec 17 15:03:26 GMT 2019] errordetail='Fetching http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo: Connection reset by peer'
[Tue Dec 17 15:03:26 GMT 2019] nwcdevelopment.co.uk:Verify error:Fetching http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo: Connection reset by peer
[Tue Dec 17 15:03:26 GMT 2019] Debug: get token url.
[Tue Dec 17 15:03:26 GMT 2019] GET
[Tue Dec 17 15:03:26 GMT 2019] url='http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo'
[Tue Dec 17 15:03:26 GMT 2019] timeout=1
[Tue Dec 17 15:03:26 GMT 2019] Http already initialized.

[Tue Dec 17 15:03:26 GMT 2019] _CURL='curl -L --silent --dump-header /root/.acme.sh/http.header  --trace-ascii /tmp/tmp.hMshVmZGwd  -g  --connect-timeout 1'
2019/12/17 15:03:26 socat[27821] N accepting connection from AF=2 127.0.0.1:19402 on AF=2 127.0.0.1:88
2019/12/17 15:03:26 socat[27821] N forked off child process 28142
2019/12/17 15:03:26 socat[27821] N listening on AF=2 0.0.0.0:88
2019/12/17 15:03:26 socat[28142] N forking off child, using socket for reading and writing
2019/12/17 15:03:26 socat[28142] N forked off child process 28143
2019/12/17 15:03:26 socat[28142] N forked off child process 28143
2019/12/17 15:03:26 socat[28142] N starting data transfer loop with FDs [4,4] and [3,3]
2019/12/17 15:03:26 socat[28142] N starting data transfer loop with FDs [4,4] and [3,3]
> 2019/12/17 15:03:26.575048  length=275 from=0 to=274
GET /.wel /.well-knownown/acacme-c-challllengege/nfnfmTUuUu8-G-G7mMfMfN-roC_Vj-roC_VjnObbbbrNqqPPXBkfkfynlnlDZCl6Cl6Vo  HTTTP/1..1

User-Aggennt:: aacmme..shh/22.88.44 ((htttpss:///gitthubub.coom/N/Neillpang/acmeng/acme.sh)h)
X-F-Forwrwardeded-F-For: : 10.0.0.6464.25254
AAccecept:: *//*
X-X-Forwrwardeded-P-Prototo: h http
p
Host:ost: nwcwcdevevelopopmennt.coco.uk
k
X-Cl-Clustter-r-Clieient-t-Ip:: 1010.0.6.64.2.254


< 2019/12/17 15:03:27.578171  length=17 from=0 to=16
HTTP/1.0 200  200 OKK\r

< 2019/12/17 15:03:27.578362  length=109 from=17 to=125
Content-Length: 8: 87\r

\r
nfmTnfmTUu8-G7mM-G7mMfN-roCroC_VjnObbrNqPXBnObbrNqPXBkfynynlDZCZCl6VoVo.4N4NBSYUYUHk2k2S_IoIoOg7g7IlG6G6dz3E3EVgBB6xqqETc6c6lJAJA4prcrcyYY2019/12/17 15:03:27 socat[28142] W read(3, 0x237bde0, 8192): Connection reset by peer
2019/12/17 15:03:27 socat[28142] N socket 2 to socket 1 is in error
2019/12/17 15:03:27 socat[28142] N socket 2 (fd 3) is at EOF
2019/12/17 15:03:27 socat[28142] N socket 1 (fd 4) is at EOF
2019/12/17 15:03:27 socat[28142] N socket 2 (fd 3) is at EOF
2019/12/17 15:03:27 socat[28142] N exiting with status 0
nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo.4NBSYUHk2S_IoOg7IlG6dz3EVgB6xqETc6lJA4prcyY[Tue Dec 17 15:03:27 GMT 2019] ret='0'
[Tue Dec 17 15:03:27 GMT 2019] Skip for removelevel:

[Tue Dec 17 15:03:27 GMT 2019] pid='27821'pid='27821'
2019/12/17 15:03:27 socat[27821] W exiting on signal 15
[Tue Dec 17 15:03:27 GMT 2019] No need to restore nginx, skip.
[Tue Dec 17 15:03:27 GMT 2019] _clearupdns
[Tue Dec 17 15:03:27 GMT 2019] dns_entries

[Tue Dec 17 15:03:27 GMT 2019] skip dns.
[Tue Dec 17 15:03:27 GMT 2019] _on_issue_err_on_issue_err

[Tue Dec 17 15:03:27 GMT 2019] Please add '--debug' or '--log' to check more details.
[Tue Dec 17 15:03:27 GMT 2019] See: https://github.com/Neilpang/acme.sh/wiki/How-to-debug-acme.sh
[Tue Dec 17 15:03:27 GMT 2019] _chk_vlist='nwcdevelopment.co.uk#nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo.4NBSYUHk2S_IoOg7IlG6dz3EVgB6xqETc6lJA4prcyY#https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ#http-01#no,'
[Tue Dec 17 15:03:27 GMT 2019] start to deactivate authz

[Tue Dec 17 15:03:27 GMT 2019] Trigger domain validation.
[Tue Dec 17 15:03:27 GMT 2019] _t_url='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'
[Tue Dec 17 15:03:27 GMT 2019] _t_key_authz='nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo.4NBSYUHk2S_IoOg7IlG6dz3EVgB6xqETc6lJA4prcyY'
[Tue Dec 17 15:03:27 GMT 2019] _t_vtype
[Tue Dec 17 15:03:27 GMT 2019] url='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'
[Tue Dec 17 15:03:27 GMT 2019] payload='{}'

[Tue Dec 17 15:03:27 GMT 2019] Use cached jwk for file: /root/.acme.sh/ca/acme-v02.api.letsencrypt.org/account.key

[Tue Dec 17 15:03:27 GMT 2019] Use _CACHED_NONCE='01018huf9VAm56xQTq0RyIVUsltTFU6KF4S3BXBYVHHOvOw'
[Tue Dec 17 15:03:27 GMT 2019] nonce='01018huf9VAm56xQTq0RyIVUsltTFU6KF4S3BXBYVHHOvOw'

[Tue Dec 17 15:03:27 GMT 2019] POST
[Tue Dec 17 15:03:27 GMT 2019] _post_url='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'_post_url='https://acme-v02.api.letsencrypt.org/acme/chall-v3/1780269624/Ve1_aQ'
[Tue Dec 17 15:03:27 GMT 2019] body='{"protected": "eyJub25jZSI6ICIwMTAxOGh1ZjlWQW01NnhRVHEwUnlJVlVzbHRURlU2S0Y0UzNCWEJZVkhIT3ZPdyIsICJ1cmwiOiAiaHR0cHM6Ly9hY21lLXYwMi5hcGkubGV0c2VuY3J5cHQub3JnL2FjbWUvY2hhbGwtdjMvMTc4MDI2OTYyNC9WZTFfYVEiLCAiYWxnIjogIlJTMjU2IiwgImtpZCI6ICJodHRwczovL2FjbWUtdjAyLmFwaS5sZXRzZW5jcnlwdC5vcmcvYWNtZS9hY2N0LzczOTczNjMzIn0", "payload": "e30", "signature": "DLt30KGSgt0Iuinaqk2-0BjNTKtpKFn9HxByUNGa9baACcVOrCNFxEHpLqmU0XSpopt9CymD1t1X0-KC7BLXqkgA96vvlO7dPsS92DVbHcwfWS0kd_IwXWI6MVKW5J9EsMcF-OfH7wXPJRlIpDAfa4OllburkLfaBAWRHp4jd62FXHWQ2d2zQcnERmpo8BXSR4BtvIQsA0DqS9LAB8yV1-VWND9ODGLpLsfJsMvcSAVhgoi6nPtdJWgF-Bsds8myPjArJJNaKoAekgER5gb-2JoE1ZRCgSQVT5X1xOsIqv8ZEIol4Rt9SqzY97oPCJf4J0EacV5IyQC-h2Z4Fw-5gA"}'
[Tue Dec 17 15:03:27 GMT 2019] _postContentType='application/jose+json'

[Tue Dec 17 15:03:27 GMT 2019] Http already initialized.
[Tue Dec 17 15:03:27 GMT 2019] _CURL='curl -L --silent --dump-header /root/.acme.sh/http.header  --trace-ascii /tmp/tmp.hMshVmZGwd  -g '
[Tue Dec 17 15:03:28 GMT 2019] _ret='0'
[Tue Dec 17 15:03:28 GMT 2019] responseHeaders='HTTP/1.1 400 Bad Request
Server: nginx
Date: Tue, 17 Dec 2019 15:03:28 GMT
Content-Type: application/problem+json
Content-Length: 144
Connection: keep-alive
Boulder-Requester: 73973633
Cache-Control: public, max-age=0, no-cache
Link: <https://acme-v02.api.letsencrypt.org/directory>;rel="index"
Replay-Nonce: 00020vqiQIHItxkT8O4QVzU_G29Y6aM79MmLCB9NkQKXOnw
'
[Tue Dec 17 15:03:28 GMT 2019] code='400'code='400'

[Tue Dec 17 15:03:28 GMT 2019] original='{
  "type": "urn:ietf:params:acme:error:malformed",
  "detail": "Unable to update challenge :: authorization must be pending",
  "status": 400
}'

[Tue Dec 17 15:03:28 GMT 2019] response='{
  "type": "urn:ietf:params:acme:error:malformed",
  "detail": "Unable to update challenge :: authorization must be pending",
  "status": 400
}'
[Tue Dec 17 15:03:28 GMT 2019] 'no' does not contain 'dns'
[Tue Dec 17 15:03:28 GMT 2019] Diagnosis versions: 
openssl:openssl
OpenSSL 1.0.1e-fips 11 Feb 2013
apache:
apache doesn't exists.
nginx:
nginx doesn't exists.
socat:
socat by Gerhard Rieger - see www.dest-unreach.org
Usage:
socat [options] <bi-address> <bi-address>
[...]
2

When I am manually trying to fetch the challenge URL:

http://nwcdevelopment.co.uk/.well-known/acme-challenge/nfmTUu8-G7mMfN-roC_VjnObbrNqPXBkfynlDZCl6Vo

I got 500 internal server error. May be you should check the frontend web server error log?

1 Like
3

This error is a red herring. For some reason, acme.sh decided to retry the completion of a failed challenge. But it doesn't seem important.

The problem is here:

This is reproducible.

When a client connects to your domain for the "first" time your server is responding to the HTTP request with [RST,ACK]:

Screenshot_2019-12-18_07-09-39
Screenshot_2019-12-18_07-09-391473×95 25.4 KB

For me, this happens for a couple of attempts, and then I begin seeing the HTTP 500 (which I assume is not actually a problem because you're proxying through using standalone mode).

If I don't talk to your server for some time after that, and try again, the [RST,ACK] comes back.

There is some kind of networking issue on your side. Maybe NAT? Do you have any non-stock sysctls enabled?

1 Like
4

The issue here is that the web server (on port 88 on localhost, but port 80 when accessed through the load balancer) is only fired up when a certificate renewal process is kicked off. It doesn’t run otherwise. So you won’t ever see anything listening on HTTP that responds to “.well-known/acme-challenge” outside of certificate renewals.

5

I am just guessing, is it possible that load balancer caches the backend unreachability status? So it does not fire the backend connection all the time, instead returns error to the client immediately, if some connection was failing a bit earlier?

1 Like
6

The [RST,ACK]s seem to have stopped for the moment. Can you issue a certificate right now?

1 Like
7

That’s really, really strange. I can issue certificates at the moment! I’ve done a couple without issue. I’m going to have to talk to Networks here again today. Oddly, we too discovered that the [RST,ACK] only happens once, and then it’s fine. We think it’s a 5ish minute timeout before it reappears… Although a few days ago I was repeatedly trying different certificates one after another without pause and all of them failed. Also oddly, I was able to push through some certs yesterday while it was still misbehaving by starting one request, then during the initial pause (“Using: ss”), starting a second request for the same certificate. Obviously not a sustainable method, but an interesting datapoint. More investigations today.

8

I have today managed to renew every certificate that I attempted (12+). Whatever the issue was, it currently is not happening. Should it come back I’ll try to get some packet captures more quickly in an attempt to get more information.

Thank you everyone who did diagnostic things, or commented with thoughts.

9

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