Specifying an SSL certificate for one domain breaks on demand TLS

1. Caddy version (caddy version):

v2.2.1 h1:Q62GWHMtztnvyRU+KPOpw6fNfeCD3SkwH7SfT1Tgt2c=

2. How I run Caddy:

a. System environment:

Ubuntu 18.04.5 LTS

b. Command:

caddy run --environ --config /etc/caddy/Caddyfile

c. Service/unit/compose file:

# caddy.service
#
# For using Caddy with a config file.
#
# Make sure the ExecStart and ExecReload commands are correct
# for your installation.
#
# See https://caddyserver.com/docs/install for instructions.
#
# WARNING: This service does not use the --resume flag, so if you
# use the API to make changes, they will be overwritten by the
# Caddyfile next time the service is restarted. If you intend to
# use Caddy's API to configure it, add the --resume flag to the
# `caddy run` command or use the caddy-api.service file instead.

[Unit]
Description=Caddy
Documentation=https://caddyserver.com/docs/
After=network.target network-online.target
Requires=network-online.target

[Service]
User=caddy
Group=caddy
ExecStart=/usr/local/bin/caddy run --environ --config /etc/caddy/Caddyfile
ExecReload=/usr/local/bin/caddy reload --config /etc/caddy/Caddyfile
TimeoutStopSec=5s
LimitNOFILE=1048576
LimitNPROC=512
PrivateTmp=true
ProtectSystem=full
AmbientCapabilities=CAP_NET_BIND_SERVICE

[Install]
WantedBy=multi-user.target

d. My complete Caddyfile or JSON config:

{
  on_demand_tls {
    ask https://www.example.com/verify
  }

  admin "0.0.0.0:2019"

  storage redis {
    host         "10.0.1.1"
    port         6379
    db           2
    key_prefix   "caddytls"
    value_prefix "caddy-storage-redis"
    timeout      5
    tls_enabled  "false"
    tls_insecure "true"
  }
}

*.example.com, www.example.com, example.com {

  tls /etc/ssl/private/example.cert.pem /etc/ssl/private/example.key.pem

  log {
    output file /var/log/caddy/access.log
  }

  reverse_proxy 10.0.0.1:80 10.0.0.2:80 10.0.0.3:80 {
    lb_policy least_conn
    health_path /status
    health_interval 10s
    health_timeout 10s
  }
}

:80 {

  log {
    output file /var/log/caddy/access.log
  }

  reverse_proxy 10.0.0.1:80 10.0.0.2:80 10.0.0.3:80 {
    lb_policy least_conn
    health_path /status
    health_interval 10s
    health_timeout 10s
  }
}

:443 {

  tls support@example.com  {
    on_demand
  }

  log {
    output file /var/log/caddy/access.log
  }

  reverse_proxy 10.0.0.1:80 10.0.0.2:80 10.0.7.3:80 {
    lb_policy least_conn
    health_path /status
    health_interval 10s
    health_timeout 10s
  }
}

3. The problem I’m having:

My main site certificate works as expected. However, on demand TLS certificates are never requested and no log messages printed. The configuration works in our staging environment with the exact same configuration except that instead of *.example.com, www.example.com, example.com we have *.example.com, staging.example.com.

This appears to be a repeat of this issue and this issue, but I don’t see the TLS handshake error messages in the logs.

4. Error messages and/or full log output:

When I make a request to a custom domain pointing to our IP I receive this error:

curl https://www.somecustomdomain.com
curl: (35) error:14094438:SSL routines:ssl3_read_bytes:tlsv1 alert internal error

Requests made using HTTP work however.

5. What I already tried:

I have tried simplifying my configuration as much as possible. In the config posted above I removed handle_errors blocks that I used to serve custom error pages and a couple other matchers to block bots. On demand TLS fails with or without these blocks in the config. I also tried combining the :80 and :443 blocks.

Based on the error from curl I can tell that Caddy isn’t serving my example.com certificate. Instead it recognizes that the custom domain doesn’t match this certificate and fails during the handshake.

6. Links to relevant resources:

These Github issues appear to be related to the same issue, but I am still having this problem with v2.2.1.

Issue #3004
Issue #3670

What is in the logs when you enable debug mode?

By debug mode you do mean DEBUG log level for the default log? If so, here’s the log on startup:

Dec 14 12:36:07 haproxy2.example.com caddy[23028]: caddy.HomeDir=/var/lib/caddy
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: caddy.AppDataDir=/var/lib/caddy/.local/share/caddy
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: caddy.AppConfigDir=/var/lib/caddy/.config/caddy
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: caddy.ConfigAutosavePath=/var/lib/caddy/.config/caddy/autosave.json
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: caddy.Version=v2.2.1
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: runtime.GOOS=linux
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: runtime.GOARCH=amd64
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: runtime.Compiler=gc
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: runtime.NumCPU=8
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: runtime.GOMAXPROCS=8
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: runtime.Version=go1.14.5
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: os.Getwd=/
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: LANG=en_US.UTF-8
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: HOME=/var/lib/caddy
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: LOGNAME=caddy
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: USER=caddy
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: INVOCATION_ID=e892a3b7bfb640d48c736f9e2f30c5f1
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: JOURNAL_STREAM=9:3237814
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8677168,"msg":"using provided configuration","config_file":"/etc/caddy/caddy.json","config_adapter":"jsonc"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8704653,"logger":"admin","msg":"admin endpoint started","address":"tcp/0.0.0.0:2019","enforce_origin":false,"origins":["0.0.0.0:2019"]}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"warn","ts":1607967367.8705032,"logger":"admin","msg":"admin endpoint on open interface; host checking disabled","address":"tcp/0.0.0.0:2019"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"debug","ts":1607967367.8711243,"logger":"caddy.storage.redis","msg":"GetConfigValue [pre]:{\"Client\":null,\"ClientLocker\":null,\"Logger\":{},\"address\":\"\",\"host\":\"10.0.1.1\",\"port\":\"6379\",\"db\":2,\"password\":\"\",\"timeout\":5,\"key_prefix\":\"caddytls\",\"value_prefix\":\"caddy-storage-redis\",\"aes_key\":\"\",\"tls_ena
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"debug","ts":1607967367.871183,"logger":"caddy.storage.redis","msg":"GetConfigValue [post]:{\"Client\":null,\"ClientLocker\":null,\"Logger\":{},\"address\":\"10.0.1.102:6379\",\"host\":\"10.0.1.1\",\"port\":\"6379\",\"db\":2,\"password\":\"\",\"timeout\":5,\"key_prefix\":\"caddytls\",\"value_prefix\":\"caddy-storage-redis\",\"aes_key\"
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8712072,"logger":"caddy.storage.redis","msg":"TLS Storage are using Redis, on 10.0.1.1:6379"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8744164,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc00019c0e0"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8763702,"logger":"http","msg":"skipping automatic certificate management because one or more matching certificates are already loaded","domain":"*.example.com","server_name":"srv0"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8764188,"logger":"http","msg":"skipping automatic certificate management because one or more matching certificates are already loaded","domain":"www.example.com","server_name":"srv0"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8764448,"logger":"http","msg":"skipping automatic certificate management because one or more matching certificates are already loaded","domain":"example.com","server_name":"srv0"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8764656,"logger":"http","msg":"enabling automatic HTTP->HTTPS redirects","server_name":"srv0"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8765042,"logger":"http","msg":"server is listening only on the HTTP port, so no automatic HTTPS will be applied to this server","server_name":"srv1","http_port":80}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"warn","ts":1607967367.8765576,"logger":"http","msg":"user server is listening on same interface as automatic HTTP->HTTPS redirects; user-configured routes might override these redirects","server_name":"srv1","interface":"tcp/:80"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"debug","ts":1607967367.878186,"logger":"http","msg":"starting server loop","address":"[::]:443","http3":false,"tls":true}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"debug","ts":1607967367.878518,"logger":"http","msg":"starting server loop","address":"[::]:80","http3":false,"tls":false}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8786993,"msg":"autosaved config","file":"/var/lib/caddy/.config/caddy/autosave.json"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.878729,"msg":"serving initial configuration"}
Dec 14 12:36:07 haproxy2.example.com caddy[23028]: {"level":"info","ts":1607967367.8803988,"logger":"tls","msg":"cleaned up storage units"}
1 Like

And still no log messages are printed when clients try to connect and it fails? Re:

However, on demand TLS certificates are never requested and no log messages printed.

To clarify, by debug mode, we mean the global option:

I.e.:

{
	debug
}

I enabled debug mode. It looks like the on_demand ask URL is returning a 403 even though when I make a manual request to the verification URL using HTTPie or Curl it returns a 200. The 403s appear to be coming a response from Caddy itself because I can’t find the requests in the application logs. i.e. the verification requests are routed back through Caddy but aren’t making it all the way to the backend application, but do when I manually make the same request.

{"level":"debug","ts":1607978300.2067528,"logger":"http.stdlib","msg":"http: TLS handshake error from 62.114.32.26:50556: certificate for hostname 'validcustomdomain.com' not allowed; non-2xx status code 403 returned from https://www.example.com/verify"}

Compared to:

❯ http https://www.example.com/verify\?domain\=validcustomdomain.com
HTTP/1.1 200 OK
1 Like

I figured it out the problem. The www version of our domain is behind Cloudflare. If I change the verification URL to a different subdomain (e.g. domains.example.com) which bypasses Cloudflare’s proxy the verification request succeeds and a certificate is successfully issued for the custom domain.

My guess is that the Host or Location header isn’t set properly for those verification requests so Cloudflare doesn’t know how to route the request and is returning the 403.

2 Likes

It’s always cloudflare :joy:

2 Likes

Great, thanks for following up with your findings!

1 Like

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