Traefik is using default cert even though acme.json file is generated correctly

Question

I'm running into an odd issue using Traefik. I'd like to use ACME to generate TLS certs. My acme.json file seems to be getting populated correctly after performing verification using DNS, however, when I use OpenSSL to verify the cert, it appears to be using the default certificate provided by Traefik.

These are my settings:

[acme]
acmelogging= true
caServer = "https://acme-staging-v02.api.letsencrypt.org/directory"
delayBeforeCheck = 0
email = "<REDACTED>"
entryPoint = "https"
storage = "/etc/traefik/acme.json"
  [acme.dnsChallenge]
  delayBeforeCheck = 0
  provider = "route53"
  [[acme.domains]]
  main = "<REDACTED>"

[entryPoints]
  [entryPoints.http]
  address = ":80"
    [entryPoints.http.redirect]
    entryPoint = "https"
  [entryPoints.https]
    address = ":443"
    [entryPoints.https.tls]

And here's the subject of the certificate:

➜  Docker git:(master) ✗ openssl s_client -connect localhost:443 -servername <REDACTED> 2>/dev/null | openssl x509 -noout -subject

subject= /CN=TRAEFIK DEFAULT CERT

Answer 1

I had the same issue yesterday afternoon. In my case, this was running on a server so I left it running to continue troubleshooting this morning.

When I tried this morning, Traefik was acting as expected! (delivering the ACME certificate). I will try to investigate a little more or open an issue in Github for clarification.

Just adding this answer in case you want to test if you experience the same behaviour. Start your environment, and leave it running for some hours.

By the way, this is the second time this happens to me. First time I had the same behaviour (not working initially, and after a couple of hours of troubleshooting started working as expected).

Taking a look at the logs, I spotted the messages that should appear when it's properly working:

{"level":"debug","msg":"Certificates obtained for domains [*.<REDACTED>]","time":"2019-03-21T18:59:44Z"}
{"level":"debug","msg":"Configuration received from provider ACME: {}","time":"2019-03-21T18:59:44Z"}
.....
{"level":"debug","msg":"Add certificate for domains *.<REDACTED>","time":"2019-03-21T18:59:45Z"}
{"level":"info","msg":"Server configuration reloaded on :443","time":"2019-03-21T18:59:45Z"}
{"level":"info","msg":"Server configuration reloaded on :8080","time":"2019-03-21T18:59:45Z"}
{"level":"info","msg":"Server configuration reloaded on :80","time":"2019-03-21T18:59:45Z"}

Also I had backed up what I thought was a valid acme.json file so I compared with today's.

Old (not working)

{
  "Account": {
    "Email": "REDACTED",
    "Registration": {
      "body": {
        "status": "valid",
        "contact": [
          "mailto:REDACTED"
        ]
      },
      "uri": "https://acme-staging-v02.api.letsencrypt.org/acme/acct/ACCOUNT_ID_1"
    },
    "PrivateKey": "REDACTED",
    "KeyType": "4096"
  },
  "Certificates": null,
  "HTTPChallenges": {},
  "TLSChallenges": {}
}

New (working)

{
  "Account": {
    "Email": "REDACTED",
    "Registration": {
      "body": {
        "status": "valid",
        "contact": [
          "mailto:REDACTED"
        ]
      },
      "uri": "https://acme-staging-v02.api.letsencrypt.org/acme/acct/ACCOUNT_ID_2"
    },
    "PrivateKey": "REDACTED",
    "KeyType": "4096"
  },
  "Certificates": [
    {
      "Domain": {
        "Main": "*.REDACTED",
        "SANs": null
      },
      "Certificate": "REDACTED",
      "Key": "REDACTED"
    }
  ],
  "HTTPChallenges": {},
  "TLSChallenges": {}
}

So the main 2 changes:

• A new account id was generated (not sure why)

• Certificates field wasn't populated. What I had in my acme.json file was probably just the private key of letsencrypt generated account, but no certificate was yet issued. Certificate was only issued around 1h30 later (unable to tell as I deleted the Pod a couple of times to see if it helped, last time I killed it was 18:03UTC and it started working at 18:59UTC.

So I will put my focus now on the acme part (so far I had been assuming certificate had been properly generated since the beginning)

EDIT: Last findings

In the end, I figured out that in my scenario (not sure if it will apply to you but you can enable acme logging to find out) the problem was related to the DNS verification.

Logs (these will be shown if acmeLogging is set to truein traefik config):

{"level":"info","msg":"legolog: [INFO] [*.REDACTED] Server responded with a certificate.","time":"2019-03-22T11:14:44Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Validations succeeded; requesting certificates","time":"2019-03-22T11:14:39Z"}
{"level":"info","msg":"legolog: [INFO] dreamhost: record_removed","time":"2019-03-22T11:14:39Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Cleaning DNS-01 challenge","time":"2019-03-22T11:14:39Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] The server validated our request","time":"2019-03-22T11:14:39Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Waiting for DNS record propagation.","time":"2019-03-22T11:13:34Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Waiting for DNS record propagation.","time":"2019-03-22T11:12:34Z"}
... (1 line per minute)
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Waiting for DNS record propagation.","time":"2019-03-22T10:58:32Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Waiting for DNS record propagation.","time":"2019-03-22T10:57:32Z"}
{"level":"info","msg":"legolog: [INFO] Wait for propagation [timeout: 1h0m0s, interval: 1m0s]","time":"2019-03-22T10:57:31Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Checking DNS record propagation using [10.96.0.10:53]","time":"2019-03-22T10:57:31Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Trying to solve DNS-01","time":"2019-03-22T10:57:31Z"}
{"level":"info","msg":"legolog: [INFO] dreamhost: record_added","time":"2019-03-22T10:57:31Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Preparing to solve DNS-01","time":"2019-03-22T10:57:31Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: use dns-01 solver","time":"2019-03-22T10:57:31Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] AuthURL: https://acme-staging-v02.api.letsencrypt.org/acme/authz/REDACTED","time":"2019-03-22T10:57:31Z"}
{"level":"info","msg":"legolog: [INFO] [*.REDACTED] acme: Obtaining bundled SAN certificate","time":"2019-03-22T10:57:30Z"}
{"level":"info","msg":"legolog: [INFO] acme: Registering account for REDACTED,"time":"2019-03-22T10:57:30Z"} 

Lego (and therefore Traefik, which uses Lego) will wait until the authoritative server for the DNS replies with the right challenge (mechanism to avoid letting LetsEncrypt peform the challenge before it is ready).

In my case, Dreamhost takes a while to perform this update. Even though the change is reflected inmediately in the web portal (TXT record created), Dreamhost DNS take a while to return an updated record for it.

In above logs it only took a few minutes, but on other iterations I've seen up to 30 minutes of delay (maybe more, not sure). Maybe you have a similar issue with route53.

Funny thing is that cloudflare DNS (1.1.1.1) was resolving this much earlier than dreamhost ones (dreamhost being authoritative).

I think you can also bypass this logic by setting delayBeforeCheck to a >0 value, but it doesn't sound a good practice since LetsEncrypt challenge might fail (not sure if LetsEncrypt queries the authoritative server for this).

Hopefully this is also your scenario. By the way, another symptom of this scenario is that the DNS record remains created, since it won't be deleted until DNS challenge succeeds (or timeout is reached I assume)