From 7b8633dadf81e91ab62a685d4aa7f03f8e0fea8d Mon Sep 17 00:00:00 2001 From: Arturo Bernal Date: Sat, 14 Nov 2026 14:45:01 +0100 Subject: [PATCH] mod_md: Log the specific reason an ACME request failed, not just "(specific information not available)". md_curl_perform() logged the actual curl_easy_strerror() for a failed request -- e.g. "Problem with the SSL CA cert (path? access rights?)" for a bad or missing MDCACertificateFile -- only at MD_LOG_DEBUG. Every higher-level caller only has the apr_status_t this maps to, which for any curl error without its own case in curl_status() is the generic APR_EGENERAL, rendered as "(specific information not available)" in the AH10056 error an administrator actually sees. The one specific, actionable detail of what went wrong was only visible with md:trace4. Raise this to MD_LOG_ERR specifically for curl error codes that indicate a problem with the TLS trust configuration itself (bad CA bundle, certificate, cipher, engine) rather than a transient network condition, since these will not be fixed by mod_md's usual retry. Other failures (DNS, connection refused, timeout, ...) keep logging at debug, as those are already expected to retry and their apr_status_t mapping (APR_ECONNREFUSED, APR_TIMEUP, ...) is already descriptive. Reproduced against a real server: pointed MDCACertificateFile at a nonexistent file and MDCertificateAuthority at a local HTTPS listener. Before the fix, "LogLevel md:warn" showed only the generic AH10056 "(specific information not available)" line. After, it also shows "request failed(77): Problem with the SSL CA cert (path? access rights?)" at md:error. PR 70300 (cherry picked from commit 45e499d3cc19d539a73958c3e408aa9e5f5a3aca) --- changes-entries/70300.txt | 5 + modules/md/md_curl.c | 34 +++++- test/modules/md/test_320_ca_cert_log_level.py | 110 ++++++++++++++++++ 3 files changed, 147 insertions(+), 2 deletions(-) create mode 100644 changes-entries/70300.txt create mode 100644 test/modules/md/test_320_ca_cert_log_level.py diff --git a/changes-entries/70300.txt b/changes-entries/70300.txt new file mode 100644 index 00000000000..36dce6c1c60 --- /dev/null +++ b/changes-entries/70300.txt @@ -0,0 +1,5 @@ + *) mod_md: Log the specific reason an ACME server request failed (e.g. + a bad or missing CA bundle file) at error level, instead of only at + debug level with just a generic "Internal error (specific + information not available)" visible otherwise. PR 70300 + [Arturo Bernal] diff --git a/modules/md/md_curl.c b/modules/md/md_curl.c index ee1c3cabd23..7a5d62205e9 100644 --- a/modules/md/md_curl.c +++ b/modules/md/md_curl.c @@ -53,6 +53,36 @@ static apr_status_t curl_status(unsigned int curl_code) } } +/* Whether curl_code denotes a problem with the TLS trust configuration + * itself (bad/missing CA bundle, cert, cipher, engine, ...) rather than a + * transient network condition. These are not going to be fixed by a later + * retry, so they are worth a log line an administrator will actually see + * without turning on md:trace4. + * + * CURLE_SSL_CONNECT_ERROR is deliberately excluded: libcurl uses it as a + * generic "something went wrong in the TLS handshake" catch-all (protocol + * mismatches, resets, timeouts, ...), not a reliable signal that the + * problem is our certificate configuration specifically. Elevating it + * here would mislabel transient failures as permanent and risk log + * flooding on retry. */ +static int curl_is_cert_error(CURLcode curl_code) +{ + switch (curl_code) { + case CURLE_SSL_ENGINE_NOTFOUND: + case CURLE_SSL_ENGINE_SETFAILED: + case CURLE_SSL_CERTPROBLEM: + case CURLE_SSL_CIPHER: + case CURLE_PEER_FAILED_VERIFICATION: + case CURLE_SSL_ENGINE_INITFAILED: + case CURLE_SSL_CACERT_BADFILE: + case CURLE_SSL_CRL_BADFILE: + case CURLE_SSL_ISSUER_ERROR: + return 1; + default: + return 0; + } +} + typedef struct { CURL *curl; CURLM *curlm; @@ -427,8 +457,8 @@ static apr_status_t md_curl_perform(md_http_request_t *req) rv = curl_status(curle); if (APR_SUCCESS != rv) { - md_log_perror(MD_LOG_MARK, MD_LOG_DEBUG, rv, req->pool, - "request failed(%d): %s", curle, curl_easy_strerror(curle)); + md_log_perror(MD_LOG_MARK, curl_is_cert_error(curle) ? MD_LOG_ERR : MD_LOG_DEBUG, + rv, req->pool, "request failed(%d): %s", curle, curl_easy_strerror(curle)); goto leave; } diff --git a/test/modules/md/test_320_ca_cert_log_level.py b/test/modules/md/test_320_ca_cert_log_level.py new file mode 100644 index 00000000000..bd5c839f142 --- /dev/null +++ b/test/modules/md/test_320_ca_cert_log_level.py @@ -0,0 +1,110 @@ +"""mod_md's curl-based HTTP client only logged the specific reason a request +to the ACME server failed (e.g. "Problem with the SSL CA cert (path? access +rights?)") at debug level. At a normal production LogLevel this reason was +invisible, and the error an administrator actually saw was the generic +"Internal error (specific information not available)" wrapper (BZ 70300). + +This does not need a real ACME server: a bad MDCACertificateFile fails +before any ACME-specific request is made, against any HTTPS endpoint. +""" +import datetime +import os +import re +import ssl +import threading +from http.server import BaseHTTPRequestHandler, HTTPServer + +import pytest +from cryptography import x509 +from cryptography.hazmat.primitives import hashes, serialization +from cryptography.hazmat.primitives.asymmetric import rsa + +from .md_conf import MDConf +from .md_env import MDTestEnv + + +def _make_self_signed_cert(cert_path, pkey_path): + key = rsa.generate_private_key(public_exponent=65537, key_size=2048) + name = x509.Name([x509.NameAttribute(x509.NameOID.COMMON_NAME, "127.0.0.1")]) + now = datetime.datetime.now(datetime.timezone.utc) + cert = ( + x509.CertificateBuilder() + .subject_name(name) + .issuer_name(name) + .public_key(key.public_key()) + .serial_number(x509.random_serial_number()) + .not_valid_before(now - datetime.timedelta(minutes=5)) + .not_valid_after(now + datetime.timedelta(days=1)) + .sign(key, hashes.SHA256()) + ) + with open(cert_path, "wb") as f: + f.write(cert.public_bytes(serialization.Encoding.PEM)) + with open(pkey_path, "wb") as f: + f.write(key.private_bytes( + encoding=serialization.Encoding.PEM, + format=serialization.PrivateFormat.PKCS8, + encryption_algorithm=serialization.NoEncryption())) + + +class _DirectoryHandler(BaseHTTPRequestHandler): + def do_GET(self): + body = b'{}' + self.send_response(200) + self.send_header("Content-Type", "application/json") + self.send_header("Content-Length", str(len(body))) + self.end_headers() + self.wfile.write(body) + + def log_message(self, *args): + pass + + +class TestCACertLogLevel: + + @pytest.fixture(scope='class') + def fake_acme_port(self, env): + cert_file = os.path.join(env.gen_dir, "md-320-fake-acme.crt") + pkey_file = os.path.join(env.gen_dir, "md-320-fake-acme.key") + _make_self_signed_cert(cert_file, pkey_file) + + server = HTTPServer(("127.0.0.1", 0), _DirectoryHandler) + ctx = ssl.SSLContext(ssl.PROTOCOL_TLS_SERVER) + ctx.load_cert_chain(certfile=cert_file, keyfile=pkey_file) + server.socket = ctx.wrap_socket(server.socket, server_side=True) + port = server.server_address[1] + t = threading.Thread(target=server.serve_forever, daemon=True) + t.start() + yield port + server.shutdown() + + def test_md_320_01_ca_cert_error_visible_at_warn_level(self, env, request, fake_acme_port): + """A bad MDCACertificateFile must be reported at a level visible + with a normal LogLevel, not only with md:debug/trace4.""" + domain = env.get_request_domain(request) + bad_ca_file = os.path.join(env.gen_dir, "md-320-does-not-exist-ca-bundle.crt") + assert not os.path.exists(bad_ca_file) + + conf = MDConf(env, local_ca=False) + conf.add([ + "LogLevel md:warn", + f"MDCACertificateFile {bad_ca_file}", + f"MDCertificateAuthority https://127.0.0.1:{fake_acme_port}/directory", + "MDCertificateAgreement accepted", + f"MDomain {domain}", + ]) + conf.add_vhost(domains=[domain], port=env.https_port, with_ssl=True) + conf.install() + assert env.apache_restart() == 0 + + start = env.httpd_error_log.current_pos() + line = env.httpd_error_log.wait_for( + re.compile(r'.*\[md:error\].*Problem with the SSL CA cert.*'), + start, timeout=15) + assert line, ( + "expected the specific curl CA-cert error to be logged at " + "md:error, not only at md:debug/trace4") + env.httpd_error_log.ignore_recent(matches=[ + r'.*Problem with the SSL CA cert.*', + r'.*Unsuccessful in contacting ACME server.*', + r'.*AH10056.*', + ])