Automatic https fails challenge. I can't figure out why

Help
1

1. Caddy version (caddy version):

v2.4.3

2. How I run Caddy:

It is on an (at the moment) single pod in a kubernetes cluster behind an aws load balancer. The load balancer forwards both 80 and 443 to this pod which accepts traffic on both 80 and 443 respectively, and I have confirmed that traffic is getting there.

a. System environment:

Amazon Linux, in docker in an eks kubernetes cluster.

b. Command:

caddy run --config Caddyfile

c. Service/unit/compose file:

There is no service / unit / etc at this point, just a running pod.

d. My complete Caddyfile or JSON config:

{
    storage dynamodb caddyserver {
      aws_region "us-east-1"
    }
    debug
    on_demand_tls {
       # for testing purposes, I promise.
        ask      https://www.google.com
        interval 2m
        burst    5
    }
    email "cloud@myhost.com"
    acme_ca "https://acme-staging-v02.api.letsencrypt.org/directory"
}

https:// {
    tls {
        on_demand
    }
    reverse_proxy myhost.customersites:8000
}

3. The problem I’m having:

My goal is to automatically lets encrypt any customer owned domain that points to it.

4. Error messages and/or full log output:

When I, with a test domain from my personal site try to:

curl -vvv https://caddy7.mcwebsite.net/asdf

It hangs for awhile while these logs are produced

2021/08/30 13:18:34.529	INFO	tls.on_demand	obtaining new certificate	{"server_name": "caddy7.mcwebsite.net"}
2021/08/30 13:18:34.553	INFO	tls.obtain	acquiring lock	{"identifier": "caddy7.mcwebsite.net"}
2021/08/30 13:18:34.562	INFO	tls.obtain	lock acquired	{"identifier": "caddy7.mcwebsite.net"}
2021/08/30 13:18:34.571	DEBUG	tls.obtain	trying issuer 1/1	{"issuer": "acme-staging-v02.api.letsencrypt.org-directory"}
2021/08/30 13:18:34.580	INFO	tls.issuance.acme	waiting on internal rate limiter	{"identifiers": ["caddy7.mcwebsite.net"], "ca": "https://acme-staging-v02.api.letsencrypt.org/directory", "account": "cloud@simplecast.com"}
2021/08/30 13:18:34.580	INFO	tls.issuance.acme	done waiting on internal rate limiter	{"identifiers": ["caddy7.mcwebsite.net"], "ca": "https://acme-staging-v02.api.letsencrypt.org/directory", "account": "cloud@simplecast.com"}
2021/08/30 13:18:34.849	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "HEAD", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-nonce", "headers": {"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Cache-Control":["public, max-age=0, no-cache"],"Date":["Mon, 30 Aug 2021 13:18:34 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0002-Rv8BgHyDJJSdQmgS_o7a2AVdtxWvGOqVcnd0qfzp8E"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:34.929	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-order", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 201, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["354"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:34 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/order/24798248/421268108"],"Replay-Nonce":["0001edxTSDXguY6X3FwoZSFL4l9TjbvfgdQNxd-SCWCMzXY"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:34.985	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/389149268", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["819"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:34 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0002Z6DUsbN0gbKycmPfvuW5SSfG78iZtYgYhE_VP_YhNXQ"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:34.985	DEBUG	tls.issuance.acme.acme_client	no solver configured	{"challenge_type": "dns-01"}
2021/08/30 13:18:34.985	INFO	tls.issuance.acme.acme_client	trying to solve challenge	{"identifier": "caddy7.mcwebsite.net", "challenge_type": "http-01", "ca": "https://acme-staging-v02.api.letsencrypt.org/directory"}
2021/08/30 13:18:35.051	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/389149268/vHnQeA", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["192"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:35 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/389149268>;rel=\"up\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/389149268/vHnQeA"],"Replay-Nonce":["0002ZVzlIOAsVZu4gnuM2MCnJZXlBO8nO6JTIq-awCvPzS0"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:35.051	DEBUG	tls.issuance.acme.acme_client	challenge accepted	{"identifier": "caddy7.mcwebsite.net", "challenge_type": "http-01"}
2021/08/30 13:18:35.359	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/389149268", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["819"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:35 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0002te6jlgzs99uXsuWr9JcanFozHNt8X0tEyGuEyrV8Q0Q"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:35.667	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/389149268", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["1268"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:35 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0001U7bh_rwp_b4314IA355piZwO2LQvvPtK7CzLhdsu7MA"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:35.673	ERROR	tls.issuance.acme.acme_client	challenge failed	{"identifier": "caddy7.mcwebsite.net", "challenge_type": "http-01", "status_code": 403, "problem_type": "urn:ietf:params:acme:error:unauthorized", "error": "Invalid response from http://caddy7.mcwebsite.net/.well-known/acme-challenge/Plf50EQ6v8PYcWIi3M32Z3BTRfKz8YJ1pAQ94UeDj2s [3.209.36.65]: \"<!doctype html>\\n<html lang=\\\"en\\\">\\n  <head>\\n\\t<meta name=\\\"generator\\\" content=\\\"Hugo 0.55.3\\\" />\\n    <meta charset=\\\"utf-8\\\">\\n    <meta \""}
2021/08/30 13:18:35.673	ERROR	tls.issuance.acme.acme_client	validating authorization	{"identifier": "caddy7.mcwebsite.net", "error": "authorization failed: HTTP 403 urn:ietf:params:acme:error:unauthorized - Invalid response from http://caddy7.mcwebsite.net/.well-known/acme-challenge/Plf50EQ6v8PYcWIi3M32Z3BTRfKz8YJ1pAQ94UeDj2s [3.209.36.65]: \"<!doctype html>\\n<html lang=\\\"en\\\">\\n  <head>\\n\\t<meta name=\\\"generator\\\" content=\\\"Hugo 0.55.3\\\" />\\n    <meta charset=\\\"utf-8\\\">\\n    <meta \"", "order": "https://acme-staging-v02.api.letsencrypt.org/acme/order/24798248/421268108", "attempt": 1, "max_attempts": 3}
2021/08/30 13:18:36.753	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-order", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 201, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["354"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:36 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/order/24798248/421268178"],"Replay-Nonce":["0002mYAJwxDqxrosRMOF04FZWZX9adjK1CAoectvKsmFGwg"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:36.810	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/389149328", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["819"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:36 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0001roKfdh7Lre1PxndC6m4n71viLAhdh6Dw-HYs7XpCO3M"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:36.810	DEBUG	tls.issuance.acme.acme_client	no solver configured	{"challenge_type": "dns-01"}
2021/08/30 13:18:36.811	INFO	tls.issuance.acme.acme_client	trying to solve challenge	{"identifier": "caddy7.mcwebsite.net", "challenge_type": "tls-alpn-01", "ca": "https://acme-staging-v02.api.letsencrypt.org/directory"}
2021/08/30 13:18:36.817	DEBUG	http.stdlib	http: TLS handshake error from 127.0.0.1:50714: EOF
2021/08/30 13:18:36.882	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/389149328/b92zww", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["196"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:36 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\"","<https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/389149328>;rel=\"up\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/chall-v3/389149328/b92zww"],"Replay-Nonce":["0001kHH4oLvafa9TNwu-RwZF5DzwpqcK1q_TLlHVInFHQTg"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:36.882	DEBUG	tls.issuance.acme.acme_client	challenge accepted	{"identifier": "caddy7.mcwebsite.net", "challenge_type": "tls-alpn-01"}
2021/08/30 13:18:37.189	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/389149328", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["866"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:37 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0002C3dfybGHvUkWB0C0GEkxPeqRLxWRXKeuDLbyV9BWWT8"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:37.195	ERROR	tls.issuance.acme.acme_client	challenge failed	{"identifier": "caddy7.mcwebsite.net", "challenge_type": "tls-alpn-01", "status_code": 403, "problem_type": "urn:ietf:params:acme:error:unauthorized", "error": "Cannot negotiate ALPN protocol \"acme-tls/1\" for tls-alpn-01 challenge"}
2021/08/30 13:18:37.195	ERROR	tls.issuance.acme.acme_client	validating authorization	{"identifier": "caddy7.mcwebsite.net", "error": "authorization failed: HTTP 403 urn:ietf:params:acme:error:unauthorized - Cannot negotiate ALPN protocol \"acme-tls/1\" for tls-alpn-01 challenge", "order": "https://acme-staging-v02.api.letsencrypt.org/acme/order/24798248/421268178", "attempt": 2, "max_attempts": 3}
2021/08/30 13:18:38.275	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/new-order", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 201, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["354"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:38 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Location":["https://acme-staging-v02.api.letsencrypt.org/acme/order/24798248/421268278"],"Replay-Nonce":["00021BIP66Rkze3A0ak1x4VFMnKcEmjD0zsZYHq4hdCUNmQ"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:38.332	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/389149428", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["819"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:38 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0001U4NpZauCd6g2UGEBLd9FuKZL5ph6eCF0ZNShVY8AwXw"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:38.332	DEBUG	tls.issuance.acme.acme_client	no solver configured	{"challenge_type": "dns-01"}
2021/08/30 13:18:38.942	DEBUG	tls.issuance.acme.acme_client	http request	{"method": "POST", "url": "https://acme-staging-v02.api.letsencrypt.org/acme/authz-v3/389149428", "headers": {"Content-Type":["application/jose+json"],"User-Agent":["Caddy/2.4.3 CertMagic acmez (linux; amd64)"]}, "status_code": 200, "response_headers": {"Boulder-Requester":["24798248"],"Cache-Control":["public, max-age=0, no-cache"],"Content-Length":["823"],"Content-Type":["application/json"],"Date":["Mon, 30 Aug 2021 13:18:38 GMT"],"Link":["<https://acme-staging-v02.api.letsencrypt.org/directory>;rel=\"index\""],"Replay-Nonce":["0002ecDqr5COxLGm6ailDXiRtWZQu3oMaiR4R50oCIzj4Es"],"Server":["nginx"],"Strict-Transport-Security":["max-age=604800"],"X-Frame-Options":["DENY"]}}
2021/08/30 13:18:38.942	ERROR	tls.obtain	could not get certificate from issuer	{"identifier": "caddy7.mcwebsite.net", "issuer": "acme-staging-v02.api.letsencrypt.org-directory", "error": "[caddy7.mcwebsite.net] solving challenges: caddy7.mcwebsite.net: no solvers available for remaining challenges (configured=[http-01 tls-alpn-01] offered=[http-01 dns-01 tls-alpn-01] remaining=[dns-01]) (order=https://acme-staging-v02.api.letsencrypt.org/acme/order/24798248/421268278) (ca=https://acme-staging-v02.api.letsencrypt.org/directory)"}

5. What I already tried:

I feel like I’ve tried everything over the past week. I started out with a json config and eventually after much trial and error got to about this spot, and then flailed for a long time. Then I tried a basic caddyfile, thinking I must have missed something, and ended up at the same place.

The logs suggest that it can’t contact http://caddy7.mcwebsite.net/.well-known/acme-challenge/Plf50EQ6v8PYcWIi3M32Z3BTRfKz8YJ1pAQ94UeDj2s, and indeed, I see no such request in the logs, but when I manually curl the url that is not getting a proper response:

 curl -vvv 'http://caddy7.mcwebsite.net/.well-known/acme-challenge/Plf50EQ6v8PYcWIi3M32Z3BTRfKz8YJ1pAQ94UeDj2s'
*   Trying 107.22.177.249:80...
* Connected to caddy7.mcwebsite.net (107.22.177.249) port 80 (#0)
> GET /.well-known/acme-challenge/Plf50EQ6v8PYcWIi3M32Z3BTRfKz8YJ1pAQ94UeDj2s HTTP/1.1
> Host: caddy7.mcwebsite.net
> User-Agent: curl/7.77.0
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 308 Permanent Redirect
< Connection: close
< Location: https://caddy7.mcwebsite.net/.well-known/acme-challenge/Plf50EQ6v8PYcWIi3M32Z3BTRfKz8YJ1pAQ94UeDj2s
< Server: Caddy
< Date: Mon, 30 Aug 2021 13:22:55 GMT
< Content-Length: 0
< 
* Closing connection 0

I see a log message suggesting it got there.

2021/08/30 13:22:55.391	ERROR	tls.issuance.acme	looking up info for HTTP challenge	{"host": "caddy7.mcwebsite.net", "error": "no information found to solve challenge for identifier: caddy7.mcwebsite.net"}

which suggests to me that traffic is getting there.

At this point I’m just evaluating caddy to see if it can be used in place of the system we currently have that is problematic, but if we have multiple caddy servers how do I ensure that the challenge goes off correctly if different caddy servers are involved in the various parts of the process?

2

Looks like for HTTP challenge requests, Let’s Encrypt is hitting some server that is serving a Hugo app. Make sure your DNS is properly configured, and that nothing in the way might be routing the request elsewhere.

For TLS-ALPN challenge requests, it looks like it’s just not reaching Caddy either.

When you’re testing that request locally, your DNS might be resolving to something different than it does for Let’s Encrypt. Your server needs to be publicly reachable.

1 Like
3

I couldn’t imagine what it could be, but it must be something. If I can take caddy misconfiguration off the table, that will at least narrow down my search for the cause.

4

Yeah, your config looks perfectly fine.

5

I feel like a complete moron. I had the IP for that subdomain set up wrong. It is not clear to me how traffic ever ended up in caddy in the first place, but I wasted hours chasing nothing at all. Thanks for the help.

2 Likes
6

It’s always DNS :rofl:

7

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