paivana

HTTP paywall reverse proxy
Log | Files | Refs | Submodules | README | LICENSE

commit 5dfdaf05ea095c7d26e1a48e76bb2a04d2c62191
parent 29ea1adce4107cf95e2f0c076cac7e94f3822f69
Author: Christian Grothoff <christian@grothoff.org>
Date:   Tue,  4 Aug 2026 16:37:50 +0200

add test to reproduce cases where upstream starts to respond but stops reading the request

Diffstat:
Msrc/tests/README | 59++++++++++++++++++++++++++++++++++++++++++++++-------------
Msrc/tests/early_response_upstream.c | 271++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++-------
Msrc/tests/test_reverse_proxy.sh | 197++++++++++++++++++++++++++++++++++++++++++++++++++++++++++---------------------
3 files changed, 438 insertions(+), 89 deletions(-)

diff --git a/src/tests/README b/src/tests/README @@ -24,12 +24,22 @@ A fifth, special-purpose upstream is also built: C / raw sockets, single-connection. Sends a 413 response immediately after reading the request headers, BEFORE consuming the request body — used - to exercise paivana's full-duplex forwarding path - (early upstream response while client upload is - still in flight). Writes the body byte count it - observed to a receipt file after the connection - closes, so the test can confirm paivana did not - abandon the upload mid-stream. + to exercise paivana's handling of an early upstream + response that lands while the client upload is + still in flight. Writes the body byte count it + observed to a receipt file, as a diagnostic. + + With `--no-drain` it additionally stops reading + once it has answered, and parks the connection with + the rest of the request queued in a deliberately + tiny receive buffer. That is what makes paivana's + outbound socket back up: measured on loopback, the + upstream holds ~12 KiB unread while ~240 KiB of the + request sits undeliverable in paivana's send buffer. + A proxy that waited for that write to finish before + acting on the response it already holds would + deadlock; without `--no-drain` the condition never + arises, because the upstream keeps reading. They all implement the same canned endpoints (see "Endpoints" below). The pipelining test client `pipeline_client` is a small C program @@ -105,14 +115,36 @@ Cross-cutting tests (run once): early upstream response against early_response_upstream, a 768 KiB POST that the upstream answers with a 413 BEFORE reading the body. - Verifies that (a) paivana forwards the - 413 to the client (no 502 from an - aborted forward) and (b) paivana - finishes streaming the upload — the - upstream's receipt file must record - the full 768 KiB. Exercises the - full-duplex code path in + Paivana must forward that 413 to the + client rather than turning it into a + 502 — the early-response path in curl_download_cb / curl_upload_cb. + Note that the upstream is NOT expected + to see the whole body: RFC 9110 §9.3 + lets a client stop sending once it has + a final response, and libcurl does + (plain curl against this upstream + sends ~128 KiB of the 768 KiB and + stops). The receipt is a diagnostic; + the test only requires that it appear, + i.e. that the exchange finished + upstream-side. + early response, no drain the same, with --no-drain: having + answered, the upstream never reads + again, so paivana's outbound socket + stays full with a request it can no + longer finish sending. It must still + answer its own client, promptly, with + the upstream's 413. Bounded by + timeout(1) rather than curl --max-time + because the failure mode is a hang: + paivana's CURLOPT_TIMEOUT would + eventually turn it into a 502 after + 60s, which must not be allowed to look + like a slow pass. The drain-mode case + above cannot catch this — the upstream + there keeps reading, so the socket + never stays full. Environment variables --------------------- @@ -138,6 +170,7 @@ are already in use. 18403 upstream_py 18404 upstream_rs 18405 early_response_upstream + 18406 early_response_upstream --no-drain 18499 dead port (for "upstream down" test) 18500 paivana-httpd diff --git a/src/tests/early_response_upstream.c b/src/tests/early_response_upstream.c @@ -21,34 +21,77 @@ /** * @file early_response_upstream.c * @brief Raw-socket HTTP upstream that responds before reading the - * request body. Used to exercise paivana's full-duplex - * forwarding path: when the upstream begins responding while - * the client (paivana) is still uploading, paivana must keep - * streaming the upload to completion AND deliver the upstream - * response to its own client — neither side may be abandoned. + * request body. Used to exercise paivana's handling of an + * early upstream response: when the upstream answers while + * the client (paivana) is still uploading, paivana must + * deliver that response to its own client rather than treat + * the interrupted forward as a failure. * * After each connection finishes the server writes the number * of body bytes it received (decimal, trailing newline) to the - * file given as the second argument, atomically via - * rename(2). The test driver reads that file to confirm that - * paivana actually forwarded the entire request body even - * though the upstream had already responded. + * file given as the second argument, atomically via rename(2). + * That count is a diagnostic, not a contract: RFC 9110 §9.3 + * lets a client stop sending its body once it has a final + * response, and libcurl does exactly that, so the upstream + * normally sees only a prefix of what was sent. + * + * With `--no-drain` the server instead *stops* reading once it + * has answered, and parks the connection with the rest of the + * request still queued in its receive buffer. That is the + * nastier half of the same situation: paivana's outbound + * socket backs up and its write() can no longer make progress, + * so it can only finish the request if it acts on the response + * that is already in hand rather than waiting for the upload + * to drain. A proxy that gets this wrong hangs until its + * transfer timeout instead of failing outright, which is why + * the driver bounds the case with timeout(1). */ +#ifndef _GNU_SOURCE +/* for POLLRDHUP, which is how we notice the peer hanging up + without ever reading from the socket */ +#define _GNU_SOURCE +#endif #include <errno.h> #include <netinet/in.h> +#include <poll.h> #include <signal.h> +#include <stdbool.h> #include <stdint.h> #include <stdio.h> #include <stdlib.h> #include <string.h> +#include <strings.h> #include <sys/socket.h> #include <sys/types.h> #include <unistd.h> +/** + * How long (ms) a `--no-drain` connection is parked before we give up + * on the peer ever hanging up. Only reached when paivana is stuck, + * and the driver's timeout(1) will have failed the case by then; the + * bound is here so a wedged run still terminates. + */ +#define PARK_TIMEOUT_MS 30000 + +/** + * Receive buffer (bytes) requested for `--no-drain` connections. The + * kernel doubles this and enforces its own floor; the point is only + * to keep it far below the body the driver sends, so that refusing to + * read reliably stalls the sender no matter how TCP autotuning is + * configured on the machine running the tests. + */ +#define NO_DRAIN_RCVBUF 8192 + static const char *receipt_path; static volatile sig_atomic_t run_flag = 1; +/** + * Keep reading the request body after responding? False under + * `--no-drain`, where refusing to read is the whole point. + */ +static bool drain_body = true; + static void on_sig (int sig) @@ -100,6 +143,56 @@ read_until_eoh (int fd, /** + * Find the Content-Length announced in the request header block held + * in the first @a len bytes of @a hdr. + * + * We need it because we cannot rely on end-of-file to tell us the + * request is over: the peer is free to keep a completed connection in + * a pool, and then no EOF ever comes. + * + * @param hdr start of the (not NUL-terminated) header block + * @param len number of bytes in @a hdr + * @return the announced length, or -1 if there was none + */ +static long long +find_content_length (const char *hdr, + size_t len) +{ + static const char name[] = "content-length:"; + const size_t nlen = sizeof (name) - 1; + + for (size_t i = 0; i + nlen <= len; i++) + { + size_t j; + long long v = 0; + bool digits = false; + + if ( (0 == i) || + ('\n' != hdr[i - 1]) ) + continue; /* header names start a line */ + if (0 != strncasecmp (&hdr[i], + name, + nlen)) + continue; + j = i + nlen; + while ( (j < len) && + ( (' ' == hdr[j]) || ('\t' == hdr[j]) ) ) + j++; + while ( (j < len) && + ('0' <= hdr[j]) && + ('9' >= hdr[j]) ) + { + v = v * 10 + (hdr[j] - '0'); + digits = true; + j++; + } + return digits ? v : -1; + } + return -1; +} + + +/** * Atomically write @a count to the receipt file (write to <path>.tmp, * fsync, rename). No-op if no receipt path was configured. */ @@ -131,6 +224,12 @@ write_receipt (size_t count) } +/** + * The early response. Deliberately *without* `Connection: close`: + * announcing a close makes libcurl give up on the rest of the request + * body it was sending, which is legitimate but would rob the + * drain-mode test of the very thing it checks. + */ static const char EARLY_RESPONSE[] = "HTTP/1.1 413 Payload Too Large\r\n" "Content-Type: text/plain\r\n" @@ -170,6 +269,52 @@ write_all (int fd, } +/** + * Wait for the peer to shut down its sending side of @a fd without + * ever reading from the socket, so that the unconsumed request body + * keeps the peer's send buffer full. Gives up after + * #PARK_TIMEOUT_MS. + * + * @param fd the connection to park + */ +static void +park_until_hangup (int fd) +{ + struct pollfd pfd = { + .fd = fd, + /* Deliberately not POLLIN: we do not want to know that body + bytes arrived, only that the peer is done sending them. */ + .events = POLLRDHUP + }; + int elapsed = 0; + + while (elapsed < PARK_TIMEOUT_MS) + { + int rv; + + if (! run_flag) + return; /* shutting down, nothing to report */ + rv = poll (&pfd, + 1, + 250); + if (rv < 0) + { + if (EINTR == errno) + continue; + return; + } + if (0 != (pfd.revents & (POLLRDHUP | POLLHUP | POLLERR))) + return; + elapsed += 250; + } + fprintf (stderr, + "no-drain connection parked for %d ms without a hangup;" + " the peer is most likely stuck\n", + elapsed); + fflush (stderr); +} + + static void handle_client (int fd) { @@ -177,6 +322,7 @@ handle_client (int fd) size_t eoh = 0; ssize_t got; size_t body_bytes; + long long content_length; got = read_until_eoh (fd, buf, @@ -188,6 +334,8 @@ handle_client (int fd) return; } body_bytes = (size_t) got - eoh; + content_length = find_content_length (buf, + eoh); /* Send the 413 response immediately. This is the whole point of this upstream: respond before consuming the request body. */ @@ -201,11 +349,33 @@ handle_client (int fd) return; } + if (! drain_body) + { + /* The interesting case: having answered, refuse to read another + byte. The rest of the request stays in our receive buffer, + our window closes, and paivana's send() stops making progress + with the response already sitting unread on its side. Park + until the peer hangs up (which is what a proxy that handles + this correctly does) rather than closing ourselves: closing + with unread data queued would send an RST, and the peer would + be entitled to discard the response we just sent -- turning a + proxy bug into a transport error and vice versa. */ + park_until_hangup (fd); + close (fd); + write_receipt (body_bytes); + return; + } + /* Now drain the rest of the request body. We must keep reading - until the client (paivana) closes its side — otherwise its - CURL would block on send() once the kernel recv buffer fills, - which would mask the very behavior we are trying to test. */ - for (;;) + until the announced Content-Length is in (or the client closes, + for a request that had none) — otherwise its CURL would block on + send() once the kernel recv buffer fills, which would mask the + very behavior we are trying to test. Stopping at + Content-Length rather than at EOF matters: having answered the + request in full we have given the peer every right to keep the + connection for reuse, and then the EOF never comes. */ + while ( (content_length < 0) || + (body_bytes < (size_t) content_length) ) { ssize_t n = read (fd, buf, @@ -231,23 +401,58 @@ main (int argc, char **argv) { int srv; - int port; + int port = 0; int yes = 1; + int have_port = 0; struct sockaddr_in addr; - if (argc < 2) + for (int i = 1; i < argc; i++) + { + if (0 == strcmp (argv[i], + "--no-drain")) + { + drain_body = false; + continue; + } + if (! have_port) + { + port = atoi (argv[i]); + have_port = 1; + continue; + } + if (NULL == receipt_path) + { + receipt_path = argv[i]; + continue; + } + fprintf (stderr, + "unexpected argument `%s'\n", + argv[i]); + have_port = 0; + break; + } + if (! have_port) { fprintf (stderr, - "usage: %s <port> [receipt-file]\n", + "usage: %s <port> [receipt-file] [--no-drain]\n", argv[0]); return 1; } - port = atoi (argv[1]); - if (argc >= 3) - receipt_path = argv[2]; - signal (SIGINT, on_sig); - signal (SIGTERM, on_sig); + { + /* sigaction(2), not signal(3): glibc's signal() implies + SA_RESTART, which would restart the accept(2) we spend most of + our life in and leave us ignoring SIGTERM forever. We need the + EINTR so the loops below can notice `run_flag'. */ + struct sigaction sa = { + .sa_handler = &on_sig, + .sa_flags = 0 + }; + + sigemptyset (&sa.sa_mask); + sigaction (SIGINT, &sa, NULL); + sigaction (SIGTERM, &sa, NULL); + } signal (SIGPIPE, SIG_IGN); srv = socket (AF_INET, SOCK_STREAM, 0); @@ -261,6 +466,23 @@ main (int argc, SO_REUSEADDR, &yes, sizeof (yes)); + if (! drain_body) + { + int rcvbuf = NO_DRAIN_RCVBUF; + + /* Set on the listening socket so accepted connections inherit + it, and before listen(2) so it is in effect for the SYN-ACK + window. Without this the peer could park a multi-megabyte + autotuned window's worth of body with us and finish its + write() after all, which would quietly turn the no-drain case + back into the drain case. */ + if (0 != setsockopt (srv, + SOL_SOCKET, + SO_RCVBUF, + &rcvbuf, + sizeof (rcvbuf))) + perror ("setsockopt(SO_RCVBUF)"); /* not fatal, just less sharp */ + } memset (&addr, 0, sizeof (addr)); addr.sin_family = AF_INET; addr.sin_addr.s_addr = htonl (INADDR_LOOPBACK); @@ -280,8 +502,11 @@ main (int argc, return 1; } fprintf (stderr, - "early_response_upstream listening on port %d\n", - port); + "early_response_upstream listening on port %d (%s)\n", + port, + drain_body + ? "draining the body after responding" + : "refusing to read the body after responding"); fflush (stderr); while (run_flag) diff --git a/src/tests/test_reverse_proxy.sh b/src/tests/test_reverse_proxy.sh @@ -81,6 +81,7 @@ GO_PORT=18402 PY_PORT=18403 RS_PORT=18404 EARLY_PORT=18405 +NODRAIN_PORT=18406 DEAD_PORT=18499 # nothing should be listening here TMPDIR="$(mktemp -d -t paivana-tests.XXXXXX)" @@ -165,14 +166,16 @@ function start_bg() { } function start_paivana() { - # $1 = upstream base URL - local dest="$1" - local flags="${2:-}" + # $1 = upstream base URL; any further arguments are passed to + # paivana-httpd verbatim. Note the shift: quoting "$@" (rather + # than a single "$flags" string) is what keeps a caller that + # passes no extra flags from handing paivana an empty argument. + local dest="$1"; shift local cfg="$TMPDIR/paivana.conf" sed -e "s|@DEST@|$dest|g" -e "s|@PORT@|$PAIVANA_PORT|g" \ "$SRCDIR/test_reverse_proxy.conf.in" > "$cfg" local log="$LOGDIR/paivana.log" - ( exec "$PAIVANA_HTTPD" -c "$cfg" -n -L INFO "$flags") >"$log" 2>&1 & + ( exec "$PAIVANA_HTTPD" -c "$cfg" -n -L WARNING "$@" ) >"$log" 2>&1 & PAIVANA_PID=$! if ! wait_for_port 127.0.0.1 "$PAIVANA_PORT"; then @@ -572,17 +575,82 @@ function test_upload_too_big_chunked() { ok } +# 768 KiB — under paivana's 1 MiB request-buffer cap, but far too +# large to fit in kernel TCP buffers, so the upstream is guaranteed +# to have answered while paivana's curl is still uploading. +EARLY_PAYLOAD_SIZE=786432 + +# Write the early-response payload to $TMPDIR/early_body, once. +function make_early_payload() { + local payload="$TMPDIR/early_body" + local got + [ -s "$payload" ] && return 0 + dd if=/dev/urandom of="$payload" bs=1024 count=768 status=none + got="$(wc -c <"$payload" | tr -d ' ')" + [ "$got" = "$EARLY_PAYLOAD_SIZE" ] || \ + fail "test setup: payload is $got bytes, want $EARLY_PAYLOAD_SIZE" +} + +EARLY_PID="" + +# Start early_response_upstream. $1 = port, $2 = receipt file, and +# any further arguments go to the upstream (e.g. --no-drain). +function start_early_upstream() { + local port="$1" receipt="$2"; shift 2 + rm -f "$receipt" + ( exec "$EARLY_RESPONSE_UPSTREAM" "$port" "$receipt" "$@" ) \ + >"$LOGDIR/early-$port.log" 2>&1 & + EARLY_PID=$! + PIDS+=("$EARLY_PID") + if ! wait_for_port 127.0.0.1 "$port"; + then + fail "early_response_upstream did not start on port $port" + fi +} + +function stop_early_upstream() { + if [ -n "$EARLY_PID" ]; + then + kill -TERM "$EARLY_PID" 2>/dev/null + # In --no-drain mode the upstream may be parked on a + # connection whose peer never hangs up, so back the TERM with + # a KILL: a wedged helper must not wedge the whole suite. + ( sleep 2; kill -KILL "$EARLY_PID" 2>/dev/null ) & + wait "$EARLY_PID" 2>/dev/null + EARLY_PID="" + fi +} + +# Block until the upstream's receipt file appears (it writes it once +# the connection is over), then echo the count it recorded. Echoes +# nothing if it never showed up. +function read_receipt() { + local receipt="$1" tries=50 + while [ "$tries" -gt 0 ] && [ ! -s "$receipt" ]; + do + sleep 0.1 + tries=$((tries - 1)) + done + [ -s "$receipt" ] || return 0 + tr -d '\n ' <"$receipt" +} + function test_early_response() { # The upstream sends a 413 response immediately after reading the # request headers, before consuming any of the request body — a - # legal HTTP/1.1 pattern. Paivana must (a) deliver that response - # back to its client (no 502 from an aborted forward) and (b) - # still finish streaming the upload to upstream so the upstream - # sees the full request body. + # legal HTTP/1.1 pattern. Paivana must deliver that response back + # to its own client rather than turning it into a 502, even though + # its curl handle was still uploading when it arrived. # - # The byte count the upstream observed is written to RECEIPT - # after the connection finishes; we read it back to confirm. - msg "early upstream response: response forwarded AND upload completed" + # Note what is deliberately NOT asserted: that the upstream sees + # the whole body. RFC 9110 §9.3 lets a client stop sending once + # it has a final response, and libcurl does exactly that — plain + # `curl` against this upstream sends ~128 KiB of a 768 KiB body + # and stops. The receipt the upstream writes is therefore a + # diagnostic, and all we require of it is that it appears: that + # means the exchange finished upstream-side instead of leaving + # the upstream blocked in read() forever. + msg "early upstream response is forwarded to the client" if [ ! -x "$EARLY_RESPONSE_UPSTREAM" ]; then echo "SKIP (early_response_upstream not built)" @@ -590,60 +658,82 @@ function test_early_response() { fi stop_paivana local receipt="$TMPDIR/early_receipt" - rm -f "$receipt" - local log="$LOGDIR/early.log" - ( exec "$EARLY_RESPONSE_UPSTREAM" "$EARLY_PORT" "$receipt" ) \ - >"$log" 2>&1 & - local early_pid=$! - PIDS+=("$early_pid") - if ! wait_for_port 127.0.0.1 "$EARLY_PORT"; - then - fail "early_response_upstream did not start on port $EARLY_PORT" - fi - start_paivana "http://127.0.0.1:$EARLY_PORT" -F - - # 768 KiB body — under paivana's 1 MiB request-buffer cap, but - # too large to fit in default kernel TCP buffers, so the response - # is guaranteed to start arriving while paivana's curl is still - # uploading. Without the full-duplex fix paivana would either - # abort the curl handle (502 to client) or silently drop the - # remaining upload bytes (receipt < expected). - local payload="$TMPDIR/early_body" - local expected=786432 - dd if=/dev/urandom of="$payload" bs=1024 count=768 status=none - local got_size - got_size="$(wc -c <"$payload" | tr -d ' ')" - [ "$got_size" = "$expected" ] || fail "test setup: payload is $got_size bytes, want $expected" + start_early_upstream "$EARLY_PORT" "$receipt" + start_paivana "http://127.0.0.1:$EARLY_PORT" + make_early_payload + # Without the early-response fix paivana would abort the curl + # handle and answer 502 instead of relaying what it was handed. local status - status="$(curl -sS -X POST --data-binary "@$payload" \ + status="$(curl -sS -X POST --data-binary "@$TMPDIR/early_body" \ --max-time 30 \ -o "$TMPDIR/body" -w '%{http_code}' \ "$(PAIVANA_URL /upload)" 2>"$TMPDIR/err")" \ || fail "curl: $(cat "$TMPDIR/err")" [ "$status" = "413" ] || \ - fail "status=$status want=413 (a 502 here means paivana aborted the forward instead of full-duplexing)" + fail "status=$status want=413 (a 502 here means paivana aborted the forward instead of relaying the early response)" grep -q 'early-response-payload' "$TMPDIR/body" || \ fail "response body did not come from upstream: $(head -c 200 "$TMPDIR/body")" - # Wait briefly for the upstream to finish draining the connection - # and write the receipt file (it does so after read() returns 0). - local tries=50 - while [ "$tries" -gt 0 ] && [ ! -s "$receipt" ]; - do - sleep 0.1 - tries=$((tries - 1)) - done - [ -s "$receipt" ] || fail "upstream did not write receipt file" - local got - got="$(tr -d '\n ' <"$receipt")" - [ "$got" = "$expected" ] || \ - fail "upstream received $got of $expected body bytes — paivana abandoned the upload mid-stream" + [ -n "$(read_receipt "$receipt")" ] || \ + fail "upstream never finished the exchange (still blocked reading the body?)" + ok + + stop_paivana + stop_early_upstream +} + +function test_early_response_no_drain() { + # The dangerous half of the same situation. Here the upstream + # answers early and then refuses to read another byte, leaving + # the rest of the request queued in its (deliberately tiny) + # receive buffer. Paivana's outbound socket therefore stays full + # and its write() can never complete: the only way out is to act + # on the response it already holds. A proxy that instead insists + # on finishing the upload first deadlocks until its own transfer + # timeout (60s for us) and only then answers 502 — which is why + # `timeout` bounds this case. Without that bound the hang would + # eventually "pass" as a slow 502 rather than fail. + # + # The drain-mode test above cannot catch this: because that + # upstream keeps read()-ing until EOF, paivana's socket never + # stays full and the deadlock never has a chance to form. + msg "early upstream response, upstream then stops reading: no hang" + if [ ! -x "$EARLY_RESPONSE_UPSTREAM" ]; + then + echo "SKIP (early_response_upstream not built)" + return + fi + stop_paivana + local receipt="$TMPDIR/nodrain_receipt" + start_early_upstream "$NODRAIN_PORT" "$receipt" --no-drain + start_paivana "http://127.0.0.1:$NODRAIN_PORT" + make_early_payload + + # 20s is comfortably above a healthy round-trip (milliseconds) + # and comfortably below paivana's 60s CURLOPT_TIMEOUT, so a + # deadlock shows up as a killed curl rather than a late answer. + local status rc + status="$(timeout 20 curl -sS -X POST \ + --data-binary "@$TMPDIR/early_body" \ + -o "$TMPDIR/body" -w '%{http_code}' \ + "$(PAIVANA_URL /upload)" 2>"$TMPDIR/err")" + rc=$? + [ "$rc" != "124" ] && [ "$rc" != "137" ] || \ + fail "no response within 20s: paivana blocked on an upload the upstream stopped reading" + [ "$rc" = "0" ] || fail "curl exited $rc: $(cat "$TMPDIR/err")" + [ "$status" = "413" ] || \ + fail "status=$status want=413 (a 502 means paivana gave up on the transfer instead of using the response it had)" + grep -q 'early-response-payload' "$TMPDIR/body" || \ + fail "response body did not come from upstream: $(head -c 200 "$TMPDIR/body")" + # No receipt assertion here: the upstream only ever saw whatever + # fit in its receive buffer, and whether the connection is closed + # or kept for reuse afterwards is paivana's business. The count + # it does eventually record is for diagnostics. ok stop_paivana - kill -TERM "$early_pid" 2>/dev/null - wait "$early_pid" 2>/dev/null + stop_early_upstream } @@ -775,8 +865,9 @@ then stop_paivana fi -# --- Early-response upstream test (restarts paivana) ------------------ +# --- Early-response upstream tests (restart paivana) ------------------ test_early_response +test_early_response_no_drain # --- Upstream-down test (runs last because it restarts paivana) ------- test_upstream_down