caddy 2.6.1 - throws exceptions and doesn't seem to renew the cert

[paulo-erichsen]

I'm having 2 issues with caddy

1. I've used cloudflare DNS for a year, but recently when the domain got renewed, it seems caddy wasn't able to refresh the certificate. I'm not sure why not because I didn't change any cloudflare settings nor changed it's token
2. in the logs it looks like an exception is being thrown

I'm wondering if anyone can point me in the right direction for how to get things going again

how I build caddy

cat Dockerfile
FROM caddy:builder AS builder
RUN xcaddy build --with github.com/caddy-dns/cloudflare

FROM caddy:latest
COPY --from=builder /usr/bin/caddy /usr/bin/caddy

version

/srv # caddy version
v2.6.1 h1:EDqo59TyYWhXQnfde93Mmv4FJfYe00dO60zMiEt+pzo=

Caddyfile.j2 (it is provisioned through ansible

*.{{ domain }} {
  log {
    level INFO
    output file /logs/caddy.log {
      roll_size 10MB
      roll_keep 10
    }
  }

  tls {
    dns cloudflare {{ cloudflare_dns_token }}
  }

  encode zstd gzip

  header {
    # Enable HTTP Strict Transport Security (HSTS)
    Strict-Transport-Security "max-age=31536000;"
    # Enable cross-site filter (XSS) and tell browser to block detected attacks
    X-XSS-Protection "1; mode=block"
    # Disallow the site to be rendered within a frame (clickjacking protection)
    X-Frame-Options "DENY"
    # Prevent search engines from indexing (optional)
    X-Robots-Tag "none"
    # Server name removing
    -Server
  }

  @vault host vault.{{ domain }}
  handle @vault {
    # allow access to the admin interface only from local networks
    @insecureadmin {
      not remote_ip private_ranges
      path /admin*
    }
    redir @insecureadmin /

    # The negotiation endpoint is also proxied to Rocket
    reverse_proxy /notifications/hub/negotiate 10.10.40.10:{{ vaultwarden_http_port }}

    # notifications redirected to the websockets server
    reverse_proxy /notifications/hub 10.10.40.10:3012

    # proxy the Root directory to Rocket
    reverse_proxy 10.10.40.10:{{ vaultwarden_http_port }} {
      # Send the true remote IP to Rocket, so that vaultwarden can put this in the
      # log, so that fail2ban can ban the correct IP.
      header_up X-Real-IP {remote_host}
    }
  }

  @portainer {
    host portainer.{{ domain }}
    remote_ip private_ranges
  }
  handle @portainer {
    reverse_proxy 10.10.40.10:9000
  }

  @home {
    host home.{{ domain }}
    remote_ip private_ranges
  }
  handle @home {
    reverse_proxy 10.10.40.10:{{ homer_http_port }}
  }

  @dns1 {
    host dns1.{{ domain }}
    remote_ip private_ranges
  }
  handle @dns1 {
    route /control/status {
      reverse_proxy 10.10.5.2:{{ adguardhome_http_port }} {
        header_up Authorization "Basic {{ (adguardhome_user + ':' + adguardhome_password) | b64encode }}"
        header_down Access-Control-Allow-Origin https://home.{{ domain }}
      }
    }
    route /control/stats {
      reverse_proxy 10.10.5.2:{{ adguardhome_http_port }} {
        header_up Authorization "Basic {{ (adguardhome_user + ':' + adguardhome_password) | b64encode }}"
        header_down Access-Control-Allow-Origin https://home.{{ domain }}
      }
    }
    reverse_proxy 10.10.5.2:{{adguardhome_http_port}}
  }

  @dns2 {
    host dns2.{{ domain }}
    remote_ip private_ranges
  }
  handle @dns2 {
    route /control/status {
      reverse_proxy 10.10.5.3:{{ adguardhome_http_port }} {
        header_up Authorization "Basic {{ (adguardhome_user + ':' + adguardhome_password) | b64encode }}"
        header_down Access-Control-Allow-Origin https://home.{{ domain }}
      }
    }
    route /control/stats {
      reverse_proxy 10.10.5.3:{{ adguardhome_http_port }} {
        header_up Authorization "Basic {{ (adguardhome_user + ':' + adguardhome_password) | b64encode }}"
        header_down Access-Control-Allow-Origin https://home.{{ domain }}
      }
    }
    reverse_proxy 10.10.5.3:{{ adguardhome_http_port }}
  }

  @overseerr {
    host overseerr.{{ domain }}
    remote_ip private_ranges
  }
  handle @overseerr {
    reverse_proxy 10.10.40.10:5055
  }

  @bazarr {
    host bazarr.{{ domain }}
    remote_ip private_ranges
  }
  handle @bazarr {
    reverse_proxy 10.10.40.2:6767
  }

  @radarr {
    host radarr.{{ domain }}
    remote_ip private_ranges
  }
  handle @radarr {
    reverse_proxy 10.10.40.2:7878
  }

  @sonarr {
    host sonarr.{{ domain }}
    remote_ip private_ranges
  }
  handle @sonarr {
    reverse_proxy 10.10.40.2:8989
  }

  @prowlarr {
    host prowlarr.{{ domain }}
    remote_ip private_ranges
  }
  handle @prowlarr {
    reverse_proxy 10.10.40.2:9696
  }

  @torrent {
    host torrent.{{ domain }}
    remote_ip private_ranges
  }
  handle @torrent {
    reverse_proxy 10.10.40.2:{{ bittorrent_http_port }}
  }

  @tautulli {
    host tautulli.{{ domain }}
    remote_ip private_ranges
  }
  handle @tautulli {
    reverse_proxy 10.10.40.10:8181
  }

  # Fallback for otherwise unhandled domains
  handle {
    abort
  }
}

logs

{"level":"info","ts":1664145994.589327,"msg":"using provided configuration","config_file":"/etc/caddy/Caddyfile","config_adapter":"caddyfile"}
{"level":"warn","ts":1664145994.5913541,"msg":"Caddyfile input is not formatted; run the 'caddy fmt' command to fix inconsistencies","adapter":"caddyfile","file":"/etc/caddy/Caddyfile","line":2}
{"level":"info","ts":1664145994.5922644,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]}
{"level":"info","ts":1664145994.5924158,"logger":"http","msg":"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}
{"level":"info","ts":1664145994.5924213,"logger":"http","msg":"enabling automatic HTTP->HTTPS redirects","server_name":"srv0"}
{"level":"info","ts":1664145994.5924242,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc000453340"}
{"level":"info","ts":1664145994.5937173,"logger":"http","msg":"enabling HTTP/3 listener","addr":":443"}
{"level":"info","ts":1664145994.593757,"logger":"tls","msg":"cleaning storage unit","description":"FileStorage:/data/caddy"}
{"level":"info","ts":1664145994.5938764,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]}
{"level":"info","ts":1664145994.5938976,"logger":"http.log","msg":"server running","name":"remaining_auto_https_redirects","protocols":["h1","h2","h3"]}
{"level":"info","ts":1664145994.5938995,"logger":"http","msg":"enabling automatic TLS certificate management","domains":["*.domain.com"]}
{"level":"info","ts":1664145994.5941696,"logger":"tls","msg":"finished cleaning storage units"}
{"level":"warn","ts":1664145994.7271044,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [*.domain.com]: parsing OCSP response: ocsp: error from server: unauthorized","identifiers":["*.domain.com"]}
{"level":"info","ts":1664145994.727986,"msg":"autosaved config (load with --resume flag)","file":"/config/caddy/autosave.json"}
{"level":"info","ts":1664145994.7280016,"msg":"serving initial configuration"}
{"level":"info","ts":1664145994.7280064,"logger":"tls.renew","msg":"acquiring lock","identifier":"*.domain.com"}
{"level":"info","ts":1664145994.743657,"logger":"tls.renew","msg":"lock acquired","identifier":"*.domain.com"}
{"level":"info","ts":1664145994.744525,"logger":"tls.renew","msg":"renewing certificate","identifier":"*.domain.com","remaining":-107959.744523348}
{"level":"info","ts":1664145994.7458518,"logger":"http","msg":"waiting on internal rate limiter","identifiers":["*.domain.com"],"ca":"https://acme-v02.api.letsencrypt.org/directory","account":""}
{"level":"info","ts":1664145994.745872,"logger":"http","msg":"done waiting on internal rate limiter","identifiers":["*.domain.com"],"ca":"https://acme-v02.api.letsencrypt.org/directory","account":""}
{"level":"info","ts":1664145994.914257,"logger":"http.acme_client","msg":"trying to solve challenge","identifier":"*.domain.com","challenge_type":"dns-01","ca":"https://acme-v02.api.letsencrypt.org/directory"}
{"level":"error","ts":1664145995.1004417,"logger":"http.acme_client","msg":"cleaning up solver","identifier":"*.domain.com","challenge_type":"dns-01","error":"no memory of presenting a DNS record for \"_acme-challenge.domain.com\" (usually OK if presenting also failed)"}
{"level":"error","ts":1664145995.1213057,"logger":"tls.renew","msg":"could not get certificate from issuer","identifier":"*.domain.com","issuer":"acme-v02.api.letsencrypt.org-directory","error":"[*.domain.com] solving challenges: presenting for challenge: adding temporary record for zone \"com.\": expected 1 zone, got 0 for com. (order=https://acme-v02.api.letsencrypt.org/acme/order/489357150/128867276987) (ca=https://acme-v02.api.letsencrypt.org/directory)"}
{"level":"info","ts":1664145995.1224875,"logger":"http","msg":"waiting on internal rate limiter","identifiers":["*.domain.com"],"ca":"https://acme.zerossl.com/v2/DV90","account":"caddy@zerossl.com"}
{"level":"info","ts":1664145995.1225061,"logger":"http","msg":"done waiting on internal rate limiter","identifiers":["*.domain.com"],"ca":"https://acme.zerossl.com/v2/DV90","account":"caddy@zerossl.com"}
{"level":"info","ts":1664146038.124356,"logger":"http.acme_client","msg":"trying to solve challenge","identifier":"*.domain.com","challenge_type":"dns-01","ca":"https://acme.zerossl.com/v2/DV90"}
{"level":"error","ts":1664146038.253235,"logger":"http.acme_client","msg":"cleaning up solver","identifier":"*.domain.com","challenge_type":"dns-01","error":"no memory of presenting a DNS record for \"_acme-challenge.domain.com\" (usually OK if presenting also failed)"}
{"level":"error","ts":1664146046.0709257,"logger":"tls.renew","msg":"could not get certificate from issuer","identifier":"*.domain.com","issuer":"acme.zerossl.com-v2-DV90","error":"[*.domain.com] solving challenges: presenting for challenge: adding temporary record for zone \"com.\": expected 1 zone, got 0 for com. (order=https://acme.zerossl.com/v2/DV90/order/dVmpVFBTt8O9bmJHukXqzQ) (ca=https://acme.zerossl.com/v2/DV90)"}
{"level":"info","ts":1664146046.0710483,"logger":"tls.renew","msg":"releasing lock","identifier":"*.domain.com"}
{"level":"info","ts":1664146046.071536,"msg":"panic: certificate worker: runtime error: invalid memory address or nil pointer dereference\ngoroutine 62 [running]:\ngithub.com/caddyserver/certmagic.(*jobManager).worker.func1()\n\tgithub.com/caddyserver/certmagic@v0.17.1/async.go:58 +0x65\npanic({0x1860d60, 0x2a6d440})\n\truntime/panic.go:884 +0x212\ngithub.com/caddyserver/certmagic.(*Config).renewCert.func2({0x1e249f8, 0xc0008665a0})\n\tgithub.com/caddyserver/certmagic@v0.17.1/config.go:821 +0xc14\ngithub.com/caddyserver/certmagic.doWithRetry({0x1e24950, 0xc000a17c40}, 0xc0005decc0, 0xc000addb60)\n\tgithub.com/caddyserver/certmagic@v0.17.1/async.go:106 +0x1cb\ngithub.com/caddyserver/certmagic.(*Config).renewCert(0xc00024ca50, {0x1e24950, 0xc000a17c40}, {0xc000a742e0, 0xf}, 0x0, 0x0)\n\tgithub.com/caddyserver/certmagic@v0.17.1/config.go:860 +0x58b\ngithub.com/caddyserver/certmagic.(*Config).RenewCertAsync(...)\n\tgithub.com/caddyserver/certmagic@v0.17.1/config.go:690\ngithub.com/caddyserver/certmagic.(*Config).manageOne.func2()\n\tgithub.com/caddyserver/certmagic@v0.17.1/config.go:394 +0x20c\ngithub.com/caddyserver/certmagic.(*jobManager).worker(0x2a78160)\n\tgithub.com/caddyserver/certmagic@v0.17.1/async.go:73 +0x11b\ncreated by github.com/caddyserver/certmagic.(*jobManager).Submit\n\tgithub.com/caddyserver/certmagic@v0.17.1/async.go:50 +0x29b"}
{"level":"info","ts":1664146594.6038508,"logger":"tls.cache.maintenance","msg":"certificate expires soon; queuing for renewal","identifiers":["*.domain.com"],"remaining":-108559.603848769}
{"level":"info","ts":1664147194.6042264,"logger":"tls.cache.maintenance","msg":"certificate expires soon; queuing for renewal","identifiers":["*.domain.com"],"remaining":-109159.604224445}
{"level":"info","ts":1664147794.6033254,"logger":"tls.cache.maintenance","msg":"certificate expires soon; queuing for renewal","identifiers":["*.domain.com"],"remaining":-109759.603323866}

[francislavoie]

"error":"[*.beholderr.com] solving challenges: presenting for challenge: adding temporary record for zone \"com.\": expected 1 zone, got 0 for com

That error is coming from here https://github.com/libdns/cloudflare/blob/e5327b93fc81c687dca3c0eaed1584d98a50750e/client.go#L103, it leads me to believe there's something wrong with your Cloudflare account, that your domain isn't actually in your account 🤔 but I'm not sure.

"msg":"panic: certificate worker: runtime error: invalid memory address or nil pointer dereference\ngoroutine 62 [running]:\ngithub.com/caddyserver/certmagic.(*jobManager).worker.func1()\n\tgithub.com/caddyserver/certmagic@v0.17.1/async.go:58 +0x65\npanic({0x1860d60, 0x2a6d440})\n\truntime/panic.go:884 +0x212\ngithub.com/caddyserver/certmagic.(*Config).renewCert.func2({0x1e249f8, 0xc0008665a0})\n\tgithub.com/caddyserver/certmagic@v0.17.1/config.go:821 +0xc14\ngithub.com/caddyserver/certmagic.doWithRetry({0x1e24950, 0xc000a17c40}, 0xc0005decc0, 0xc000addb60)\n\tgithub.com/caddyserver/certmagic@v0.17.1/async.go:106 +0x1cb\ngithub.com/caddyserver/certmagic.(*Config).renewCert(0xc00024ca50, {0x1e24950, 0xc000a17c40}, {0xc000a742e0, 0xf}, 0x0, 0x0)\n\tgithub.com/caddyserver/certmagic@v0.17.1/config.go:860 +0x58b\ngithub.com/caddyserver/certmagic.(*Config).RenewCertAsync(...)\n\tgithub.com/caddyserver/certmagic@v0.17.1/config.go:690\ngithub.com/caddyserver/certmagic.(*Config).manageOne.func2()\n\tgithub.com/caddyserver/certmagic@v0.17.1/config.go:394 +0x20c\ngithub.com/caddyserver/certmagic.(*jobManager).worker(0x2a78160)\n\tgithub.com/caddyserver/certmagic@v0.17.1/async.go:73 +0x11b\ncreated by github.com/caddyserver/certmagic.(*jobManager).Submit\n\tgithub.com/caddyserver/certmagic@v0.17.1/async.go:50 +0x29b"

I think this is a bug that was just fixed in certmagic, it'll be in the next release caddyserver/certmagic@55fc6a9 unless it's a different one (please double-check @mholt). I don't think this is critical in this case though.

[mholt]

Thanks Francis. Yeah, the panic should be fixed, and I'll update the dependency shortly.

As for this error, @paulo-erichsen:

adding temporary record for zone "com.": expected 1 zone, got 0 for com.

I would need you to post your unredacted logs to be sure, but it sounds like your system's DNS is misconfigured. It appears to be resolving the nearest zone as "com." which obviously you do not control in your Cloudflare account :)

You will please need to post your full unredacted config and logs in order for us to help you, if this is a bug in CertMagic/Caddy, otherwise the evidence points to a local DNS misconfiguration.

[paulo-erichsen]

thank you @francislavoie and @mholt for your answers! that helped me fix the issue. Feel free to close this ticket (unless you'd like to track that exception here)

Like you've mentioned the issue was indeed my DNS server.
I have some iptables on my UDMP to redirect any DNS queries to my personal Adguard Home DNS servers.
Once I disabled those redirect DNS firewall rules and added resolvers 1.1.1.1 to the tls section in the Caddyfile, caddy was able to pull an updated certificate successfully!

@mholt in case it's still helpful, I've uploaded the log file here. The only thing I've redacted from it is the domain name

• http://sprunge.us/JzaBbn

[mholt]

It's always DNS 😉

Glad you figured it out. And no worries, it happens often. Whenever people come in with issues like this and are like, "It worked for the last <span of time> and I didn't change anything (relevant)," I always always always scrutinize that assumption because with networking infrastructure it is never that simple. "Oh, I did change my local network somewhat recently." -- that would do it!

It's not just you though, everyone does this, including me.

Thanks for following up and confirming!