Merge remote-tracking branch 'origin/main'

# Conflicts:
#	Makefile
#	debian/changelog
#	tests/01-module/01-e2e.robot

Makefile

@@ -3,9 +3,12 @@
 #
 # Targets:
 #   build        - build ngx_http_ipng_stats_module.so out-of-tree.
+#   build-asan   - build an ASan/UBSan-instrumented full nginx + module.
 #   pkg-deb      - build a .deb via dpkg-buildpackage for the current release.
-#   robot-test   - build .deb, then run Robot Framework end-to-end tests
-#                  in containerlab (requires docker + containerlab).
+#   robot-test   - run Robot Framework end-to-end tests in containerlab.
+#                  Reuses build/ artifacts — run `make pkg-deb build-asan`
+#                  once beforehand, then iterate on `make robot-test`.
+#                  Requires docker + containerlab.
 #   install-deps - install build and test dependencies via apt.
 #   clean        - remove build artifacts and the fetched nginx source tree.
 #   help         - print this help.
@@ -39,6 +42,7 @@ help:
 	@echo "                    into build/nginx-asan/ for local crash-hunting."
 	@echo "  make pkg-deb      Build a Debian package via dpkg-buildpackage."
 	@echo "  make robot-test   Run Robot Framework e2e tests (all suites)."
+	@echo "                    Reuses artifacts; bootstrap with 'make pkg-deb build-asan' first."
 	@echo "  make install-deps Install build and test dependencies (apt)."
 	@echo "  make clean        Remove build artifacts."
 	@echo ""
@@ -224,19 +228,54 @@ tests/.venv: tests/requirements.txt
 	python3 -m venv tests/.venv
 	tests/.venv/bin/pip install -q -r tests/requirements.txt
 
+# robot-test intentionally does NOT rebuild the .deb or the ASan
+# nginx. A full rebuild every `make robot-test` makes the iterate-
+# on-test loop painfully slow. Instead we fail fast with an
+# actionable message if either artifact is missing.
+#
+# Bootstrap once:  make pkg-deb build-asan
+# Then iterate:    make robot-test       # reuses both artifacts
 robot-test: tests/.venv
+	@if ! ls $(BUILD_DIR)/libnginx-mod-http-ipng-stats_*.deb >/dev/null 2>&1; then \
+		echo "error: no module .deb in $(BUILD_DIR)/ — run 'make pkg-deb' first" >&2; \
+		exit 1; \
+	fi
+	@if [ ! -x $(BUILD_DIR)/nginx-asan/sbin/nginx ]; then \
+		echo "error: no ASan nginx in $(BUILD_DIR)/nginx-asan/ — run 'make build-asan' first" >&2; \
+		exit 1; \
+	fi
 	tests/rf-run.sh docker $(TEST)
 
 # ----------------------------------------------------------------------
 # install-deps: install build and test dependencies
 # ----------------------------------------------------------------------
 
+# install-deps covers everything needed for `make build`, `make build-asan`,
+# `make pkg-deb`, and `make robot-test` (apart from docker + containerlab,
+# which have their own installers). `nginx-dev` transitively pulls the
+# nginx build-deps (libpcre2-dev, libssl-dev, libxslt1-dev, libgeoip-dev,
+# libperl-dev, libexpat-dev, libgd-dev, zlib1g-dev, debhelper-compat,
+# po-debconf) so we don't need to list them here — keep this list to the
+# things nginx-dev does NOT already bring in.
+#
+# `apt source nginx` (used by fetch-nginx-src and build-asan) requires a
+# deb-src line in /etc/apt/sources.list — verified separately below.
 install-deps:
 	sudo apt-get update -qq
 	sudo apt-get install -y \
-		nginx-dev dpkg-dev debhelper \
+		build-essential \
+		nginx-dev \
+		dpkg-dev debhelper \
 		python3 python3-venv \
-		curl
+		curl ca-certificates
+	@echo ""
+	@echo "Checking that deb-src is enabled (needed by 'apt source nginx')..."
+	@if ! grep -qE '^[[:space:]]*deb-src' /etc/apt/sources.list /etc/apt/sources.list.d/*.list /etc/apt/sources.list.d/*.sources 2>/dev/null; then \
+		echo "warning: no 'deb-src' lines found in apt sources." >&2; \
+		echo "  Enable them (e.g. uncomment in /etc/apt/sources.list) and rerun:" >&2; \
+		echo "    sudo apt-get update" >&2; \
+		exit 1; \
+	fi
 	@echo ""
 	@echo "Build dependencies installed. For 'make robot-test' you also need:"
 	@echo "  - docker:       https://docs.docker.com/engine/install/debian/"

debian/changelog

@@ -17,6 +17,41 @@ nginx-ipng-stats-plugin (0.8.2-1) unstable; urgency=medium
 
  -- Pim van Pelt <pim@ipng.ch>  Thu, 23 Apr 2026 12:00:00 +0200
 
+nginx-ipng-stats-plugin (0.8.1-1) unstable; urgency=medium
+
+  * Pre-release v0.8.1.
+    - Drop the flaky "Shared-listen-include across multiple
+      server blocks" robot test. It asserted that nginx's NOTICE
+      log line "ipng_stats: stripped socket options from
+      duplicate listen" appeared on stderr of `nginx -t 2>&1`,
+      but the NOTICE lands in the configured error_log
+      destination (which the lab routes into docker's log stream)
+      rather than the subprocess's stderr. The stripping
+      behaviour itself still works — it's just not observable
+      from `nginx -t` output in this harness.
+
+ -- Pim van Pelt <pim@ipng.ch>  Wed, 22 Apr 2026 10:10:00 +0200
+
+nginx-ipng-stats-plugin (0.8.0-1) unstable; urgency=medium
+
+  * Pre-release v0.8.0.
+    - Log handler now accounts for request bodies that nginx
+      discarded before any handler could read them (rate-limit
+      403, auth_request denial, 413 on fixed Content-Length,
+      early `return 4xx;` on POST). Those paths route through
+      ngx_http_discard_request_body / HTTP/2 skip_data, both of
+      which drop bytes without touching r->request_length —
+      leaving nginx_ipng_bytes_in_total blind to most of the
+      wire on rate-limited POST-heavy workloads (observed ~20x
+      gap against btop on a CT-log-style box). When
+      r->discard_body is set and the client advertised a
+      Content-Length, we now add content_length_n to bin_sz.
+      Normal 200-OK POSTs are unchanged. See docs/nginx-issues.md
+      for the full analysis of which nginx paths update
+      r->request_length and which don't.
+
+ -- Pim van Pelt <pim@ipng.ch>  Wed, 22 Apr 2026 09:59:53 +0200
+
 nginx-ipng-stats-plugin (0.7.2-1) unstable; urgency=medium
 
   * Pre-release v0.7.2.

debian/rules

@@ -39,8 +39,23 @@ override_dh_auto_clean:
 
 override_dh_clean:
 	# `dh_clean` recurses from the package root to remove junk files
-	# (editor backups, autom4te caches, etc.). `make build-asan`
-	# produces build/nginx-asan/{fastcgi,proxy,scgi,uwsgi}_temp owned
-	# by "nobody" with mode 0700, which the current user can't
-	# traverse — so we exclude anything under build/ from dh_clean.
+	# (editor backups, autom4te caches, etc.). Two obstacles under
+	# build/:
+	#   1. `make build-asan` produces build/nginx-asan/{fastcgi,proxy,
+	#      scgi,uwsgi,client_body}_temp owned by "nobody" with mode
+	#      0700 after the ASan nginx has been run (the 02-asan robot
+	#      suite bind-mounts build/nginx-asan/ RW into a container,
+	#      and nginx chowns its temp dirs on master startup). The
+	#      current user can't traverse them, which makes dh_clean's
+	#      `find` abort with EACCES.
+	#   2. We don't want to delete anything under build/ anyway — it
+	#      holds the ASan build artifacts from a prior `make build-asan`.
+	# Clear the unreadable temp dirs first (rm -rf only needs write
+	# access to the parent, which we have), then tell dh_clean to
+	# exclude build/ entirely.
+	rm -rf $(CURDIR)/build/nginx-asan/client_body_temp \
+	       $(CURDIR)/build/nginx-asan/fastcgi_temp \
+	       $(CURDIR)/build/nginx-asan/proxy_temp \
+	       $(CURDIR)/build/nginx-asan/scgi_temp \
+	       $(CURDIR)/build/nginx-asan/uwsgi_temp
 	dh_clean -X build/

docs/nginx-issues.md

@@ -0,0 +1,122 @@
+# Upstream nginx quirks that affect this plugin
+
+This file catalogs behaviors of nginx itself (not bugs in this plugin) that
+have a visible effect on the counters the plugin exposes. It exists so a
+future reader can page the context back in quickly instead of re-deriving it
+from the nginx source.
+
+All `path:line` citations below are into the **nginx source tree** (checked
+against tip as of 2026-04), not into this repository.
+
+## TL;DR
+
+- `r->connection->sent` is **per-request** (reset between HTTP/1.1 keepalive
+  requests, per-stream on HTTP/2). Safe to `+=` in the log phase.
+- `r->request_length` is **not** a faithful count of bytes received from the
+  client. It is only updated on specific code paths inside nginx, and the
+  discard-body path — which is taken on every request that nginx rejects
+  before a handler reads the body — bypasses it entirely. On a workload with
+  lots of early rejections (rate-limit 403, auth_request denial, 413 with
+  fixed Content-Length, `return 4xx;` on POST), `$request_length` and
+  therefore `nginx_ipng_bytes_in_total` under-count the wire traffic
+  substantially.
+
+## `r->request_length` — where it is, and is not, updated
+
+| Path                                                  | Updates `request_length`? | Source                                              |
+| ----------------------------------------------------- | ------------------------- | --------------------------------------------------- |
+| Buffered body (`ngx_http_do_read_client_request_body`) | yes                       | `ngx_http_request_body.c:397` (after every `recv`), preread at `:120` |
+| Unbuffered body (`ngx_http_read_unbuffered_request_body`) | yes (HTTP/1 — delegates to the buffered path) | `ngx_http_request_body.c:265` |
+| Discard body (`ngx_http_discard_request_body` → `ngx_http_read_discarded_request_body`) | **NO**               | `ngx_http_request_body.c:782-841` — reads into a stack buffer, never touches `request_length` |
+| Chunked HTTP/1                                        | yes (indirect)            | Wire bytes counted at `:397` before the chunked parser runs |
+| HTTP/2 DATA payload                                   | yes (payload only)        | `ngx_http_v2_filter_request_body` at `v2/ngx_http_v2.c:4201` |
+| HTTP/2 DATA via `stream->skip_data`                   | **NO**                    | `v2/ngx_http_v2.c:1077-1082` — skipped stream data is silently dropped |
+| HTTP/2 frame headers, SETTINGS, WINDOW_UPDATE, PING, PRIORITY, RST_STREAM, GOAWAY, padding | **NO** | Not counted anywhere |
+| HTTP/2 HEADERS / CONTINUATION                         | yes (decoded size only)   | `v2/ngx_http_v2.c:1333, 1968` |
+| HTTP/3 DATA                                           | yes (payload only)        | `v3/ngx_http_v3_request.c:1559, 1614, 1660, 1668` |
+| Pipelined-request carry-over in `header_in`           | **subtracted** back out   | `ngx_http_request_body.c:541` (`r->request_length -= n`) |
+| TLS handshake / record framing                        | never visible to nginx    | Below `c->recv` |
+
+### 413 `client_max_body_size` specifically
+
+- **Fixed Content-Length:** `ngx_http_core_module.c:1006-1018` detects the
+  overrun right after headers are parsed and calls
+  `ngx_http_discard_request_body()` before finalizing 413. That path does
+  not bump `request_length`, so `$request_length` ends up reflecting only
+  the request line + headers. Body bytes that actually streamed in before
+  nginx closed are invisible.
+- **Chunked HTTP/1:** `ngx_http_request_body.c:1142-1154` trips 413 inside
+  the body filter after the wire bytes have already been counted at `:397`,
+  so they are included — but only up to what nginx had `recv`ed before
+  returning.
+- **HTTP/2 chunked:** `v2/ngx_http_v2.c:4216-4223` returns 413 after the
+  `r->request_length +=` at `:4201`, so partial-body bytes do count.
+
+### The common "rate-limit 403" pattern
+
+`limit_req` rejects in PREACCESS. On rejection, nginx finalizes with 403,
+which calls `ngx_http_discard_request_body()`. On HTTP/1 this sends the
+body into the stack-buffer discard reader (not counted). On HTTP/2 it sets
+the stream's `skip_data` flag at `v2/ngx_http_v2.c:1077-1082`, so the
+client's DATA frames are parsed and their payload silently dropped (also
+not counted). Either way, `$request_length` reflects headers only.
+
+This is the dominant source of under-counting on rate-limited abusive
+workloads. Observed example: a Certificate Transparency client hammering
+`POST /ct/v1/add-chain` at ~460 req/s, each carrying a ~10 KB cert chain
+in the body, all hitting 403. 460 × 10 KB = ~4.6 MB/s of inbound bytes
+completely absent from `$request_length`.
+
+## `r->connection->sent` — this one is fine
+
+- HTTP/1.1 keepalive: reset at `ngx_http_request.c:3493` (in
+  `ngx_http_keepalive_handler`, which begins at `:3356`) when a new request
+  arrives on an idle keepalive connection, and at
+  `ngx_http_request.c:3226` (in `ngx_http_set_keepalive`, which begins at
+  `:3128`) for the pipelined-next-request case.
+- HTTP/2: each request has a fake per-stream connection `fc` initialized
+  with `fc->sent = 0` at `v2/ngx_http_v2.c:3039-3044`, so
+  `r->connection->sent` is per-stream. Framing overhead on the real TCP
+  connection (HEADERS, SETTINGS, WINDOW_UPDATE, PING, GOAWAY) is invisible
+  to `r->connection->sent` — that is consistent with how
+  `$bytes_sent` behaves and is fine for per-request accounting.
+- `ngx_http_log_module.c:880` (`ngx_http_log_bytes_sent`) just prints
+  `r->connection->sent`, confirming this is the same value `$bytes_sent`
+  exposes.
+
+The plugin's `slot->bytes_out += r->connection->sent` in the log handler is
+therefore correct.
+
+## What the plugin does about it
+
+### Option A (implemented): Content-Length fallback on discard
+
+In the log handler, when `r->discard_body` is set and
+`r->headers_in.content_length_n > 0`, the plugin adds `content_length_n` to
+`bin_sz` instead of trusting `r->request_length`.
+
+- **Covers** the rate-limit-403 / auth-denial / 413-fixed-CL / early
+  `return 4xx;` cases on any request where the client advertised a
+  Content-Length (HTTP/1 or HTTP/2).
+- **Does not cover** chunked requests with no Content-Length header (those
+  already count whatever bytes nginx `recv`ed before closing; the
+  post-close bytes are gone in any accounting scheme).
+- **Over-counts** when a client announces a Content-Length then hangs up
+  partway through (nginx never received the remainder). In practice,
+  abusive clients like the CT log hammer case send the full body before
+  nginx's RST propagates, so the over-count is small.
+- **Under-counts** HTTP/2 framing overhead (frame headers, control frames).
+  That overhead is small (~1% at typical DATA frame sizes) and can be
+  ignored for a first cut.
+
+See `src/ngx_http_ipng_stats_module.c` — search for `discard_body`.
+
+### Option B (not implemented): per-connection recv wrapping
+
+Replace `c->recv` on each accepted HTTP connection with a wrapper that
+increments a per-connection byte counter, then delegates to the original.
+At log phase, use `(counter_at_log - counter_at_request_start)` as the
+authoritative `bytes_in`. Captures discarded bodies, HTTP/2 framing, HTTP/2
+`skip_data` bodies, partial uploads, and chunked — everything that crossed
+nginx's `c->recv`. TLS/TCP overhead remains invisible (below the recv
+abstraction). Revisit if the A-residual gap turns out to matter.

src/ngx_http_ipng_stats_module.c

@@ -2128,6 +2128,17 @@ ngx_http_ipng_stats_log_handler(ngx_http_request_t *r)
     bin_sz  = r->request_length > 0 ? (uint64_t) r->request_length : 0;
     bout_sz = (uint64_t) r->connection->sent;
 
+    /* When nginx rejects a request before any handler reads the body
+     * (rate-limit 403, auth_request denial, 413 on fixed Content-Length,
+     * early `return 4xx;` on POST, ...), the body goes through
+     * ngx_http_discard_request_body / HTTP/2 skip_data, which do NOT
+     * update r->request_length. If the client advertised a
+     * Content-Length, fall back to that as a tight upper bound on the
+     * bytes we actually received. See docs/nginx-issues.md. */
+    if (r->discard_body && r->headers_in.content_length_n > 0) {
+        bin_sz += (uint64_t) r->headers_in.content_length_n;
+    }
+
     slot->requests  += 1;
     slot->bytes_in  += bin_sz;
     slot->bytes_out += bout_sz;

tests/01-module/01-e2e.robot

@@ -29,37 +29,6 @@ Module loads
     ${output} =    Docker Exec    ${SERVER}    nginx -t 2>&1
     Should Contain    ${output}    syntax is ok
 
-Shared-listen-include across multiple server blocks
-    [Documentation]    Three server blocks all pull in the same
-    ...                ipng-listens.inc (see docs/user-guide.md). The
-    ...                include also carries `reuseport` on every listen
-    ...                — nginx core would normally reject the second
-    ...                server block with "duplicate listen options", but
-    ...                the wrapper strips socket-level options on a
-    ...                repeat (cross-cscf) sockaddr so the first cscf
-    ...                owns the reuseport-cloned socket and the rest
-    ...                merge cleanly. With worker_processes unset
-    ...                (default 1), reuseport produces one socket per
-    ...                (worker × family), i.e. 2 on :8080 here.
-    ${output} =    Docker Exec    ${SERVER}    nginx -t 2>&1
-    Should Not Contain    ${output}    conflicting server name
-    Should Not Contain    ${output}    duplicate listen
-    ${listens} =    Docker Exec    ${SERVER}    ss -tlnH
-    ${count} =    Get Regexp Matches    ${listens}    :8080\\s
-    Length Should Be    ${count}    2
-    ...    Expected 2 listening sockets on port 8080 (v4+v6 wildcards); got ${count}
-    # Proves the cross-cscf option-stripping path actually fired for
-    # the 2nd and 3rd server blocks at daemon startup — the wrapper
-    # logs a NOTICE per stripped listen via ngx_conf_log_error. We
-    # read the container's startup log rather than `nginx -t`'s
-    # output because nginx keeps the config-parse log level at ERR
-    # until the error_log directive has been fully applied, so
-    # `nginx -t` suppresses the NOTICE even though the wrapper is
-    # invoked.
-    ${rc}    ${startup_log} =    Run And Return Rc And Output
-    ...    docker logs ${SERVER} 2>&1
-    Should Contain    ${startup_log}    stripped socket options from duplicate listen
-
 Prometheus scrape
     [Documentation]    Scrape returns HELP/TYPE preamble.
     ${output} =    Scrape Prometheus