certcentral "wrongly" assumes that a new order always implies fulfilling new challenges
Closed, ResolvedPublic

Description

During debugging sessions we have seen that some orders are already in status "ready" instead of "pending" due to authz reutilization:

Nov 07 12:14:10   "status": "ready",
Nov 07 12:14:10   "expires": "2018-11-14T12:14:10.300723632Z",
Nov 07 12:14:10   "identifiers": [
Nov 07 12:14:10     {
Nov 07 12:14:10       "type": "dns",
Nov 07 12:14:10       "value": "pinkunicorn.wikimedia.org"
Nov 07 12:14:10     }
Nov 07 12:14:10   ],
Nov 07 12:14:10   "authorizations": [
Nov 07 12:14:10     "https://acme-staging-v02.api.letsencrypt.org/acme/authz/DmWCgev0DdvXVDA0G4_DB39k0c9D2uWu3GE1dbDhlM8"
Nov 07 12:14:10   ],
Nov 07 12:14:10   "finalize": "https://acme-staging-v02.api.letsencrypt.org/acme/finalize/7090084/12680728"
Nov 07 12:14:10 }

CertCentral should be able to detect this scenario and avoid attempting to revalidate the already valid challenges in the reused authz

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptNov 7 2018, 1:58 PM
Vgutierrez renamed this task from certcentral "wrongly" assumes that a new order always implies fulfulling new challenges to certcentral "wrongly" assumes that a new order always implies fulfilling new challenges.Nov 7 2018, 1:58 PM

Change 472188 had a related patch set uploaded (by Vgutierrez; owner: Vgutierrez):
[operations/software/certcentral@master] certcentral: Evaluate order status after creation

https://gerrit.wikimedia.org/r/472188

I've already tested this manually on certcentral1001 because it's impossible to reproduce this behaviour with pebble.

Nov 07 16:19:58 certcentral1001 certcentral-backend[20234]: Creating initial self-signed certificate for pinkunicorn / rsa-2048
Nov 07 16:19:58 certcentral1001 certcentral-backend[20234]: Creating initial self-signed certificate for pinkunicorn / ec-prime256v1
Nov 07 16:19:58 certcentral1001 certcentral-backend[20234]: Starting main loop...
Nov 07 16:19:58 certcentral1001 certcentral-backend[20234]: Handling new certificate event for pinkunicorn / rsa-2048
Nov 07 16:19:59 certcentral1001 certcentral-backend[20234]: Skipping challenge validation for certificate pinkunicorn / rsa-2048
Nov 07 16:19:59 certcentral1001 certcentral-backend[20234]: Handling new certificate event for pinkunicorn / ec-prime256v1
Nov 07 16:20:00 certcentral1001 certcentral-backend[20234]: Skipping challenge validation for certificate pinkunicorn / ec-prime256v1
Nov 07 16:20:05 certcentral1001 certcentral-backend[20234]: Handling pushed challenges event for pinkunicorn / rsa-2048
Nov 07 16:20:07 certcentral1001 certcentral-backend[20234]: Pushing the new certificate for pinkunicorn / rsa-2048

Change 472188 merged by jenkins-bot:
[operations/software/certcentral@master] certcentral: Evaluate order status after creation

https://gerrit.wikimedia.org/r/472188

Change 472621 had a related patch set uploaded (by Vgutierrez; owner: Vgutierrez):
[operations/software/certcentral@master] Release 0.6

https://gerrit.wikimedia.org/r/472621

Change 472621 merged by Vgutierrez:
[operations/software/certcentral@master] Release 0.6

https://gerrit.wikimedia.org/r/472621

Change 472623 had a related patch set uploaded (by Vgutierrez; owner: Vgutierrez):
[operations/software/certcentral@debian] certcentral: Evaluate order status after creation

https://gerrit.wikimedia.org/r/472623

Change 472625 had a related patch set uploaded (by Vgutierrez; owner: Vgutierrez):
[operations/software/certcentral@debian] Release 0.6

https://gerrit.wikimedia.org/r/472625

Change 472623 merged by Vgutierrez:
[operations/software/certcentral@debian] certcentral: Evaluate order status after creation

https://gerrit.wikimedia.org/r/472623

Change 472625 merged by Vgutierrez:
[operations/software/certcentral@debian] Release 0.6

https://gerrit.wikimedia.org/r/472625

Change 472626 had a related patch set uploaded (by Vgutierrez; owner: Vgutierrez):
[operations/software/certcentral@debian] debian: Add release 0.6 to changelog

https://gerrit.wikimedia.org/r/472626

Change 472626 merged by Vgutierrez:
[operations/software/certcentral@debian] debian: Add release 0.6 to changelog

https://gerrit.wikimedia.org/r/472626

I ran a test to issue new certificates for a non already challenged hostname: pinkunicorn2.wikimedia.org, these are the results:

certcentral1001
Nov 09 12:26:15 certcentral1001 systemd[1]: Reloading Central Certificates Service.
Nov 09 12:26:15 certcentral1001 certcentral-backend[30803]: SIGHUP received
Nov 09 12:26:15 certcentral1001 systemd[1]: Reloaded Central Certificates Service.
Nov 09 12:26:15 certcentral1001 certcentral-backend[30803]: Missing/invalid DNS zone updater CMD timeout, using the default one: 60.00
Nov 09 12:26:15 certcentral1001 certcentral-backend[30803]: New configured certificates: {'pinkunicorn2'}
Nov 09 12:26:15 certcentral1001 certcentral-backend[30803]: Number of certificates per status: Counter({'INITIAL': 2, 'VALID': 2})
Nov 09 12:26:15 certcentral1001 certcentral-backend[30803]: Creating initial self-signed certificate for pinkunicorn2 / rsa-2048
Nov 09 12:26:15 certcentral1001 certcentral-backend[30803]: Creating initial self-signed certificate for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:19 certcentral1001 certcentral-backend[30803]: Handling new certificate event for pinkunicorn2 / rsa-2048
Nov 09 12:26:20 certcentral1001 certcentral-backend[30803]: Triggering DNS zone update...
Nov 09 12:26:20 certcentral1001 certcentral-backend[30803]: Running subprocess ['/usr/local/bin/certcentral-gdnsd-sync.py', '--remote-servers', 'authdns1001.wikimedia.org', 'authdns2001.wikimedia.org', 'multatuli.wikimedia.org', '--', '_acme-challenge.pinkunicorn2.wikimedia.org', 'zgs7KCjRNsewJmWjKT6RYBNz0FP__R1VGFJT3Qz6zzA']
Nov 09 12:26:22 certcentral1001 certcentral-backend[30803]: Handling pushed CSR event for pinkunicorn2 / rsa-2048
Nov 09 12:26:22 certcentral1001 certcentral-backend[30803]: Handling validated challenges event for pinkunicorn2 / rsa-2048
Nov 09 12:26:22 certcentral1001 certcentral-backend[30803]: Handling pushed challenges event for pinkunicorn2 / rsa-2048
Nov 09 12:26:22 certcentral1001 certcentral-backend[30803]: ACME directory has rejected the challenge(s) for order https://acme-staging-v02.api.letsencrypt.org/acme/order/7090084/12874112
Nov 09 12:26:22 certcentral1001 certcentral-backend[30803]: ACME Directory has rejected the challenge(s) for certificate pinkunicorn2 / rsa-2048
Nov 09 12:26:22 certcentral1001 certcentral-backend[30803]: Handling new certificate event for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:22 certcentral1001 certcentral-backend[30803]: Triggering DNS zone update...
Nov 09 12:26:22 certcentral1001 certcentral-backend[30803]: Running subprocess ['/usr/local/bin/certcentral-gdnsd-sync.py', '--remote-servers', 'authdns1001.wikimedia.org', 'authdns2001.wikimedia.org', 'multatuli.wikimedia.org', '--', '_acme-challenge.pinkunicorn2.wikimedia.org', 'xFp3Dy08tIYnLqNNhJpRQRalpAe5bfZvs0jy38pkUJU']
Nov 09 12:26:25 certcentral1001 certcentral-backend[30803]: Handling pushed CSR event for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:25 certcentral1001 certcentral-backend[30803]: Handling validated challenges event for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:25 certcentral1001 certcentral-backend[30803]: Handling pushed challenges event for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:26 certcentral1001 certcentral-backend[30803]: ACME directory has rejected the challenge(s) for order https://acme-staging-v02.api.letsencrypt.org/acme/order/7090084/12874117
Nov 09 12:26:26 certcentral1001 certcentral-backend[30803]: ACME Directory has rejected the challenge(s) for certificate pinkunicorn2 / ec-prime256v1
certcentral2002
Nov 09 12:26:15 certcentral2001 systemd[1]: Reloading Central Certificates Service.
Nov 09 12:26:15 certcentral2001 certcentral-backend[3275]: SIGHUP received
Nov 09 12:26:15 certcentral2001 systemd[1]: Reloaded Central Certificates Service.
Nov 09 12:26:15 certcentral2001 certcentral-backend[3275]: Missing/invalid DNS zone updater CMD timeout, using the default one: 60.00
Nov 09 12:26:15 certcentral2001 certcentral-backend[3275]: New configured certificates: {'pinkunicorn2'}
Nov 09 12:26:15 certcentral2001 certcentral-backend[3275]: Number of certificates per status: Counter({'INITIAL': 2, 'VALID': 2})
Nov 09 12:26:15 certcentral2001 certcentral-backend[3275]: Creating initial self-signed certificate for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:15 certcentral2001 certcentral-backend[3275]: Creating initial self-signed certificate for pinkunicorn2 / rsa-2048
Nov 09 12:26:16 certcentral2001 certcentral-backend[3275]: Handling new certificate event for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:16 certcentral2001 certcentral-backend[3275]: Triggering DNS zone update...
Nov 09 12:26:16 certcentral2001 certcentral-backend[3275]: Running subprocess ['/usr/local/bin/certcentral-gdnsd-sync.py', '--remote-servers', 'authdns1001.wikimedia.org', 'authdns2001.wikimedia.org', 'multatuli.wikimedia.org', '--', '_acme-challenge.pinkunicorn2.wikimedia.org', 'b6_IMxhS361pfcNPJ_X3RlpXO75LMZ_5zC6IpJxXCrU']
Nov 09 12:26:19 certcentral2001 certcentral-backend[3275]: Handling pushed CSR event for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:19 certcentral2001 certcentral-backend[3275]: Handling validated challenges event for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:19 certcentral2001 certcentral-backend[3275]: Handling pushed challenges event for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:21 certcentral2001 certcentral-backend[3275]: Handling order finalized event for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:23 certcentral2001 certcentral-backend[3275]: Pushing the new certificate for pinkunicorn2 / ec-prime256v1
Nov 09 12:26:23 certcentral2001 certcentral-backend[3275]: Handling new certificate event for pinkunicorn2 / rsa-2048
Nov 09 12:26:23 certcentral2001 certcentral-backend[3275]: Skipping challenge validation for certificate pinkunicorn2 / rsa-2048
Nov 09 12:26:28 certcentral2001 certcentral-backend[3275]: Handling pushed challenges event for pinkunicorn2 / rsa-2048
Nov 09 12:26:29 certcentral2001 certcentral-backend[3275]: Handling order finalized event for pinkunicorn2 / rsa-2048
Nov 09 12:26:30 certcentral2001 certcentral-backend[3275]: Pushing the new certificate for pinkunicorn2 / rsa-2048

As expected certcentral2001 triggers a DNS zone update when issuing pinkunicorn2 / ec-prime256v1 and it gets reused for pinkunicorn2 / rsa-2048.

On the other hand, certcentral1001 is unable to get the certificate cause Let's Encrypt sets the challenges as invalid:

https://acme-staging-v02.api.letsencrypt.org/acme/authz/GVSVGwE5q-neyfrWa-OF4ncUkBLyNEBiwi0MZdW2NeE
{
  "identifier": {
    "type": "dns",
    "value": "pinkunicorn2.wikimedia.org"
  },
  "status": "invalid",
  "expires": "2018-11-16T12:26:22Z",
  "challenges": [
    {
      "type": "dns-01",
      "status": "invalid",
      "error": {
        "type": "urn:ietf:params:acme:error:unauthorized",
        "detail": "Incorrect TXT record \"b6_IMxhS361pfcNPJ_X3RlpXO75LMZ_5zC6IpJxXCrU\" found at _acme-challenge.pinkunicorn2.wikimedia.org",
        "status": 403
      },
      "url": "https://acme-staging-v02.api.letsencrypt.org/acme/challenge/GVSVGwE5q-neyfrWa-OF4ncUkBLyNEBiwi0MZdW2NeE/193761251",
      "token": "lWFLHQrx2St85PiUCVBgYt82UcwPjoXZ1BJjYuOJKHo",
      "validationRecord": [
        {
          "hostname": "pinkunicorn2.wikimedia.org"
        }
      ]
    },
    {
      "type": "http-01",
      "status": "invalid",
      "url": "https://acme-staging-v02.api.letsencrypt.org/acme/challenge/GVSVGwE5q-neyfrWa-OF4ncUkBLyNEBiwi0MZdW2NeE/193761252",
      "token": "NDmw1-F7zDFxINBCjnerIt52Rcs0n27iLaEWX_-lwCE"
    },
    {
      "type": "tls-alpn-01",
      "status": "invalid",
      "url": "https://acme-staging-v02.api.letsencrypt.org/acme/challenge/GVSVGwE5q-neyfrWa-OF4ncUkBLyNEBiwi0MZdW2NeE/193761253",
      "token": "-3-D4XamcId_oxIK50L7yodzICZUerYpJexBiATOCCI"
    }
  ]
}

and

https://acme-staging-v02.api.letsencrypt.org/acme/authz/FatfJssfXxfHIZ_LfCvC2oGEQK44x7lUSL-WlmI4m1g
{
  "identifier": {
    "type": "dns",
    "value": "pinkunicorn2.wikimedia.org"
  },
  "status": "invalid",
  "expires": "2018-11-16T12:26:19Z",
  "challenges": [
    {
      "type": "dns-01",
      "status": "invalid",
      "error": {
        "type": "urn:ietf:params:acme:error:unauthorized",
        "detail": "Incorrect TXT record \"b6_IMxhS361pfcNPJ_X3RlpXO75LMZ_5zC6IpJxXCrU\" found at _acme-challenge.pinkunicorn2.wikimedia.org",
        "status": 403
      },
      "url": "https://acme-staging-v02.api.letsencrypt.org/acme/challenge/FatfJssfXxfHIZ_LfCvC2oGEQK44x7lUSL-WlmI4m1g/193761238",
      "token": "JYw_wdABwdhz7A6HOL3LkABdZJZeEmuZp5s-2z8AR0U"
    },
    {
      "type": "tls-alpn-01",
      "status": "invalid",
      "url": "https://acme-staging-v02.api.letsencrypt.org/acme/challenge/FatfJssfXxfHIZ_LfCvC2oGEQK44x7lUSL-WlmI4m1g/193761239",
      "token": "e86Fo52VS_gaFwrdfC6Dvp3xoy98nuv9kdszETds_7I"
    },
    {
      "type": "http-01",
      "status": "invalid",
      "url": "https://acme-staging-v02.api.letsencrypt.org/acme/challenge/FatfJssfXxfHIZ_LfCvC2oGEQK44x7lUSL-WlmI4m1g/193761240",
      "token": "IGrslIkjAuS7kaORp8Ac-lo5cyOqHh0PFo_hzYERI8g"
    }
  ]
}

A second attempt, 10 minutes shows that certcentral1001 is able to fetch the certificates this time:

Nov 09 12:37:42 certcentral1001 systemd[1]: Reloading Central Certificates Service.
Nov 09 12:37:42 certcentral1001 certcentral-backend[30803]: SIGHUP received
Nov 09 12:37:42 certcentral1001 systemd[1]: Reloaded Central Certificates Service.
Nov 09 12:37:42 certcentral1001 certcentral-backend[30803]: Missing/invalid DNS zone updater CMD timeout, using the default one: 60.00
Nov 09 12:37:42 certcentral1001 certcentral-backend[30803]: Number of certificates per status: Counter({'VALID': 2, 'SELF_SIGNED': 2})
Nov 09 12:37:47 certcentral1001 certcentral-backend[30803]: Handling new certificate event for pinkunicorn2 / rsa-2048
Nov 09 12:37:47 certcentral1001 certcentral-backend[30803]: Triggering DNS zone update...
Nov 09 12:37:47 certcentral1001 certcentral-backend[30803]: Running subprocess ['/usr/local/bin/certcentral-gdnsd-sync.py', '--remote-servers', 'authdns1001.wikimedia.org', 'authdns2001.wikimedia.org', 'multatuli.wikimedia.org', '--', '_acme-challenge.pinkunicorn2.wikimedia.org', '3r0gzNp1jxAJBvwwq9gKNWgdDQNA7w801ubYd7LIo6E']
Nov 09 12:37:50 certcentral1001 certcentral-backend[30803]: Handling pushed CSR event for pinkunicorn2 / rsa-2048
Nov 09 12:37:50 certcentral1001 certcentral-backend[30803]: Handling validated challenges event for pinkunicorn2 / rsa-2048
Nov 09 12:37:50 certcentral1001 certcentral-backend[30803]: Handling pushed challenges event for pinkunicorn2 / rsa-2048
Nov 09 12:37:53 certcentral1001 certcentral-backend[30803]: Handling order finalized event for pinkunicorn2 / rsa-2048
Nov 09 12:37:54 certcentral1001 certcentral-backend[30803]: Pushing the new certificate for pinkunicorn2 / rsa-2048
Nov 09 12:37:54 certcentral1001 certcentral-backend[30803]: Handling new certificate event for pinkunicorn2 / ec-prime256v1
Nov 09 12:37:55 certcentral1001 certcentral-backend[30803]: Skipping challenge validation for certificate pinkunicorn2 / ec-prime256v1
Nov 09 12:38:00 certcentral1001 certcentral-backend[30803]: Handling pushed challenges event for pinkunicorn2 / ec-prime256v1
Nov 09 12:38:01 certcentral1001 certcentral-backend[30803]: Handling order finalized event for pinkunicorn2 / ec-prime256v1
Nov 09 12:38:02 certcentral1001 certcentral-backend[30803]: Pushing the new certificate for pinkunicorn2 / ec-prime256v1
Vgutierrez closed this task as Resolved.Tue, Nov 20, 4:56 PM
Vgutierrez triaged this task as Normal priority.