Page MenuHomePhabricator

acme-chief is unable to validate challenges against GTS staging environment
Closed, ResolvedPublic

Description

Mar 08 20:22:46 acmechief-test2001 acme-chief-backend[4120947]: Running subprocess ['/usr/local/bin/acme-chief-gdnsd-sync.py', '--remote-servers', 'dns1004.wik
imedia.org', 'dns1005.wikimedia.org', 'dns1006.wikimedia.org', 'dns2004.wikimedia.org', 'dns2005.wikimedia.org', 'dns2006.wikimedia.org', 'dns3003.wikimedia.or
g', 'dns3004.wikimedia.org', 'dns4003.wikimedia.org', 'dns4004.wikimedia.org', 'dns5003.wikimedia.org', 'dns5004.wikimedia.org', 'dns6001.wikimedia.org', 'dns6
002.wikimedia.org', 'dns7001.wikimedia.org', 'dns7002.wikimedia.org', '--', '_acme-challenge.measure-ulsfo.wikimedia.org', 'f1WK--f-YIlIIevqbvg26YRQE0fgCQciBoB
ht_5kHEY', '_acme-challenge.measure-magru.wikimedia.org', '1MwHNTa36xEN7iASMi0rgL0nsYyYKIj7Vv_RmK6Sbq4', '_acme-challenge.measure-drmrs.wikimedia.org', 'C-DfsS
te5NrPYN1STQ-MW-G2k2ibdXwFB6H2ruW4ciI', '_acme-challenge.measure-esams.wikimedia.org', 'xFLiyzl9vfr-j-MyD4n1UMtPBI0GGDx5lhvAaHTW_TA', '_acme-challenge.measure-
eqsin.wikimedia.org', 'EKs_g6e3d1Q81swaTvqOvKZtq-zF-rRP-k9PG36Tfxg', '_acme-challenge.measure-eqiad.wikimedia.org', 'wpx4ZWZg0WK97evGd28rSMRff_oiy-uo3sMHparejH
g', '_acme-challenge.measure-codfw.wikimedia.org', 'ANs-hxMiWVooqLtr3gLzTyLRusDIujH1j5sYFhSqLZ0']                                       
Mar 08 20:22:51 acmechief-test2001 acme-chief-backend[4120947]: Handling pushed CSR event for measure-goog / ec-prime256v1              
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]: Handling validated challenges event for measure-goog / ec-prime256v1                           
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]: Traceback (most recent call last):                        
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme_chief/acme_requests.py", line 415, in push_solved_c
hallenges                                                                                                                                                      
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     self.acme_client.answer_challenge(challenge, response)                                     
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme/client.py", line 397, in answer_challenge
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     resp = self._post(challb.uri, response)                               
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^                                                    
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme/client.py", line 338, in _post                  
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     return self.net.post(*args, **kwargs)                                          
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^                                                      
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme/client.py", line 711, in post                      
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     return self._post_once(*args, **kwargs)                                  
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^                                                    
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme/client.py", line 724, in _post_once                
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     response = self._check_response(response, content_type=content_type)                       Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^                       Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme/client.py", line 575, in _check_response           Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     raise messages.Error.from_json(jobj)                                                       Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]: acme.messages.Error: urn:ietf:params:acme:error:malformed :: The request message was malformed :: Only "pending" challenges may be validated                                                                                                                  Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]: The above exception was the direct cause of the following exception:                           
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]: Traceback (most recent call last):                                  
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/bin/acme-chief-backend", line 33, in <module>                
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     sys.exit(load_entry_point('acme-chief==0.38', 'console_scripts', 'acme-chief-backend')())  
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^   
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme_chief/acme_chief.py", line 984, in main
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     ACMEChief().run()                                                                          
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme_chief/acme_chief.py", line 408, in run             
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     self.certificate_management()                                            
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme_chief/acme_chief.py", line 955, in certificate_mana
gement                                                                                                                                                         
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     new_status = self._new_certificate(cert_id, key_type_id)                                   
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^                                   
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme_chief/acme_chief.py", line 599, in _new_certificate
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     status = self._handle_pushed_csr(cert_id, key_type_id)                                     
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^                                     
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme_chief/acme_chief.py", line 650, in _handle_pushed_c
sr                                                                                                                                                             
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     status = self._handle_validated_challenges(cert_id, key_type_id)
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^                           
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme_chief/acme_chief.py", line 677, in _handle_validate
d_challenges                                                                                                                                                   
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     session.push_solved_challenges(csr_id, challenge_type=challenge_type)                      
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:   File "/usr/lib/python3/dist-packages/acme_chief/acme_requests.py", line 417, in push_solved_c
hallenges                                                                                                                                                      
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]:     raise ACMEError('Unable to answer challenge') from answer_challenge_error
Mar 08 20:23:11 acmechief-test2001 acme-chief-backend[4120947]: acme_chief.acme_requests.ACMEError: Unable to answer challenge

Details

Related Changes in GitLab:
TitleReferenceAuthorSource BranchDest Branch
acme_requests: Skip challenges flagged as VALIDrepos/sre/acme-chief!19vgutierrezT419352main
Customize query in GitLab

Event Timeline

Icinga downtime and Alertmanager silence (ID=76b75fef-29b4-41de-866b-831397b1b2af) set by vgutierrez@cumin1003 for 1 day, 0:00:00 on 1 host(s) and their services with reason: GTS issues

acmechief-test2001.codfw.wmnet

I've tried to patch our client to skip already validated challenges but I'm running into another issue, this is the request flow performed by acme-chief:

  1. Fetch directory: GET https://dv.acme-v02.test-api.pki.goog/directory -> 200 OK, JSON directory object
  1. Fetch nonce: HEAD https://dv.acme-v02.test-api.pki.goog/new-nonce -> 200 OK, Replay-Nonce returned
  1. Create new order (SAN order with 7 identifiers): POST https://dv.acme-v02.test-api.pki.goog/new-order Payload: {"identifiers":[...7 dns identifiers...]} -> 201 Created Location: https://dv.acme-v02.test-api.pki.goog/order/7lLV4e_eNGoHtC1NNlEYWQ Order body includes:
    • status: "pending"
    • authorizations: 7 authz URLs
    • finalize URL
  1. Fetch each authorization (POST-as-GET to each authz URL): Example: POST https://dv.acme-v02.test-api.pki.goog/authz/2yD8-9J12GPK86pcstvlXw -> 200 OK Returned authorization for identifier "measure-ulsfo.wikimedia.org":
    • authz.status = "valid"
    • dns-01 challenge status = "valid"
    • validated = "2026-03-06T05:55:33.309977693Z" (This indicates staging is reusing previously valid authorizations.)

      Other authzs returned "pending" and included multiple challenge types (http-01, dns-01, tls-alpn-01), with dns-01 challenges in "pending" status.
  1. Publish dns-01 challenge TXT records (our integration step): We update DNS with TXT records under _acme-challenge.<domain> for all pending identifiers.
  1. Trigger validation by answering dns-01 challenges: Our client POSTs an empty JSON object {} (JWS signed) to each selected challenge URL.

    6a) For one challenge, server includes the expected rel="up" link: POST https://dv.acme-v02.test-api.pki.goog/challenge/h6qI_Wh8VYpfI1yWbvzdJQ -> 200 OK Headers include: Link: https://dv.acme-v02.test-api.pki.goog/authz/AgVWYwe755dJA1k7YWJAFg;rel="up", https://dv.acme-v02.test-api.pki.goog/directory;rel="index" Body (JSON) shows challenge status transitions to "processing".

    6b) For a subsequent challenge in the same order, server returns 200 but omits Link rel="up": POST https://dv.acme-v02.test-api.pki.goog/challenge/6pmycOOEGw3Boo0KWnksiQ -> 200 OK Headers include: Link: https://dv.acme-v02.test-api.pki.goog/directory;rel="index" (No rel="up" link is present) Body (JSON) shows: {"type":"dns-01","url":"https://dv.acme-v02.test-api.pki.goog/challenge/6pmycOOEGw3Boo0KWnksiQ","status":"processing","token":"..."}

Observed client failure

The python acme library’s ClientV2.answer_challenge() expects the response to include Link: ...;rel="up" and attempts to read it via resp.links['up']['url']. When the up link is missing, it raises:

  • KeyError: 'up'
  • acme.errors.ClientError: '"up" Link header missing'

I'm reporting this to GTS via their contact form

Mentioned in SAL (#wikimedia-traffic) [2026-03-09T15:44:15Z] <vgutierrez> vgutierrez@acmechief-test2001:~$ sudo -i systemctl disable reload-acme-chief-backend.timer - T419352

Vgutierrez lowered the priority of this task from High to Medium.Mar 9 2026, 5:45 PM

with the patch applied acme-chief was able to issue the certificate a few hours after reporting the issue to GTS (no active answer from them though)

Mentioned in SAL (#wikimedia-operations) [2026-03-10T13:27:36Z] <vgutierrez> upload acme-chief 0.39 to bookworm-wikimedia (apt.wm.o) - T419352

Mentioned in SAL (#wikimedia-traffic) [2026-03-10T13:28:40Z] <vgutierrez> testing acme-chief 0.39 in acmechief-test2001 - T419352

Mentioned in SAL (#wikimedia-operations) [2026-03-11T11:37:55Z] <vgutierrez> upgrading to acme-chief 0.39 on acme-chief production instances - T419352

Vgutierrez claimed this task.

Thanks for identifying and fixing this, @Vgutierrez!