Page MenuHomePhabricator
Create Task
Maniphest T208948

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

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

Details

Related Changes in Gerrit:
SubjectAuthorRepoBranchLines +/-
debian: Add release 0.6 to changelogVgutierrezoperations/software/certcentraldebian+8 -0
Release 0.6Vgutierrezoperations/software/certcentraldebian+1 -1
certcentral: Evaluate order status after creationVgutierrezoperations/software/certcentraldebian+45 -1
Release 0.6Vgutierrezoperations/software/certcentralmaster+1 -1
certcentral: Evaluate order status after creationVgutierrezoperations/software/certcentralmaster+45 -1
Customize query in gerrit

Related Objects

Event Timeline

Vgutierrez created this task.Nov 7 2018, 1:58 PM
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
gerritbot subscribed.Nov 7 2018, 4:38 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

gerritbot added a project: Patch-For-Review.Nov 7 2018, 4:38 PM
Vgutierrez mentioned this in rOSCC200529d2433d: certcentral: Evaluate order status after creation.Nov 7 2018, 4:41 PM
Vgutierrez added a comment.Nov 7 2018, 4:46 PM

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
Vgutierrez mentioned this in rOSCC563632b94b04: certcentral: Evaluate order status after creation.Nov 8 2018, 3:55 PM
Vgutierrez mentioned this in rOSCCb6fadc7738a6: certcentral: Evaluate order status after creation.Nov 8 2018, 6:50 PM
gerritbot added a comment.Nov 8 2018, 7:40 PM

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

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

gerritbot added a comment.Nov 9 2018, 8:43 AM

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

Vgutierrez mentioned this in rOSCCd1583469c43c: Release 0.6.Nov 9 2018, 8:46 AM
gerritbot added a comment.Nov 9 2018, 8:47 AM

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

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

gerritbot added a comment.Nov 9 2018, 8:50 AM

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

gerritbot added a comment.Nov 9 2018, 8:50 AM

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

Vgutierrez mentioned this in rOSCC0c179f70f6c3: certcentral: Evaluate order status after creation.Nov 9 2018, 8:52 AM
Vgutierrez mentioned this in rOSCC69fff94a8845: Release 0.6.
gerritbot added a comment.Nov 9 2018, 8:53 AM

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

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

gerritbot added a comment.Nov 9 2018, 8:53 AM

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

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

gerritbot added a comment.Nov 9 2018, 8:57 AM

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

gerritbot added a comment.Nov 9 2018, 8:59 AM

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

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

Vgutierrez mentioned this in rOSCC39e0a2e35866: debian: Add release 0.6 to changelog.Nov 9 2018, 8:59 AM
Stashbot mentioned this in T208859: certcentral: keep track of orders and authorizations IDs when issuing certificates.Nov 9 2018, 10:50 AM
Stashbot subscribed.

Mentioned in SAL (#wikimedia-operations) [2018-11-09T10:50:54Z] <vgutierrez> uploaded certcentral 0.6 to apt.wikimedia.org (stretch) - T208859 T208948 T208967 T208970

Stashbot mentioned this in T208967: Avoid using acme.client poll_and_finalize() method.Nov 9 2018, 10:51 AM
Stashbot mentioned this in T208970: certcentral wrongly handles acme.errors.ValidationError exception.
Vgutierrez added a comment.Nov 9 2018, 12:37 PM

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"
    }
  ]
}
Vgutierrez added a comment.Nov 9 2018, 12:38 PM

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.Nov 20 2018, 4:56 PM
Vgutierrez triaged this task as Medium priority.
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits