503 with fallback certificate on http-01 challenge verification request

[arminabf]

Hello,

on a local test setup I'm using httpd-2.4.57 to integrate mod_md with boulder. The setup looks like this

• integration of virtual host acme-test.foo.com on port 443
• no certificate for this vhost
• usage of http-01 challenge
• redirection from port 80 to 443 on HTTP challenge request

MDCAChallenges http-01
Protocols acme-tls/1
MDCertificateAgreement accepted
MDCertificateStatus off 
MDStoreDir ${INST}/md
MDContactEmail test@foo.com
MDCertificateAuthority http://127.0.0.1:4001/directory
MDomain acme-test.foo.com

<VirtualHost 10.0.8.5:80>
  ServerName acme-test.foo.com

  # redirect to 443
  RewriteEngine On
  RewriteCond %{HTTPS} off
  RewriteRule (.*) https://%{HTTP_HOST}%{REQUEST_URI}
</VirtualHost>

<VirtualHost 10.0.8.5:443>
  ServerName acme-test.foo.com
  SSLEngine on
</VirtualHost>

On startup of the instance, httpd complains that "there are no SSL certificates configured".

[Tue Jun 20 10:12:45.974973 2023] [warn] AH10085: Init: acme-test.foo.com:443 will respond with '503 Service Unavailable' for now. There are no SSL certificates configured and no other module contributed any. [pid 8220:tid 4152661760] [ssl_engine_init.c(1937)]

However, by debugging (see below) the startup phase it can be seen that mod_md provides a fallback certificate for the acme-test.foo.com vhost... as also shown by debug messages

[Tue Jun 20 10:12:45.745663 2023] [info] AH01914: Configuring server acme-test.foo.com:443 for SSL protocol [pid 8220:tid 4152661760] [ssl_engine_init.c(2046)]
[Tue Jun 20 10:12:45.745669 2023] [debug] AH10113: get_certificates called for vhost acme-test.foo.com. [pid 8220:tid 4152661760] [mod_md.c(1116)]
[Tue Jun 20 10:12:45.745681 2023] [debug] AH10077: acme-test.foo.com[state=0]: providing certificates for server acme-test.foo.com [pid 8220:tid 4152661760] [mod_md.c(1211)]
[Tue Jun 20 10:12:45.745685 2023] [debug] AH10113: get_certificates called for vhost acme-test.foo.com. [pid 8220:tid 4152661760] [mod_md.c(1116)]
[Tue Jun 20 10:12:45.974948 2023] [debug] AH10116: acme-test.foo.com: providing rsa fallback certificate for server acme-test.foo.com [pid 8220:tid 4152661760] [mod_md.c(1200)]

But the challenge request (after redirection to 443) gets responded with 503 Service Unavailable...

10.77.77.77 - - [20/Jun/2023:10:48:07 +0200] "GET /.well-known/acme-challenge/18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug HTTP/1.1" 302 280 cc="-" rc="-" conc="-" "boulder-remote-a" - - - 0 198 561 759 "-" #26191
10.77.77.77 - - [20/Jun/2023:10:48:07 +0200] "GET /.well-known/acme-challenge/18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug HTTP/1.1" 302 280 cc="-" rc="-" conc="-" "boulder-remote-b" - - - 0 198 561 759 "-" #26191
10.77.77.77 - - [20/Jun/2023:10:48:07 +0200] "GET /.well-known/acme-challenge/18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug HTTP/1.1" 302 280 cc="-" rc="-" conc="-" "boulder" - - - 0 189 561 750 "-" #26191
10.77.77.77 - - [20/Jun/2023:10:48:07 +0200] "GET /.well-known/acme-challenge/18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug HTTP/1.1" 503 299 cc="-" rc="-" conc="-" "boulder" - - - 0 646 2034 2680 "-" #26191

boulder_1    | 08:48:07.143729 6 boulder-va 07Kn5AU [AUDIT] Checked CAA records for acme-test.foo.com, [Present: false, Account ID: 44, Challenge: http-01, Valid for issuance: true, Found at: ""] Response=""
boulder_1    | 08:48:07.144360 6 boulder-va zoLV9wc [AUDIT] Attempting to validate HTTP-01 for "acme-test.foo.com" with GET to "http://acme-test.foo.com/.well-known/acme-challenge/18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug"
boulder_1    | 08:48:07.174409 6 boulder-va v8qEzgM [AUDIT] Validation result JSON={"ID":"104","Requester":44,"Hostname":"acme-test.foo.com","Challenge":{"type":"http-01","status":"invalid","error":{"type":"unauthorized","detail":"10.0.8.5: Invalid response from https://acme-test.foo.com/.well-known/acme-challenge/18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug: 503","status":403},"token":"18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug","keyAuthorization":"18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug.eRVGQ-ZPP9VEiLC5GqxSsWbM-25gOttUSAj67596s2w","validationRecord":[{"url":"http://acme-test.foo.com/.well-known/acme-challenge/18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug","hostname":"acme-test.foo.com","port":"80","addressesResolved":["10.0.8.5"],"addressUsed":"10.0.8.5"},{"url":"https://acme-test.foo.com/.well-known/acme-challenge/18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug","hostname":"acme-test.foo.com","port":"443","addressesResolved":["10.0.8.5"],"addressUsed":"10.0.8.5"}]},"ValidationLatency":0.035,"Error":"unauthorized :: 10.0.8.5: Invalid response from https://acme-test.foo.com/.well-known/acme-challenge/18Jy81cFpyRJYcGQ2Tnha7lxCCt1zW6HfYKe5YokRug: 503"}

After searching for the relevant parts of the code and then debugging, I could verify that mod_md returns a fallback certificate upon call of the ssl_run_add_fallback_cert_files hook, but still the vhost is set as "service_unavailable" by ssl_engine_init.c and finally responded with 503 by ssl_engine_kernel.c.

As an experiment, I commented out this line and re-compiled the code, then the challenge request works.

10.77.77.77 - - [20/Jun/2023:10:33:01 +0200] "GET /.well-known/acme-challenge/CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU HTTP/1.1" 302 280 "boulder" - - - 0 189 561 750 "-" #18267
10.77.77.77 - - [20/Jun/2023:10:33:01 +0200] "GET /.well-known/acme-challenge/CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU HTTP/1.1" 302 280 "boulder-remote-b" - - - 0 198 561 759 "-" #18267
10.77.77.77 - - [20/Jun/2023:10:33:02 +0200] "GET /.well-known/acme-challenge/CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU HTTP/1.1" 302 280 "boulder-remote-a" - - - 0 198 561 759 "-" #18267
10.77.77.77 - - [20/Jun/2023:10:33:02 +0200] "GET /.well-known/acme-challenge/CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU HTTP/1.1" 200 88 "boulder" - - - 0 646 1824 2470 "-" #18267
10.77.77.77 - - [20/Jun/2023:10:33:02 +0200] "GET /.well-known/acme-challenge/CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU HTTP/1.1" 200 88 "boulder-remote-a" - - - 0 655 1824 2479 "-" #18267
10.77.77.77 - - [20/Jun/2023:10:33:02 +0200] "GET /.well-known/acme-challenge/CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU HTTP/1.1" 200 88 "boulder-remote-b" - - - 0 655 1824 2479 "-" #18267

boulder_1    | 08:33:01.983466 6 boulder-va -9q1lwk [AUDIT] Attempting to validate HTTP-01 for "acme-test.foo.com" with GET to "http://acme-test.foo.com/.well-known/acme-challenge/CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU"
boulder_1    | 08:33:01.986200 6 boulder-va yqjqlQY [AUDIT] Checked CAA records for acme-test.foo.com, [Present: false, Account ID: 42, Challenge: http-01, Valid for issuance: true, Found at: ""] Response=""
boulder_1    | 08:33:02.034375 6 boulder-va obaagQ0 [AUDIT] Validation result JSON={"ID":"98","Requester":42,"Hostname":"acme-test.foo.com","Challenge":{"type":"http-01","status":"valid","token":"CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU","keyAuthorization":"CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU.c-UOxaD8p05O8EBCPY6olkUPjV9F_3O1zUt3Umrz8iM","validationRecord":[{"url":"http://acme-test.foo.com/.well-known/acme-challenge/CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU","hostname":"acme-test.foo.com","port":"80","addressesResolved":["10.0.8.5"],"addressUsed":"10.0.8.5"},{"url":"https://acme-test.foo.com/.well-known/acme-challenge/CADrbVbBodq7dLBsOvEuuHEljy4IsC-kYgdqhAz_eVU","hostname":"acme-test.foo.com","port":"443","addressesResolved":["10.0.8.5"],"addressUsed":"10.0.8.5"}]},"ValidationLatency":0.055}
boulder_1    | 08:33:03.434843 6 boulder-ra 5v-75QM FinalizationCaaCheck JSON={"Requester":42,"Reused":1}
boulder_1    | 08:33:03.579647 6 boulder-ra -fi7zAg [AUDIT] Certificate request - successful JSON={"ID":"zwgOt4j_kOd8KkGuj12y9Z2FiDylfgDhGgqi1ezYrWs","Requester":42,"OrderID":98,"SerialNumber":"ff5c0f16f765e7e007d12d0a8770da41e103","VerifiedFields":["subject.commonName","subjectAltName"],"CommonName":"acme-test.foo.com","Names":["acme-test.foo.com"],"NotBefore":"2023-06-20T07:33:03Z","NotAfter":"2023-09-18T07:33:02Z","RequestTime":"2023-06-20T08:33:03.422482384Z","ResponseTime":"2023-06-20T08:33:03.579009296Z","Authorizations":{"acme-test.foo.com":{"ID":"98","ChallengeType":"http-01"}}}

Now I wonder if this is a special behavior due to the usage of boulder or if there is a general problem in ssl_engine_init.c with fallback certificates?

[daum3ns]

i think the problem is this condition....

 /* Allow others to provide certificate files */
    pks = sc->server->pks;
    n = pks->cert_files->nelts;
    ap_ssl_add_cert_files(s, p, pks->cert_files, pks->key_files);
    ssl_run_add_cert_files(s, p, pks->cert_files, pks->key_files);

    if (apr_is_empty_array(pks->cert_files)) {
        /* does someone propose a certiciate to fall back on here? */
        ap_ssl_add_fallback_cert_files(s, p, pks->cert_files, pks->key_files);
        ssl_run_add_fallback_cert_files(s, p, pks->cert_files, pks->key_files);
        if (n < pks->cert_files->nelts) {
            pks->service_unavailable = 1;
            ap_log_error(APLOG_MARK, APLOG_WARNING, 0, s, APLOGNO(10085)
                         "Init: %s will respond with '503 Service Unavailable' for now. There "
                         "are no SSL certificates configured and no other module contributed any.",
                         ssl_util_vhostid(p, s));
        }
    }

if the condition if (apr_is_empty_array(pks->cert_files)) { is true, that means that n is 0.. (it was set to pks->cert_files->nelts before the if)

now if another module provides a cert and key the var n is still 0, and this condition will always be true because n is not recalculated..

my feeling is that instead of checking if (n < pks->cert_files->nelts) { we should check for apr_is_empty_array(pks->cert_files) again..

[icing]

"But the challenge request (after redirection to 443) gets responded with 503 Service Unavailable..."

There is the problem. If you redirect all plain http: requests to https:, ACME will not work. You need to let the /.well-known/acme-challenge through, so an answer can be sent back to boulder.

One way to achieve that is via the directive MDRequireHttps. But adjusting your Rewrite will of course also work.

[daum3ns]

what do you think of my proposal here?

because i have patched and tested it and the issue is gone then...