search

icing / mod_md

Let's Encrypt (ACME) in Apache httpd
https://icing.github.io/mod_md/
Apache License 2.0
334 stars 28 forks source link

503 with fallback certificate on http-01 challenge verification request #315

Open arminabf opened 1 year ago

arminabf commented 1 year ago

Hello,

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

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_certfiles 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 commented 1 year ago

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->certfiles->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 commented 1 year ago

"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 commented 1 year ago

what do you think of my proposal here?

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