1. Caddy version (caddy version
):
- Win - v2.4.1 => D:\Code\kmpm\dns-loopia\experiment\caddy
- Linux - v2.4.1 => /srv/caddy-loopia-propagation/caddy
2. How I run Caddy:
I run a custom caddy, on 2 different machines. One is Windows and the other is a Rapberry Pi with Raspperry OS.
On RaspOS i run as root.
bin/caddy run
The binary is compiled the same way with the same options using the same ref of my caddy branch.
https://github.com/kmpm/caddy@caddyfile-propagation
xcaddy build \
--output bin/caddy \
--with github.com/caddy-dns/loopia \
--with github.com/caddyserver/caddy/v2=./caddy
a. System environment:
- Windows 10 Pro, amd64
- RaspberryOS, Raspberry Pi 4
Windows
> go version
go version go1.16.3 windows/amd64
> go env
set GO111MODULE=
set GOARCH=amd64
set GOBIN=
set GOCACHE=D:\Code\kmpm\dns-loopia\experiment\var\go-build
set GOENV=D:\Code\kmpm\dns-loopia\experiment\var\go
set GOEXE=.exe
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=D:\Code\kmpm\dns-loopia\experiment\var\pkg\mod
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=C:\Users\peter\go
set GOPRIVATE=
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=C:\Program Files\Go
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=C:\Program Files\Go\pkg\tool\windows_amd64
set GOVCS=
set GOVERSION=go1.16.3
set GCCGO=gccgo
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=NUL
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -fmessage-length=0 -fdebug-prefix-map=C:\Users\peter\AppData\Local\Temp\go-build3294507345=/tmp/go-build -gno-record-gcc-switches
RaspOS
$ go version
go version go1.16.4 linux/arm
$ go env
GO111MODULE=""
GOARCH="arm"
GOBIN=""
GOCACHE="/srv/caddy-loopia-propagation/var/go-build"
GOENV="/srv/caddy-loopia-propagation/var/go"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="arm"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/srv/caddy-loopia-propagation/var/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/root/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_arm"
GOVCS=""
GOVERSION="go1.16.4"
GCCGO="gccgo"
GOARM="6"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -marm -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build1608304632=/tmp/go-build -gno-record-gcc-switches"
b. Command:
bin/caddy run
c. Service/unit/compose file:
Not used.
d. My complete Caddyfile or JSON config:
{
debug
}
faasd1.lcl.kapi.se
reverse_proxy 127.0.0.1:8080
tls {
issuer acme {
email "<redacted email>"
propagation_timeout "15m0s"
dns loopia {
username "<redacteduser>@loopiaapi"
password "<redactedpassword>"
}
resolvers ns1.loopia.se
}
}
3. The problem I’m having:
On Windows caddy starts and creates a certificate without any issue, and it’s often done in <5 minutes.
On RaspOS it waits for the full propagation_timeout
duration and fails.
When looking at the logs I noticed that they don’t produce the same type of output.
In Windows the first thing after “trying to solve challenge” is a POST to https://acme-v02.api.letsencrypt.org/acme/chall-v3/xxxxxxxxx
.
The first thing after “trying to solve challenge” in RaspOS is much more delayed and is a POST to https://acme-v02.api.letsencrypt.org/acme/authz-v3/xxxxxxxxx
.
I have not been able to get it working on RaspOS no matter what and that differens, that chall-v3
is never called in RaspOS, seemed really strange.
Can anyone help me out, please? Ideas, theories or just wild ramblings, anything is accepted
4. Error messages and/or full log output:
Windows
> bin/caddy.exe run
2021/05/26 11:22:46.747 INFO using adjacent Caddyfile
2021/05/26 11:22:46.748 WARN input is not formatted with 'caddy fmt' {"adapter": "caddyfile", "file": "Caddyfile", "line": 2}
2021/05/26 11:22:46.756 INFO admin admin endpoint started {"address": "tcp/localhost:2019", "enforce_origin": false, "origins": ["localhost:2019", "[::1]:2019", "127.0.0.1:2019"]}
2021/05/26 11:22:46.757 INFO tls.cache.maintenance started background certificate maintenance {"cache": "0xc0003b58f0"}
2021/05/26 11:22:46.757 INFO http server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS {"server_name": "srv0", "https_port": 443}
2021/05/26 11:22:46.758 INFO http enabling automatic HTTP->HTTPS redirects {"server_name": "srv0"}
2021/05/26 11:22:46.758 INFO tls cleaning storage unit {"description": "FileStorage:C:\\Users\\peter\\AppData\\Roaming\\Caddy"}
2021/05/26 11:22:46.758 DEBUG http starting server loop {"address": "[::]:443", "http3": false, "tls": true}
2021/05/26 11:22:46.759 DEBUG http starting server loop {"address": "[::]:80", "http3": false, "tls": false}
2021/05/26 11:22:46.759 INFO http enabling automatic TLS certificate management {"domains": ["faasd1.lcl.kapi.se"]}
2021/05/26 11:22:46.761 INFO autosaved config (load with --resume flag) {"file": "C:\\Users\\peter\\AppData\\Roaming\\Caddy\\autosave.json"}
2021/05/26 11:22:46.761 INFO serving initial configuration
2021/05/26 11:22:46.761 INFO tls finished cleaning storage units
2021/05/26 11:22:46.762 INFO tls.obtain acquiring lock {"identifier": "faasd1.lcl.kapi.se"}
2021/05/26 11:22:46.836 INFO tls.obtain lock acquired {"identifier": "faasd1.lcl.kapi.se"}
2021/05/26 11:22:47.609 DEBUG tls.issuance.acme.acme_client http request {"method": "GET", "url": "https://acme-v02.api.letsencrypt.org/directory", "headers": {"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["658"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:22:49 GMT"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:22:47.759 DEBUG tls.issuance.acme.acme_client http request {"method": "HEAD", "url": "https://acme-v02.api.letsencrypt.org/acme/new-nonce", "headers": {"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Date":["Wed, 26 May 2021 11:22:49 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0004uHRhtf0Th83g96oRzTK_B5IBgGBGJtEunHFjGfmbago"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:22:47.973 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/new-acct", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 201, "response_headers": {"Boulder-Requester":["124875463"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["331"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:22:49 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://letsencrypt.org/documents/LE-SA-v1.2-November-15-2017.pdf>;rel=\"terms-of-service\""],"Location":["https://acme-v02.api.letsencrypt.org/acme/acct/124875463"],"Replay-Nonce":["0003L-GiwsSlOeIL4bjEcm3hC9zuQhcPS59Spyp84EWJy14"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:22:47.980 INFO tls.issuance.acme waiting on internal rate limiter {"identifiers": ["faasd1.lcl.kapi.se"]}
2021/05/26 11:22:47.980 INFO tls.issuance.acme done waiting on internal rate limiter {"identifiers": ["faasd1.lcl.kapi.se"]}
2021/05/26 11:22:48.269 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/new-order", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 201, "response_headers": {"Boulder-Requester":["124875463"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["340"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:22:50 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-v02.api.letsencrypt.org/acme/order/124875463/9964176239"],"Replay-Nonce":["00037nSxPHpVlN7BYfiOjrC4fZzBVGAeolDQXIx-9K2Nb4M"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:22:48.457 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/authz-v3/13451017962", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["124875463"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["799"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:22:50 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0003NqfSGO2Ws5Qr8aLpRqXIgcMAPP1CVmczwk7rz-jsKWE"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:22:48.458 INFO tls.issuance.acme.acme_client trying to solve challenge {"identifier": "faasd1.lcl.kapi.se", "challenge_type": "dns-01", "ca": "https://acme-v02.api.letsencrypt.org/directory"}
2021/05/26 11:25:40.778 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/chall-v3/13451017962/ODTgJA", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 400, "response_headers": {"Boulder-Requester":["124875463"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["173"],"Content-Type":["application/problem+json"],"Date":["Wed, 26 May 2021 11:25:42 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0004Cx21hvTRNKDMV0OWepOxhDAtBkN4LXceHe2zEiy6AKE"],"Server":["nginx"]}}
2021/05/26 11:25:40.779 DEBUG tls.issuance.acme.acme_client server rejected our nonce; retrying {"detail": "JWS has an invalid anti-replay nonce: \"0003NqfSGO2Ws5Qr8aLpRqXIgcMAPP1CVmczwk7rz-jsKWE\"", "error": "HTTP 400 urn:ietf:params:acme:error:badNonce - JWS has an invalid anti-replay nonce: \"0003NqfSGO2Ws5Qr8aLpRqXIgcMAPP1CVmczwk7rz-jsKWE\""}
2021/05/26 11:25:41.221 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/chall-v3/13451017962/ODTgJA", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["124875463"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["185"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:25:43 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://acme-v02.api.letsencrypt.org/acme/authz-v3/13451017962>;rel=\"up\""],"Location":["https://acme-v02.api.letsencrypt.org/acme/chall-v3/13451017962/ODTgJA"],"Replay-Nonce":["0003Nl9VKrTktGxhisZ_9WlM3xkmrHnSnIQbs8Xo0LwqPVo"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:25:41.222 DEBUG tls.issuance.acme.acme_client challenge accepted {"identifier": "faasd1.lcl.kapi.se", "challenge_type": "dns-01"}
2021/05/26 11:25:41.659 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/authz-v3/13451017962", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["124875463"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["799"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:25:43 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0004lNNyXqGMO0waaOD5kluPy4i3MXkdYiBkQkEodIt9alI"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:25:42.108 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/authz-v3/13451017962", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["124875463"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["799"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:25:43 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0003TJ6MNG0Vi65OmVSVqkw4c-8nA85e9cMcdqlZcPhCQGM"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:25:42.548 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/authz-v3/13451017962", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["124875463"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["510"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:25:44 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0003KyafI3GttXdzI6fxI8zkleGgxcBLjGeCGuJgEBKK4N4"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:25:56.008 INFO tls.issuance.acme.acme_client validations succeeded; finalizing order {"order": "https://acme-v02.api.letsencrypt.org/acme/order/124875463/9964176239"}
2021/05/26 11:25:56.663 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/finalize/124875463/9964176239", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["124875463"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["442"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:25:58 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-v02.api.letsencrypt.org/acme/order/124875463/9964176239"],"Replay-Nonce":["00046SXxfLYOhn7wgxH3nnFHsfdQQkFyeUq_UTOOZQ2xLgQ"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:25:56.840 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/cert/03619fd2b3a142142f3af8865dbbe48aadf0", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["5329"],"Content-Type":["application/pem-certificate-chain"],"Date":["Wed, 26 May 2021 11:25:58 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://acme-v02.api.letsencrypt.org/acme/cert/03619fd2b3a142142f3af8865dbbe48aadf0/1>;rel=\"alternate\""],"Replay-Nonce":["0003zzrvQ1jM3Xx1WQbmTJt8UbzxSPZ-TLHAPCOkg_oM2iA"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:25:57.026 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/cert/03619fd2b3a142142f3af8865dbbe48aadf0/1", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (windows; amd64)"]}, "status_code": 200, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["3405"],"Content-Type":["application/pem-certificate-chain"],"Date":["Wed, 26 May 2021 11:25:58 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://acme-v02.api.letsencrypt.org/acme/cert/03619fd2b3a142142f3af8865dbbe48aadf0/0>;rel=\"alternate\""],"Replay-Nonce":["0004MrFGa5GUqrSDx-HGQXNnos3zuDik44ss9EZNXIaUwWU"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:25:57.027 INFO tls.issuance.acme.acme_client successfully downloaded available certificate chains {"count": 2, "first_url": "https://acme-v02.api.letsencrypt.org/acme/cert/03619fd2b3a142142f3af8865dbbe48aadf0"}
2021/05/26 11:25:57.032 INFO tls.obtain certificate obtained successfully {"identifier": "faasd1.lcl.kapi.se"}
2021/05/26 11:25:57.033 INFO tls.obtain releasing lock {"identifier": "faasd1.lcl.kapi.se"}
2021/05/26 11:26:01.679 INFO shutting down {"signal": "SIGINT"}
2021/05/26 11:26:01.679 WARN exiting; byeee!! đź‘‹ {"signal": "SIGINT"}
RaspOS
$ bin/caddy run
2021/05/26 11:32:32.909 INFO using adjacent Caddyfile
2021/05/26 11:32:32.912 WARN input is not formatted with 'caddy fmt' {"adapter": "caddyfile", "file": "Caddyfile", "line": 2}
2021/05/26 11:32:32.914 INFO admin admin endpoint started {"address": "tcp/localhost:2019", "enforce_origin": false, "origins": ["localhost:2019", "[::1]:2019", "127.0.0.1:2019"]}
2021/05/26 11:32:32.915 INFO tls.cache.maintenance started background certificate maintenance {"cache": "0x28ba4b0"}
2021/05/26 11:32:32.915 INFO http server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS {"server_name": "srv0", "https_port": 443}
2021/05/26 11:32:32.917 INFO http enabling automatic HTTP->HTTPS redirects {"server_name": "srv0"}
2021/05/26 11:32:32.918 INFO tls cleaning storage unit {"description": "FileStorage:/root/.local/share/caddy"}
2021/05/26 11:32:32.918 INFO tls finished cleaning storage units
2021/05/26 11:32:32.919 DEBUG http starting server loop {"address": "[::]:443", "http3": false, "tls": true}
2021/05/26 11:32:32.920 DEBUG http starting server loop {"address": "[::]:80", "http3": false, "tls": false}
2021/05/26 11:32:32.920 INFO http enabling automatic TLS certificate management {"domains": ["faasd1.lcl.kapi.se"]}
2021/05/26 11:32:32.921 INFO autosaved config (load with --resume flag) {"file": "/root/.config/caddy/autosave.json"}
2021/05/26 11:32:32.922 INFO serving initial configuration
2021/05/26 11:32:32.922 INFO tls.obtain acquiring lock {"identifier": "faasd1.lcl.kapi.se"}
2021/05/26 11:32:32.930 INFO tls.obtain lock acquired {"identifier": "faasd1.lcl.kapi.se"}
2021/05/26 11:32:33.752 DEBUG tls.issuance.acme.acme_client http request {"method": "GET", "url": "https://acme-v02.api.letsencrypt.org/directory", "headers": {"User-Agent":["Caddy/2.4.1 CertMagic acmez (linux; arm)"]}, "status_code": 200, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["658"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:32:33 GMT"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:32:33.890 DEBUG tls.issuance.acme.acme_client http request {"method": "HEAD", "url": "https://acme-v02.api.letsencrypt.org/acme/new-nonce", "headers": {"User-Agent":["Caddy/2.4.1 CertMagic acmez (linux; arm)"]}, "status_code": 200, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Date":["Wed, 26 May 2021 11:32:33 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0103F-XX1bzcw-Gko1jUoAR3kaIllDsWp3sEtpWyFx-vfPY"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:32:34.092 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/new-acct", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (linux; arm)"]}, "status_code": 201, "response_headers": {"Boulder-Requester":["124876308"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["331"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:32:34 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://letsencrypt.org/documents/LE-SA-v1.2-November-15-2017.pdf>;rel=\"terms-of-service\""],"Location":["https://acme-v02.api.letsencrypt.org/acme/acct/124876308"],"Replay-Nonce":["0103NbUNoB4QIHoZNcyXEzvpfMuQ06Xtm1Bo6Ie88Ha0RKo"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:32:34.094 INFO tls.issuance.acme waiting on internal rate limiter {"identifiers": ["faasd1.lcl.kapi.se"]}
2021/05/26 11:32:34.095 INFO tls.issuance.acme done waiting on internal rate limiter {"identifiers": ["faasd1.lcl.kapi.se"]}
2021/05/26 11:32:34.259 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/new-order", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (linux; arm)"]}, "status_code": 201, "response_headers": {"Boulder-Requester":["124876308"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["340"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:32:34 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-v02.api.letsencrypt.org/acme/order/124876308/9964321423"],"Replay-Nonce":["0104v7r096kis1thX2mWReqER-gMXtN8PUow867sjFBL5FE"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:32:34.406 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/authz-v3/13451192785", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (linux; arm)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["124876308"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["799"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:32:34 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0104zazfdDHFRoPgek9JqXGQCVF9b9NJoKVc-M6dAdJIPtA"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:32:34.412 DEBUG tls.issuance.acme.acme_client no solver configured {"challenge_type": "http-01"}
2021/05/26 11:32:34.414 INFO tls.issuance.acme.acme_client trying to solve challenge {"identifier": "faasd1.lcl.kapi.se", "challenge_type": "dns-01", "ca": "https://acme-v02.api.letsencrypt.org/directory"}
2021/05/26 11:47:43.318 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/authz-v3/13451192785", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (linux; arm)"]}, "status_code": 400, "response_headers": {"Boulder-Requester":["124876308"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["173"],"Content-Type":["application/problem+json"],"Date":["Wed, 26 May 2021 11:47:43 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["01034jaAZKge-lEITZLTNtGgVYv_ynHc7TT0dyydMS5uRu4"],"Server":["nginx"]}}
2021/05/26 11:47:43.319 DEBUG tls.issuance.acme.acme_client server rejected our nonce; retrying {"detail": "JWS has an invalid anti-replay nonce: \"0104zazfdDHFRoPgek9JqXGQCVF9b9NJoKVc-M6dAdJIPtA\"", "error": "HTTP 400 urn:ietf:params:acme:error:badNonce - JWS has an invalid anti-replay nonce: \"0104zazfdDHFRoPgek9JqXGQCVF9b9NJoKVc-M6dAdJIPtA\""}
2021/05/26 11:47:43.722 DEBUG tls.issuance.acme.acme_client http request {"method": "POST", "url": "https://acme-v02.api.letsencrypt.org/acme/authz-v3/13451192785", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.1 CertMagic acmez (linux; arm)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["124876308"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["803"],"Content-Type":["application/json"],"Date":["Wed, 26 May 2021 11:47:43 GMT"],"Link":["<https://acme-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0103G8LHKH0frHR1yr4JkplsmZ9G7f70zpfhPEFFiKYhyIk"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/05/26 11:47:43.722 ERROR tls.obtain will retry {"error": "[faasd1.lcl.kapi.se] Obtain: [faasd1.lcl.kapi.se] solving challenges: waiting for solver certmagic.solverWrapper to be ready: timed out waiting for record to fully propagate; verify DNS provider configuration is correct - last error: <nil> (order=https://acme-v02.api.letsencrypt.org/acme/order/124876308/9964321423) (ca=https://acme-v02.api.letsencrypt.org/directory)", "attempt": 1, "retrying_in": 60, "elapsed": 910.791086928, "max_duration": 2592000}
2021/05/26 11:48:08.527 INFO shutting down {"signal": "SIGINT"}
2021/05/26 11:48:08.527 WARN exiting; byeee!! đź‘‹ {"signal": "SIGINT"}
2021/05/26 11:48:08.530 INFO tls.cache.maintenance stopped background certificate maintenance {"cache": "0x28ba4b0"}
2021/05/26 11:48:08.531 INFO tls.obtain releasing lock {"identifier": "faasd1.lcl.kapi.se"}
2021/05/26 11:48:08.532 ERROR tls.obtain unable to unlock {"identifier": "faasd1.lcl.kapi.se", "lock_key": "issue_cert_faasd1.lcl.kapi.se", "error": "remove /root/.local/share/caddy/locks/issue_cert_faasd1.lcl.kapi.se.lock: no such file or directory"}
2021/05/26 11:48:08.533 ERROR tls job failed {"error": "faasd1.lcl.kapi.se: obtaining certificate: context canceled"}
2021/05/26 11:48:08.533 INFO admin stopped previous server {"address": "tcp/localhost:2019"}
2021/05/26 11:48:08.534 INFO shutdown complete {"signal": "SIGINT", "exit_code": 0}
5. What I already tried:
- recompiled on both environments with clean GOENV, GOCACHE, GOMODCACHE
- validated git hashes on the caddy version used.
- looked for anything strange in the build logs
- tried different hostnames
- validated that the DNS reports a updated _acme-challenge TXT record on all occations using
dig