diff --git a/changes-entries/proxy-hcheck-fixes.txt b/changes-entries/proxy-hcheck-fixes.txt new file mode 100644 index 0000000000..0c46938b3f --- /dev/null +++ b/changes-entries/proxy-hcheck-fixes.txt @@ -0,0 +1,12 @@ + *) mod_proxy_hcheck: Fix several health check problems. A response whose + headers end at EOF is now a failure. A changed hcuri (balancer-manager) + is used by the next check, and hcuri and the worker path are joined with + a single slash. https checks send the SNI and verify the certificate name + like proxied requests. A check is bound by the worker timeout overall, + accepts at most 100 response header fields, and keeps a response body (up + to 1MB) only for a worker that has an hcexpr. hcpasses, hcfails and + ProxyHCTPsize reject values that are not whole numbers. The cache of + check workers no longer uses the address of a local variable as a key, the + worker list is read under the balancer lock, and a check that cannot be + queued no longer stops further checks of its worker. + [Jim Jagielski] diff --git a/docs/log-message-tags/next-number b/docs/log-message-tags/next-number index 9b20153c15..16a7e7453c 100644 --- a/docs/log-message-tags/next-number +++ b/docs/log-message-tags/next-number @@ -1 +1 @@ -10639 +10644 diff --git a/docs/manual/mod/mod_proxy_hcheck.xml b/docs/manual/mod/mod_proxy_hcheck.xml index 69d72d85ab..e29b0b708e 100644 --- a/docs/manual/mod/mod_proxy_hcheck.xml +++ b/docs/manual/mod/mod_proxy_hcheck.xml @@ -76,17 +76,22 @@ hcpasses 1 - Number of successful health check tests before worker is re-enabled + Number of successful health check tests before worker is re-enabled + (a whole number, 0 or more) hcfails 1 - Number of failed health check tests before worker is disabled + Number of failed health check tests before worker is disabled + (a whole number, 0 or more) hcinterval 30 Period of health checks in seconds (e.g. performed every 30 seconds). Uses the time-interval directive syntax. hcuri   - Additional URI to be appended to the worker URL for the health check. + Additional URI to be appended to the worker URL for the health check. + It is joined to the path of the worker URL, if any, with a single slash, + so ping and /ping are the same. A change made + in the balancer-manager is used by the next check. hctemplate   Name of template, created via ProxyHCTemplate, @@ -99,6 +104,19 @@ +What a health check accepts +

The backend is not trusted to behave. A check fails if the response is not + complete (its headers must end with the blank line, not at the end of the + connection), has more than 100 header fields or a header line that is too + long, or if the whole exchange takes longer than the worker's + timeout (the server's Timeout + if the worker has none); a backend that keeps sending cannot hold a check + open. For https workers the check sends the server name (SNI) + and verifies the certificate name just as a proxied request to the same + worker does, according to the mod_ssl + SSLProxy* directives.

+ + Compatibility:

OPTIONS11, HEAD11 and GET11 are available in 2.4.55 and above.

@@ -178,7 +196,10 @@ ProxyPass "/apps" "balancer://foo"

If using a health check method (eg: GET) which results in a response body, that body itself can be checked via ap_expr using the hc() - expression function, which is unique to this module.

+ expression function, which is unique to this module. The body is only read into + memory for a worker that has an hcexpr, and then at most 1MB of it: a + larger body fails the check. Without an hcexpr the body is read and + discarded.

In the following example, we send the backend a GET request and if the response body contains the phrase Under maintenance, diff --git a/modules/proxy/mod_proxy_hcheck.c b/modules/proxy/mod_proxy_hcheck.c index 2fe1152fe1..290bc60ef3 100644 --- a/modules/proxy/mod_proxy_hcheck.c +++ b/modules/proxy/mod_proxy_hcheck.c @@ -13,6 +13,8 @@ * See the License for the specific language governing permissions and * limitations under the License. */ +#include +#include #include "mod_proxy.h" #include "mod_watchdog.h" #include "ap_slotmem.h" @@ -36,6 +38,14 @@ module AP_MODULE_DECLARE_DATA proxy_hcheck_module; #define HC_USE_THREADS 0 #endif +/* + * What a health check will take from a backend. The backend is not trusted to + * be well behaved (it may be broken, or compromised), and a check runs in a + * long-lived thread and pool of the watchdog child. + */ +#define HC_MAX_HEADER_FIELDS 100 /* response header fields */ +#define HC_MAX_BODY (1024 * 1024) /* body kept for a condition */ + typedef struct { char *name; hcmethod_t method; @@ -91,6 +101,21 @@ static void *hc_create_config(apr_pool_t *p, server_rec *s) return ctx; } +/* A whole number >= 0 and < INT_MAX; atoi() would take "abc" as 0. */ +static int hc_parse_count(const char *val, int *out) +{ + char *end; + apr_int64_t v; + + errno = 0; + v = apr_strtoi64(val, &end, 10); + if (errno || end == val || *end || v < 0 || v >= INT_MAX) { + return 0; + } + *out = (int)v; + return 1; +} + static ap_watchdog_t *watchdog; #if HC_USE_THREADS static apr_thread_pool_t *hctp; @@ -180,9 +205,8 @@ static const char *set_worker_hc_param(apr_pool_t *p, } } else if (!strcasecmp(key, "hcpasses")) { - ival = atoi(val); - if (ival < 0) - return "Passes must be a positive value"; + if (!hc_parse_count(val, &ival)) + return "Passes must be a whole number, 0 or more"; if (worker) { worker->s->passes = ival; } else { @@ -190,9 +214,8 @@ static const char *set_worker_hc_param(apr_pool_t *p, } } else if (!strcasecmp(key, "hcfails")) { - ival = atoi(val); - if (ival < 0) - return "Fails must be a positive value"; + if (!hc_parse_count(val, &ival)) + return "Fails must be a whole number, 0 or more"; if (worker) { worker->s->fails = ival; } else { @@ -328,10 +351,9 @@ static const char *set_hc_tpsize (cmd_parms *cmd, void *dummy, const char *arg) if (err) return err; - tpsize = atoi(arg); - if (tpsize < 0) + if (!hc_parse_count(arg, &tpsize)) return "Invalid ProxyHCTPsize parameter. Parameter must be " - ">= 0"; + "a whole number >= 0"; return NULL; } #endif @@ -459,16 +481,33 @@ static void create_hcheck_req(wctx_t *wctx, proxy_worker *hc, if (!method) { /* did we fall thru? If not, we are GET */ method = "GET"; } - req = apr_psprintf(p, - "%s %s%s%s %s\r\n" - "Host: %s:%d\r\n" - "\r\n", - method, - (wctx->path ? wctx->path : ""), - (wctx->path && *hc->s->hcuri ? "/" : "" ), - (*hc->s->hcuri ? hc->s->hcuri : ""), - protocol, - hc->s->hostname_ex, (int)hc->s->port); + { + /* The request target is the worker's path and hcuri, joined by + * exactly one slash, and always starts with one. */ + const char *path = wctx->path ? wctx->path : ""; + const char *uri = hc->s->hcuri; + apr_size_t plen = strlen(path); + const char *target; + + while (plen && path[plen - 1] == '/') { + plen--; + } + while (*uri == '/') { + uri++; + } + if (*uri) { + target = apr_psprintf(p, "%.*s/%s", (int)plen, path, uri); + } + else { + target = plen ? apr_pstrmemdup(p, path, plen) : "/"; + } + req = apr_psprintf(p, + "%s %s %s\r\n" + "Host: %s:%d\r\n" + "\r\n", + method, target, protocol, + hc->s->hostname_ex, (int)hc->s->port); + } break; default: @@ -491,6 +530,7 @@ static proxy_worker *hc_get_hcworker(sctx_t *ctx, proxy_worker *worker, apr_status_t rv; const char *url = worker->s->name; wctx_t *wctx = apr_pcalloc(ctx->p, sizeof(wctx_t)); + proxy_worker **key; port = (worker->s->port ? worker->s->port : ap_proxy_port_of_scheme(worker->s->scheme)); @@ -530,11 +570,16 @@ static proxy_worker *hc_get_hcworker(sctx_t *ctx, proxy_worker *worker, wctx->w = worker; create_hcheck_req(wctx, hc, ctx->p); hc->context = wctx; - apr_hash_set(ctx->hcworkers, &worker, sizeof worker, hc); + /* apr_hash_set() keeps the key pointer as is, not a copy of the key, + * so it must outlive the hash: not the address of our argument. */ + key = apr_palloc(ctx->p, sizeof *key); + *key = worker; + apr_hash_set(ctx->hcworkers, key, sizeof *key, hc); } - /* This *could* have changed via the Balancer Manager */ - /* TODO */ - if (hc->s->method != worker->s->method) { + /* The method and the URI could have been changed via the Balancer Manager; + * the request is pre-formatted from both, so rebuild it when either did. */ + if (hc->s->method != worker->s->method + || strcmp(hc->s->hcuri, worker->s->hcuri)) { wctx_t *wctx = hc->context; port = (worker->s->port ? worker->s->port : ap_proxy_port_of_scheme(worker->s->scheme)); @@ -543,6 +588,7 @@ static proxy_worker *hc_get_hcworker(sctx_t *ctx, proxy_worker *worker, worker, worker->s->scheme, worker->s->hostname_ex, (int)port); hc->s->method = worker->s->method; + PROXY_STRNCPY(hc->s->hcuri, worker->s->hcuri); create_hcheck_req(wctx, hc, ctx->p); } return hc; @@ -608,6 +654,18 @@ static int hc_get_backend(const char *proxy_function, proxy_conn_rec **backend, return !OK; } (*backend)->is_ssl = 1; + /* + * Name the host as a proxied request to this worker would (see + * ap_proxy_determine_connection()): ap_proxy_connection_create_ex() + * passes it on to mod_ssl, which then sends it as the SNI and checks + * the certificate against it. Without it the probe would neither + * pick the right virtual host on the backend nor notice a + * certificate for another name. + */ + if (!(*backend)->ssl_hostname) { + (*backend)->ssl_hostname = apr_pstrdup((*backend)->scpool, + hc->s->hostname_ex); + } } return hc_determine_connection(proxy_function, *backend, ctx->s); @@ -724,12 +782,36 @@ static int hc_send(request_rec *r, const char *out, apr_bucket_brigade *bb) return (rv) ? !OK : OK; } -static int hc_read_headers(request_rec *r) +/* + * Make the next read fit in the time left of the check's overall deadline: a + * per-read socket timeout alone never ends a backend that keeps sending. + * Returns 0 if there is no time left. + */ +static int hc_time_left(apr_socket_t *sock, apr_time_t deadline) +{ + apr_interval_time_t left = deadline - apr_time_now(); + apr_interval_time_t cur; + + if (left <= 0) { + return 0; + } + if (apr_socket_timeout_get(sock, &cur) != APR_SUCCESS || cur < 0 + || left < cur) { + apr_socket_timeout_set(sock, left); + } + return 1; +} + +static int hc_read_headers(request_rec *r, apr_socket_t *sock, + apr_time_t deadline) { char buffer[HUGE_STRING_LEN]; - int len; + int len, fields = 0; const char *ct; + if (!hc_time_left(sock, deadline)) { + return !OK; + } len = ap_getline(buffer, sizeof(buffer), r, 1); if (len <= 0) { return !OK; @@ -765,8 +847,16 @@ static int hc_read_headers(request_rec *r) } /* OK, 1st line is OK... scarf in the headers */ - while ((len = ap_getline(buffer, sizeof(buffer), r, 1)) > 0) { + while (hc_time_left(sock, deadline) + && (len = ap_getline(buffer, sizeof(buffer), r, 1)) > 0) { char *value; + + if (++fields > HC_MAX_HEADER_FIELDS || len >= sizeof(buffer) - 1) { + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, r->server, APLOGNO(10639) + "Health check response has too many header fields " + "or a header line that is too long"); + return !OK; + } ap_log_error(APLOG_MARK, APLOG_TRACE7, 0, r->server, "%.*s", len, buffer); if (!(value = strchr(buffer, ':'))) { @@ -779,6 +869,12 @@ static int hc_read_headers(request_rec *r) ap_cstr_stripws(value); apr_table_add(r->headers_out, buffer, value); } + if (len != 0) { + /* EOF, an error, or out of time before the blank line that ends the + * headers: the response is truncated, not a (healthy) one without + * more headers. */ + return !OK; + } /* Set the Content-Type for the request if set */ if ((ct = apr_table_get(r->headers_out, "Content-Type")) != NULL) @@ -787,14 +883,26 @@ static int hc_read_headers(request_rec *r) return OK; } -static int hc_read_body(request_rec *r, apr_bucket_brigade *bb) +/* + * Read the response body to its end. It is kept (in r->kept_body, for the + * expression to look at) only if retain is set, and then only up to + * HC_MAX_BODY; otherwise it is read and dropped. + */ +static int hc_read_body(request_rec *r, apr_bucket_brigade *bb, + apr_socket_t *sock, apr_time_t deadline, int retain) { apr_status_t rv = APR_SUCCESS; int seen_eos = 0; + apr_off_t kept = 0; do { apr_size_t len = HUGE_STRING_LEN; + if (!hc_time_left(sock, deadline)) { + ap_log_error(APLOG_MARK, APLOG_DEBUG, 0, r->server, APLOGNO(10640) + "Health check response body not complete in time"); + return !OK; + } apr_brigade_cleanup(bb); rv = ap_get_brigade(r->proto_input_filters, bb, AP_MODE_READBYTES, APR_BLOCK_READ, len); @@ -819,6 +927,19 @@ static int hc_read_body(request_rec *r, apr_bucket_brigade *bb) apr_bucket_delete(bucket); continue; } + if (!retain) { + apr_bucket_delete(bucket); + continue; + } + kept += (bucket->length != (apr_size_t)-1) ? bucket->length : 0; + if (kept > HC_MAX_BODY) { + ap_log_error(APLOG_MARK, APLOG_INFO, 0, r->server, APLOGNO(10641) + "Health check response body is larger than %d " + "bytes, too much to evaluate a condition on", + HC_MAX_BODY); + apr_brigade_cleanup(bb); + return !OK; + } APR_BUCKET_REMOVE(bucket); APR_BRIGADE_INSERT_TAIL(r->kept_body, bucket); } @@ -846,6 +967,7 @@ static apr_status_t hc_check_http(baton_t *baton, apr_thread_t *thread) wctx_t *wctx; hc_condition_t *cond; apr_bucket_brigade *bb; + apr_time_t deadline; wctx = (wctx_t *)hc->context; if (!wctx->req || !wctx->method) { @@ -868,17 +990,22 @@ static apr_status_t hc_check_http(baton_t *baton, apr_thread_t *thread) bb = apr_brigade_create(r->pool, r->connection->bucket_alloc); + /* The whole exchange gets the time a single read is allowed. */ + deadline = apr_time_now() + (hc->s->timeout_set ? hc->s->timeout + : ctx->s->timeout); + if ((status = hc_send(r, wctx->req, bb)) != OK) { return backend_cleanup("HCOH", backend, ctx->s, status); } - if ((status = hc_read_headers(r)) != OK) { + if ((status = hc_read_headers(r, backend->sock, deadline)) != OK) { return backend_cleanup("HCOH", backend, ctx->s, status); } if (!r->header_only) { apr_table_t *saved_headers_in = r->headers_in; r->headers_in = apr_table_copy(r->pool, r->headers_out); ap_proxy_pre_http_request(backend->connection, r); - status = hc_read_body(r, bb); + status = hc_read_body(r, bb, backend->sock, deadline, + *worker->s->hcexpr != '\0'); r->headers_in = saved_headers_in; if (status != OK) { return backend_cleanup("HCOH", backend, ctx->s, status); @@ -1006,6 +1133,7 @@ static apr_status_t hc_watchdog_callback(int state, void *data, now = apr_time_now(); balancer = (proxy_balancer *)conf->balancers->elts; for (i = 0; i < conf->balancers->nelts; i++, balancer++) { + PROXY_THREAD_LOCK(balancer); workers = (proxy_worker **)balancer->workers->elts; for (n = 0; n < balancer->workers->nelts; n++, workers++) { worker = *workers; @@ -1013,6 +1141,7 @@ static apr_status_t hc_watchdog_callback(int state, void *data, worker->s->updated = now; } } + PROXY_THREAD_UNLOCK(balancer); } #if HC_USE_THREADS if (tpsize && hctp == NULL) { @@ -1042,12 +1171,22 @@ static apr_status_t hc_watchdog_callback(int state, void *data, { balancer = (proxy_balancer *)conf->balancers->elts; for (i = 0; i < conf->balancers->nelts; i++, balancer++) { - /* Have any new balancers or workers been added dynamically? */ + apr_array_header_t *members; + + /* Have any new balancers or workers been added dynamically? + * Request threads add them too (under this lock), growing + * the array and possibly moving it, so look at the list + * only with the lock held and work from a copy of it; a + * check can take long and must not hold the lock. + */ + PROXY_THREAD_LOCK(balancer); ap_proxy_sync_balancer(balancer, s, conf); + members = apr_array_copy(pool, balancer->workers); + PROXY_THREAD_UNLOCK(balancer); now = apr_time_now(); - workers = (proxy_worker **)balancer->workers->elts; - for (n = 0; n < balancer->workers->nelts; n++, workers++) { + workers = (proxy_worker **)members->elts; + for (n = 0; n < members->nelts; n++, workers++) { worker = *workers; if (!PROXY_WORKER_IS(worker, PROXY_WORKER_STOPPED) && (worker->s->method != NONE) && @@ -1084,9 +1223,34 @@ static apr_status_t hc_watchdog_callback(int state, void *data, #if HC_USE_THREADS if (hctp) { - apr_thread_pool_push(hctp, hc_check, (void *)baton, - APR_THREAD_TASK_PRIORITY_NORMAL, - NULL); + apr_status_t prv; + + prv = apr_thread_pool_push(hctp, hc_check, + (void *)baton, + APR_THREAD_TASK_PRIORITY_NORMAL, + NULL); + if (prv == APR_NOTFOUND || prv == APR_ENOMEM) { + /* The task was not queued: nothing will + * run this check or release its pool, and + * worker->s->updated would stay 0, which + * stops all further checks of the worker. + */ + ap_log_error(APLOG_MARK, APLOG_ERR, prv, s, + APLOGNO(10642) "Cannot queue " + "health check of %s", + worker->s->name); + worker->s->updated = now; + apr_pool_destroy(ptemp); + } + else if (prv != APR_SUCCESS) { + /* Queued, but no thread could be created + * for it (yet): it runs when one is, and + * must not be freed here. */ + ap_log_error(APLOG_MARK, APLOG_WARNING, prv, s, + APLOGNO(10643) "Cannot start a " + "thread for the health check " + "of %s", worker->s->name); + } } else #endif diff --git a/test/pytest_suite/t/conf/proxy_hcheck.conf.in b/test/pytest_suite/t/conf/proxy_hcheck.conf.in new file mode 100644 index 0000000000..090ca46e8b --- /dev/null +++ b/test/pytest_suite/t/conf/proxy_hcheck.conf.in @@ -0,0 +1,91 @@ +#t/TEST -proxy_hcheck +# +# Health-checked balancers for t/modules/test_proxy_hcheck.py. The backends are +# not httpd: the tests start small socket servers on the ports allocated here, +# so that they control exactly what each health check sees. hcinterval=1 with +# one pass / one fail makes a worker change state within a couple of seconds. + + + + + + Define HC_URI_PORT @NextAvailablePort@ + Define HC_HDR_PORT @NextAvailablePort@ + Define HC_MANYHDR_PORT @NextAvailablePort@ + Define HC_SLOW_PORT @NextAvailablePort@ + Define HC_BIGEXPR_PORT @NextAvailablePort@ + Define HC_BIGPLAIN_PORT @NextAvailablePort@ + Define HC_PATHA_PORT @NextAvailablePort@ + Define HC_PATHB_PORT @NextAvailablePort@ + Define HC_PATHC_PORT @NextAvailablePort@ + Define HC_TLSBAD_PORT @NextAvailablePort@ + Define HC_TLSGOOD_PORT @NextAvailablePort@ + + + LogLevel proxy_hcheck:debug + + # The probe path is changed at run time through the balancer-manager. + + BalancerMember http://127.0.0.1:${HC_URI_PORT} hcmethod=GET hcuri=/old hcinterval=1 hcpasses=1 hcfails=1 + + ProxyPass /hcuri balancer://hcuri + + # A HEAD probe against a backend that sends a truncated response. + + BalancerMember http://127.0.0.1:${HC_HDR_PORT} hcmethod=HEAD hcuri=/ hcinterval=1 hcpasses=1 hcfails=1 + + ProxyPass /hchdr balancer://hchdr + + # HTTPS probes. Certificates are not chain-verified (SSLProxyVerify none) + # so that only the host name check is in play: the "bad" backend presents a + # certificate for another name, the "good" one for localhost. + + SSLProxyEngine on + SSLProxyVerify none + SSLProxyCheckPeerName on + + BalancerMember https://localhost:${HC_TLSBAD_PORT} hcmethod=GET hcuri=/ hcinterval=1 hcpasses=1 hcfails=1 + + ProxyPass /hctlsbad balancer://hctlsbad + + BalancerMember https://localhost:${HC_TLSGOOD_PORT} hcmethod=GET hcuri=/ hcinterval=1 hcpasses=1 hcfails=1 + + ProxyPass /hctlsgood balancer://hctlsgood + + + # How the probe path is put together from the worker URL and hcuri. + + BalancerMember http://127.0.0.1:${HC_PATHA_PORT} hcmethod=GET hcuri=ping hcinterval=1 hcpasses=1 hcfails=1 + + + BalancerMember http://127.0.0.1:${HC_PATHB_PORT}/app hcmethod=GET hcuri=/ping hcinterval=1 hcpasses=1 hcfails=1 + + + BalancerMember http://127.0.0.1:${HC_PATHC_PORT}/app/ hcmethod=GET hcuri=ping hcinterval=1 hcpasses=1 hcfails=1 + + + # Limits on what a probe will take from a backend. + ProxyHCExpr nomaint {hc('body') !~ /UNDER-MAINTENANCE/} + + BalancerMember http://127.0.0.1:${HC_MANYHDR_PORT} hcmethod=GET hcuri=/ hcinterval=1 hcpasses=1 hcfails=1 + + # timeout=2: also the overall budget of one probe + + BalancerMember http://127.0.0.1:${HC_SLOW_PORT} hcmethod=GET hcuri=/ hcinterval=1 hcpasses=1 hcfails=1 timeout=2 + + + BalancerMember http://127.0.0.1:${HC_BIGEXPR_PORT} hcmethod=GET hcuri=/ hcinterval=1 hcpasses=1 hcfails=1 hcexpr=nomaint + + + BalancerMember http://127.0.0.1:${HC_BIGPLAIN_PORT} hcmethod=GET hcuri=/ hcinterval=1 hcpasses=1 hcfails=1 + + + + SetHandler balancer-manager + Require all granted + + + + + + diff --git a/test/pytest_suite/tests/t/modules/test_proxy_hcheck.py b/test/pytest_suite/tests/t/modules/test_proxy_hcheck.py new file mode 100644 index 0000000000..2482368ef6 --- /dev/null +++ b/test/pytest_suite/tests/t/modules/test_proxy_hcheck.py @@ -0,0 +1,407 @@ +r"""Tests for mod_proxy_hcheck. + +The backends are plain socket servers started here (not httpd), so each test +controls exactly what the health check sees. Worker state is read from the +balancer-manager of the t/conf/proxy_hcheck.conf.in vhost: "Ok" while the +worker is healthy, "HcFl" once a health check has failed it. +""" + +import re +import shutil +import socketserver +import ssl +import subprocess +import tempfile +import threading +import time +from pathlib import Path + +import pytest + +from apache_pytest import need_module + +need = need_module("proxy_hcheck", "proxy_balancer", "proxy_http", "watchdog") + + +def conf_port(http, name): + conf = Path(http.vars("t_logs")).parent / "conf" / "proxy_hcheck.conf" + m = re.search(rf"Define HC_{name}_PORT (\d+)", conf.read_text()) + assert m, f"HC_{name}_PORT not found in {conf}" + return int(m.group(1)) + + +class Backend: + """A TCP server that records each request head and answers via respond().""" + + def __init__(self, port, respond, tls=None): + self.requests = [] # [(method, target, {lower-case header: value})] + self.sni = [] # server names seen in TLS ClientHellos (None = none) + self.respond = respond # (backend, request) -> bytes or an iterable of them + self.stopping = False + self.tls = None + if tls: + self.tls = ssl.SSLContext(ssl.PROTOCOL_TLS_SERVER) + self.tls.load_cert_chain(*tls) + self.tls.sni_callback = lambda sock, name, ctx: self.sni.append(name) + outer = self + + class Handler(socketserver.BaseRequestHandler): + def handle(self): + data = b"" + conn = self.request + conn.settimeout(5) + if outer.tls: + try: + conn = outer.tls.wrap_socket(conn, server_side=True) + except (ssl.SSLError, OSError): + return + self.request = conn + try: + while b"\r\n\r\n" not in data: + chunk = self.request.recv(4096) + if not chunk: + return + data += chunk + except OSError: + return + lines = data.split(b"\r\n\r\n")[0].decode("latin-1").split("\r\n") + method, target, _ = lines[0].split(" ", 2) + headers = {} + for ln in lines[1:]: + k, _, v = ln.partition(":") + headers[k.strip().lower()] = v.strip() + req = (method, target, headers) + outer.requests.append(req) + try: + out = outer.respond(outer, req) + if isinstance(out, (bytes, bytearray)): + out = [out] + for chunk in out: # a generator may stream, slowly + if outer.stopping: + break + self.request.sendall(chunk) + except OSError: + pass + + class Server(socketserver.ThreadingTCPServer): + allow_reuse_address = True + daemon_threads = True + + self.server = Server(("127.0.0.1", port), Handler) + threading.Thread(target=self.server.serve_forever, daemon=True).start() + + def close(self): + self.stopping = True + self.server.shutdown() + self.server.server_close() + + def targets(self): + return [t for _, t, _ in self.requests] + + +def ok_response(backend, req): + return (b"HTTP/1.1 200 OK\r\nContent-Length: 0\r\nConnection: close\r\n\r\n") + + +def worker_status(http, port): + """The balancer-manager's status text for the worker on port .""" + r = http.GET("/balancer-manager") + assert r.status_code == 200, "balancer-manager not reachable" + needle = re.compile(rf":{port}\b") + for row in re.split(r"", r.text): + if needle.search(row): + for cell in re.findall(r"]*>(.*?)", row, re.S): + text = re.sub(r"<[^>]+>", "", cell).strip() + if re.search(r"\b(Init|Ok|Dis|Stop|HcFl|Err)\b", text): + return text + return None + + +def wait_until(fn, timeout, interval=0.3): + deadline = time.time() + timeout + last = None + while time.time() < deadline: + last = fn() + if last: + return last + time.sleep(interval) + return last + + +def is_ok(http, port): + st = worker_status(http, port) or "" + return "Ok" in st and "HcFl" not in st + + +def goes_bad(http, backend, port, bad): + """Start from a healthy worker, then make the backend misbehave. + + A worker whose backend is not up yet is already failing, so "it is failing" + proves nothing: first see it pass, and only then switch the response.""" + backend.respond = ok_response + assert wait_until(lambda: is_ok(http, port), 20), ( + f"worker never became healthy: {worker_status(http, port)!r}") + backend.respond = bad + return wait_until(lambda: "HcFl" in (worker_status(http, port) or ""), 20) + + +@pytest.fixture +def hc_http(http): + http.module("proxy_hcheck") + try: + yield http + finally: + http.module(None) + + +@need +def test_complete_response_keeps_worker_healthy(hc_http): + """Control: a proper response passes the health check.""" + port = conf_port(hc_http, "HDR") + b = Backend(port, ok_response) + try: + assert wait_until(lambda: b.requests, 15), "no health check arrived" + time.sleep(3) + assert "HcFl" not in (worker_status(hc_http, port) or "") + assert "Ok" in (worker_status(hc_http, port) or "") + finally: + b.close() + + +@need +def test_truncated_response_headers_fail_the_check(hc_http): + """A response whose headers end at EOF, without the blank line that + terminates them, is not a valid response. It used to be accepted, so a + backend that was cutting its responses short was reported healthy.""" + port = conf_port(hc_http, "HDR") + + def truncated(backend, req): + return b"HTTP/1.1 200 OK\r\nServer: broken\r\n" # ...and closes + + b = Backend(port, ok_response) + try: + assert goes_bad(hc_http, b, port, truncated), ( + f"truncated headers passed: {worker_status(hc_http, port)!r}") + finally: + b.close() + + +def manager_post(http, balancer, query): + """POST to the vhost's balancer-manager (the nonce comes from its page).""" + r = http.GET("/balancer-manager") + assert r.status_code == 200, "balancer-manager not reachable" + m = re.search(rf"b={balancer}[^\"]*?nonce=([0-9a-fA-F-]+)", r.text.replace("&", "&")) + assert m, f"no nonce for balancer://{balancer}" + v = http.vars() + port = http.vhost_port("proxy_hcheck") + referer = {"Referer": f"http://{v['servername']}:{port}/balancer-manager"} + return http.POST("/balancer-manager", + content=(query + "&nonce=" + m.group(1)).encode(), + headers=referer) + + +@need +def test_changed_probe_uri_is_used(hc_http): + """The probe URI is read from the worker when the health check is first set + up, and was never looked at again, so changing it in the balancer-manager + had no effect on what the backend saw.""" + port = conf_port(hc_http, "URI") + b = Backend(port, ok_response) + try: + assert wait_until(lambda: "/old" in b.targets(), 15), "no /old probe" + + r = manager_post(hc_http, "hcuri", f"w=http://127.0.0.1:{port}&b=hcuri&w_hu=/new") + assert r.status_code == 200 + assert "/new" in hc_http.GET("/balancer-manager").text, ( + "the balancer-manager did not store the new URI") + + mark = len(b.requests) + assert wait_until(lambda: "/new" in b.targets()[mark:], 15), ( + f"probes after the change still went to {sorted(set(b.targets()[mark:]))}") + finally: + b.close() + + +def make_cert(directory, name): + """A self-signed certificate for `name`; returns (certfile, keyfile) or None.""" + for exe in (shutil.which("openssl"), "/opt/homebrew/opt/openssl@3/bin/openssl", + "/opt/local/bin/openssl"): + if not exe: + continue + cert, key = f"{directory}/{name}.crt", f"{directory}/{name}.key" + r = subprocess.run( + [exe, "req", "-x509", "-newkey", "rsa:2048", "-nodes", "-days", "2", + "-subj", f"/CN={name}", "-addext", f"subjectAltName=DNS:{name}", + "-keyout", key, "-out", cert], + capture_output=True) + if r.returncode == 0: + return cert, key + return None + + +@pytest.fixture +def certs(): + with tempfile.TemporaryDirectory() as d: + bad, good = make_cert(d, "wrong.invalid"), make_cert(d, "localhost") + if not bad or not good: + pytest.skip("no openssl able to make a test certificate") + yield {"bad": bad, "good": good} + + +def tls_need(http): + if not http.have_module("ssl"): + pytest.skip("mod_ssl is required") + + +@need +def test_https_probe_sends_sni_and_checks_the_name(hc_http, certs): + """A health check of an https worker used to send no SNI and skip the host + name check, so a backend presenting the certificate of another host passed + even though real requests to it are refused.""" + tls_need(hc_http) + port = conf_port(hc_http, "TLSBAD") + b = Backend(port, ok_response, tls=certs["bad"]) + try: + assert wait_until(lambda: b.sni, 15), "no TLS handshake reached the backend" + assert "localhost" in b.sni, f"SNI seen by the backend: {b.sni}" + # The worker starts out failing (nothing was listening yet), so what + # matters is that, with handshakes happening, it never turns healthy. + assert not wait_until(lambda: is_ok(hc_http, port), 8), ( + "wrong-host certificate passed the check: " + f"{worker_status(hc_http, port)!r}") + finally: + b.close() + + +@need +def test_https_probe_with_matching_certificate_passes(hc_http, certs): + """Control for the above: the right certificate keeps the worker healthy.""" + tls_need(hc_http) + port = conf_port(hc_http, "TLSGOOD") + b = Backend(port, ok_response, tls=certs["good"]) + try: + assert wait_until(lambda: b.requests, 15), "no health check request arrived" + time.sleep(3) + status = worker_status(hc_http, port) or "" + assert "Ok" in status and "HcFl" not in status, status + assert "localhost" in b.sni + finally: + b.close() + + +# ---- limits on what a probe accepts from a backend ---------------------------- + +@need +def test_response_with_too_many_headers_fails_the_check(hc_http): + port = conf_port(hc_http, "MANYHDR") + + def many(backend, req): + hdrs = b"".join(b"X-Filler-%d: v\r\n" % i for i in range(2000)) + return b"HTTP/1.1 200 OK\r\n" + hdrs + b"Content-Length: 0\r\nConnection: close\r\n\r\n" + + b = Backend(port, ok_response) + try: + assert goes_bad(hc_http, b, port, many), ( + f"2000 response headers were accepted: {worker_status(hc_http, port)!r}") + finally: + b.close() + + +@need +def test_endless_response_is_cut_off(hc_http): + """A backend that keeps sending (a byte every half second here) never trips + a per-read timeout. The probe needs an overall deadline (the worker's + timeout, 2s here) or it holds a checking thread, and keeps growing its + buffer, for as long as the backend cares to go on.""" + port = conf_port(hc_http, "SLOW") + + def endless(backend, req): + yield b"HTTP/1.1 200 OK\r\nConnection: close\r\n\r\n" + while True: + time.sleep(0.5) + yield b"x" + + b = Backend(port, ok_response) + try: + assert goes_bad(hc_http, b, port, endless), ( + f"an endless response was never cut off: {worker_status(hc_http, port)!r}") + finally: + b.close() + + +def big_ok(size): + def respond(backend, req): + yield (b"HTTP/1.1 200 OK\r\nContent-Length: %d\r\nConnection: close\r\n\r\n" % size) + sent = 0 + while sent < size: + n = min(65536, size - sent) + yield b"x" * n + sent += n + return respond + + +@need +def test_large_body_is_not_kept_for_a_condition(hc_http): + """With a condition on the body, a probe keeps the body in memory to evaluate + it. A 3MB body is more than that is allowed to take, and fails the check.""" + port = conf_port(hc_http, "BIGEXPR") + b = Backend(port, ok_response) + try: + assert goes_bad(hc_http, b, port, big_ok(3 * 1024 * 1024)), ( + f"a 3MB body was kept and evaluated: {worker_status(hc_http, port)!r}") + finally: + b.close() + + +@need +def test_large_body_without_a_condition_is_fine(hc_http): + """Control: with no condition the body is not needed, is read and dropped, + and the check passes as before.""" + port = conf_port(hc_http, "BIGPLAIN") + b = Backend(port, big_ok(3 * 1024 * 1024)) + try: + assert wait_until(lambda: len(b.requests) >= 2, 15), "probes stopped arriving" + status = worker_status(hc_http, port) or "" + assert "Ok" in status and "HcFl" not in status, status + finally: + b.close() + + +# ---- the probe's request line --------------------------------------------------- + +@need +@pytest.mark.parametrize("name,expected", [ + ("PATHA", "/ping"), # http://host:port + hcuri "ping" + ("PATHB", "/app/ping"), # http://host:port/app + hcuri "/ping" + ("PATHC", "/app/ping"), # http://host:port/app/ + hcuri "ping" +]) +def test_probe_path_joins_worker_path_and_hcuri(hc_http, name, expected): + """One slash between the worker's path and hcuri, and a request target that + starts with one: a bare "ping" used to be sent as "GET ping HTTP/1.0", and a + path plus "/ping" as "/app//ping".""" + b = Backend(conf_port(hc_http, name), ok_response) + try: + assert wait_until(lambda: b.requests, 15), "no health check arrived" + assert set(b.targets()) == {expected}, b.targets() + finally: + b.close() + + +@need +def test_check_worker_is_created_once(hc_http): + """The cache of per-worker check state is looked up on every cycle; if the + lookup were to miss, a new long-lived check worker would be created each + time. (Guards the lifetime of the cache's keys.)""" + port = conf_port(hc_http, "URI") + error_log = Path(hc_http.vars("t_logs")) / "error_log" + b = Backend(port, ok_response) + try: + assert wait_until(lambda: len(b.requests) >= 5, 20), "too few health checks" + finally: + b.close() + session_start = int(hc_http.vars("session_log_start") or 0) + with error_log.open("r", errors="replace") as fh: + fh.seek(session_start) + created = [ln for ln in fh if "Creating hc worker" in ln + and f"127.0.0.1:{port}" in ln] + assert len(created) == 1, created