diff --git a/Cargo.lock b/Cargo.lock index a0255b8b..78c36da3 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -453,6 +453,7 @@ dependencies = [ "serde_json", "socket2 0.5.10", "tempfile", + "tikv-jemalloc-ctl", "tikv-jemallocator", "tokio", "tracing", @@ -4864,6 +4865,17 @@ dependencies = [ "rustc-hash", ] +[[package]] +name = "tikv-jemalloc-ctl" +version = "0.6.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "661f1f6a57b3a36dc9174a2c10f19513b4866816e13425d3e418b11cc37bc24c" +dependencies = [ + "libc", + "paste", + "tikv-jemalloc-sys", +] + [[package]] name = "tikv-jemalloc-sys" version = "0.6.1+5.3.0-1-ge13ca993e8ccb9ba9847cc330696e02839f328f7" diff --git a/bench/onthebench/README.md b/bench/onthebench/README.md index 56c462bf..a34480fd 100644 --- a/bench/onthebench/README.md +++ b/bench/onthebench/README.md @@ -101,10 +101,30 @@ part of this repository; flamegraphs default off for entrants because shipped release binaries are usually stripped (a stripped target skips the flamegraph with a warning rather than failing the run). +## Post-load decay leg (`run-decay.sh`) + +`run-decay.sh ` measures the axis the load grid +cannot see: what happens to gateway RSS *after* the load stops +(api7/aisix#968). One saturating burst of large bodies (default: c=64 for 60s, +~120 KiB legal chat-completions requests standing in for inline-base64 +multimodal payloads), then 120s of idle sampling — VmRSS/VmHWM at ~2 Hz plus +`smaps_rollup` Pss/LazyFree at ~1 Hz, because pages an allocator returns with +`MADV_FREE` stay in VmRSS until the kernel reclaims them, and the corrected +series `rss - lazyfree` is the residency an OOM limit actually enforces. +Deliberately a separate runner: the large bodies drive VmHWM far above the +baseline grid's, so sharing a process lifetime with `run-baseline.sh` would +poison `rss_hwm_kb` against every historical baseline. Knobs: +`BENCH_DECAY_CONC`, `BENCH_DECAY_BURST_S`, `BENCH_DECAY_S`, +`BENCH_DECAY_BODY_KB` (≤126: the body travels as one argv string under +Linux's 128 KiB `MAX_ARG_STRLEN`). A burst window with any failed request is +recorded, marked invalid, and produces no decay curve; a curve cut short by a +dead gateway exits nonzero like any incomplete run. + ## Output One directory per run: `results.jsonl` (one JSON object per measured window, -`kind` gateway/floor, `entrant` naming the measured target), `meta.json`, the +`kind` gateway/floor — or decay_anchor/decay_burst/decay/decay_summary from +the decay runner, `entrant` naming the measured target), `meta.json`, the generated config files, and the gateway/mock logs. `flamegraph-c128.svg` is present when Inferno rendering succeeded; on a rendering failure the run keeps `perf.data` instead, so the SVG can be produced off-rig. diff --git a/bench/onthebench/lib.sh b/bench/onthebench/lib.sh index f28f7f50..f2a28f5f 100644 --- a/bench/onthebench/lib.sh +++ b/bench/onthebench/lib.sh @@ -348,6 +348,131 @@ run_point() { # run_point HARNESS_RC=1; } } +# ---- decay leg --------------------------------------------------------------- + +# Post-load RSS decay (api7/aisix#968): one saturating burst of large bodies, +# then sample the idle process's memory for a fixed window. VmRSS alone cannot +# answer "did the allocator hand the pages back" — pages released with +# MADV_FREE stay resident until the kernel reclaims them, so a pure VmRSS +# curve reads "already reclaimable" as "never returned". Every 1s sample +# therefore also reads smaps_rollup's Pss and LazyFree; rss_kb - lazyfree_kb +# is the residency that memory pressure cannot take back for free — the +# OOM-relevant series. smaps_rollup walks the VMA list (~ms per read), which +# is why it must never run inside a measured load window; the decay phase is +# idle by definition, so there it costs nothing. + +status_mem_kb() { # status_mem_kb -> "rss_kb hwm_kb" (or "null null") + awk '/^VmRSS:/{r=$2} /^VmHWM:/{h=$2} + END{print (r==""?"null":r), (h==""?"null":h)}' \ + "/proc/$1/status" 2>/dev/null || echo "null null" +} + +smaps_mem_kb() { # smaps_mem_kb -> "pss_kb lazyfree_kb" (or "null null") + # LazyFree missing but Pss present is an old kernel without the field, + # not a read failure: report 0, the corrected series then equals VmRSS. + awk '/^Pss:/{p=$2} /^LazyFree:/{l=$2} + END{if (p=="") print "null null"; else print p, (l==""?0:l)}' \ + "/proc/$1/smaps_rollup" 2>/dev/null || echo "null null" +} + +decay_leg() { # decay_leg (0-delay mock + gateway up) + local conc="$1" burst_s="$2" decay_s="$3" + local rssfile="$OUT/.rss-decay.$$" line rss0 hwm0 pss0 lz0 rss_peak + local rps fail ok p50 p99 rigref budget spawn valid t_end t_now t_s + local rss hwm pss lz i corrected delta gw_birth + + echo "== decay leg (c=$conc, burst=${burst_s}s, decay=${decay_s}s, body=${#BODY}B) ==" >&2 + + read -r rss0 hwm0 <<<"$(status_mem_kb "$GW_PID")" + read -r pss0 lz0 <<<"$(smaps_mem_kb "$GW_PID")" + # starttime (field 22 of /proc//stat) pins the pid to this incarnation: + # over a 120s idle window a dead gateway's pid can be reused, and /proc + # existence alone would then sample a stranger. + gw_birth=$(awk '{print $22}' "/proc/$GW_PID/stat" 2>/dev/null || echo "") + printf '{"kind":"decay_anchor","entrant":"%s","conc":%s,"burst_s":%s,"decay_s":%s,"body_bytes":%s,"rss_kb":%s,"hwm_kb":%s,"pss_kb":%s,"lazyfree_kb":%s}\n' \ + "$ENTRANT_NAME" "$conc" "$burst_s" "$decay_s" "${#BODY}" "$rss0" "$hwm0" "$pss0" "$lz0" >> "$RESULTS" + + # The burst, with the same peak-RSS sampler and validity policy as + # measured_window. An invalid burst (any failed request) is recorded and + # marked but produces no decay curve: a refusal or a 413 means the heap + # was never driven to the state the curve would claim to describe. + ( max=0; while [ -d "/proc/$GW_PID" ]; do + v=$(awk '/VmRSS/{print $2}' "/proc/$GW_PID/status" 2>/dev/null || true) + v="${v:-0}" + if [ "$v" -gt "$max" ]; then max="$v"; echo "$max" > "$rssfile"; fi + sleep 0.2 + done ) & SAMPLER_PID=$! + line=$(loadgen "127.0.0.1:$GW_PORT" "$conc" "$burst_s") || line="" + line=${line//[\"\\]/ } + t_end=$(date +%s.%N) + kill "$SAMPLER_PID" 2>/dev/null || true; wait "$SAMPLER_PID" 2>/dev/null || true; SAMPLER_PID="" + rss_peak=$(cat "$rssfile" 2>/dev/null || echo 0); rm -f "$rssfile" + + rps=$(field rps "$line"); fail=$(field fail "$line"); ok=$(field ok "$line") + p50=$(field p50us "$line"); p99=$(field p99us "$line") + rigref=$(field rigrefused "$line"); budget=$(field budgetexceeded "$line"); spawn=$(field spawnfailed "$line") + valid=true + [ "${fail:-1}" = "0" ] && [ "${rigref:-0}" = "0" ] && [ "${budget:-0}" = "0" ] \ + && [ "${spawn:-0}" = "0" ] || valid=false + printf '{"kind":"decay_burst","entrant":"%s","conc":%s,"burst_s":%s,"valid":%s,"rps":%s,"fail":%s,"ok":%s,"p50_us":%s,"p99_us":%s,"gw_rss_peak_kb":%s,"otb_line":"%s"}\n' \ + "$ENTRANT_NAME" "$conc" "$burst_s" "$valid" "${rps:-null}" "${fail:-null}" "${ok:-null}" \ + "${p50:-null}" "${p99:-null}" "$rss_peak" "$line" >> "$RESULTS" + echo " [burst] rps=$rps fail=$fail peak=${rss_peak}kB valid=$valid" >&2 + if [ "$valid" != true ]; then + echo "WARNING: burst window invalid - no decay curve from this run" >&2 + HARNESS_RC=1 + return 0 + fi + + # Idle sampling. Timestamps are measured against the burst's end rather + # than accumulated from sleeps, so a slow smaps read cannot silently + # stretch the curve. Status (VmRSS/VmHWM) at ~2 Hz, smaps_rollup at ~1 Hz. + i=0 + while :; do + t_now=$(date +%s.%N) + t_s=$(awk -v a="$t_end" -v b="$t_now" 'BEGIN{printf "%.1f", b-a}') + awk -v t="$t_s" -v d="$decay_s" 'BEGIN{exit !(t >= d)}' && break + if [ ! -d "/proc/$GW_PID" ]; then + echo "WARNING: gateway died ${t_s}s into the ${decay_s}s decay window - curve incomplete" >&2 + HARNESS_RC=1 + return 0 + fi + read -r rss hwm <<<"$(status_mem_kb "$GW_PID")" + if [ $((i % 2)) -eq 0 ]; then + read -r pss lz <<<"$(smaps_mem_kb "$GW_PID")" + else + pss=null; lz=null + fi + printf '{"kind":"decay","entrant":"%s","t_s":%s,"rss_kb":%s,"hwm_kb":%s,"pss_kb":%s,"lazyfree_kb":%s}\n' \ + "$ENTRANT_NAME" "$t_s" "$rss" "$hwm" "$pss" "$lz" >> "$RESULTS" + i=$((i + 1)) + sleep 0.5 + done + + # One final full sample is the gate input: corrected residency and its + # distance from the corrected pre-burst anchor (same LazyFree correction + # on both sides, so an anchor that itself holds lazily-freed pages cannot + # understate the residual). + if [ "$(awk '{print $22}' "/proc/$GW_PID/stat" 2>/dev/null || echo x)" != "$gw_birth" ]; then + echo "WARNING: gateway died or its pid was reused during the decay window - no summary" >&2 + HARNESS_RC=1 + return 0 + fi + read -r rss hwm <<<"$(status_mem_kb "$GW_PID")" + read -r pss lz <<<"$(smaps_mem_kb "$GW_PID")" + corrected=null; delta=null + if [ "$rss" != null ] && [ "$lz" != null ]; then + corrected=$((rss - lz)) + if [ "$rss0" != null ] && [ "$lz0" != null ]; then + delta=$((corrected - (rss0 - lz0))) + fi + fi + printf '{"kind":"decay_summary","entrant":"%s","conc":%s,"burst_s":%s,"decay_s":%s,"rss_idle_kb":%s,"pre_rss_kb":%s,"burst_peak_kb":%s,"final_rss_kb":%s,"final_hwm_kb":%s,"final_pss_kb":%s,"final_lazyfree_kb":%s,"final_corrected_kb":%s,"residual_vs_idle_kb":%s}\n' \ + "$ENTRANT_NAME" "$conc" "$burst_s" "$decay_s" "${RSS_IDLE:-null}" "$rss0" "$rss_peak" \ + "$rss" "$hwm" "$pss" "$lz" "$corrected" "$delta" >> "$RESULTS" + echo " [decay] idle=${RSS_IDLE:-?}kB pre=${rss0}kB peak=${rss_peak}kB final=${rss}kB lazyfree=${lz}kB corrected=${corrected}kB residual_vs_idle=${delta}kB" >&2 +} + # ---- grid helpers ------------------------------------------------------------ grid_ttfts() { # distinct delay tiers, in grid order diff --git a/bench/onthebench/run-decay.sh b/bench/onthebench/run-decay.sh new file mode 100755 index 00000000..60244f39 --- /dev/null +++ b/bench/onthebench/run-decay.sh @@ -0,0 +1,152 @@ +#!/usr/bin/env bash +# Post-load RSS decay runner (api7/aisix#968): after a burst of large-payload +# traffic stops, does the gateway hand freed pages back to the OS, or does +# RSS ratchet at the burst peak? One saturating burst of BENCH_DECAY_BODY_KB +# bodies, then BENCH_DECAY_S seconds of idle sampling (VmRSS/VmHWM at ~2 Hz, +# smaps_rollup Pss/LazyFree at ~1 Hz), all appended to results.jsonl by +# decay_leg in lib.sh. +# +# Deliberately a separate runner rather than a run-baseline.sh tier: the large +# bodies drive VmHWM far above anything the baseline grid produces, and a +# shared process lifetime would poison meta.json's rss_hwm_kb against every +# historical baseline. This runner gets a fresh gateway, its own idle anchor, +# and its own meta.json. +# +# Usage: run-decay.sh +set -euo pipefail + +SRC="${1:?usage: run-decay.sh }" +OUT="${2:?usage: run-decay.sh }" + +DECAY_CONC="${BENCH_DECAY_CONC:-64}" +DECAY_BURST_S="${BENCH_DECAY_BURST_S:-60}" +DECAY_S="${BENCH_DECAY_S:-120}" +DECAY_BODY_KB="${BENCH_DECAY_BODY_KB:-120}" + +# Same refuse-don't-collect policy as the lib.sh knobs: nonsense must fail +# here, not after a gateway is up. Indirect expansion, not word-splitting a +# name:value list — a value with embedded whitespace ("64 128") must be +# refused, not leak into the JSONL as non-numeric fields. The body cap is a +# transport limit, not a taste choice: the body travels to otb as one argv +# string and Linux MAX_ARG_STRLEN is 128 KiB, so MB-scale bodies need an +# @file mode in otb first (out of scope for #968; 126 leaves room for the +# JSON envelope). +for _k in DECAY_CONC DECAY_BURST_S DECAY_S DECAY_BODY_KB; do + [[ "${!_k}" =~ ^[1-9][0-9]*$ ]] || + { echo "FATAL: BENCH_$_k must be a positive integer, got '${!_k}'"; exit 1; } +done +[ "$DECAY_BODY_KB" -le 126 ] || + { echo "FATAL: BENCH_DECAY_BODY_KB must be <= 126 (argv transport limit), got '$DECAY_BODY_KB'"; exit 1; } + +# A legal chat-completions request padded to ~BODY_KB, standing in for an +# inline-base64 multimodal payload — the traffic shape the issue names as the +# ratchet driver. Set before sourcing lib.sh so readiness probes, the burst, +# and meta all see the same body. +BODY=$(python3 -c 'import json, sys +pad = "x" * (int(sys.argv[1]) * 1024) +print(json.dumps({"model": "gpt-4o-mini", + "messages": [{"role": "user", "content": pad}], + "max_tokens": 16}))' "$DECAY_BODY_KB") + +ENTRANT_NAME=aisix +# shellcheck source=lib.sh +source "$(dirname "${BASH_SOURCE[0]}")/lib.sh" + +BIN="$SRC/target/release/aisix" + +# ---- sanity ----------------------------------------------------------------- + +[ -x "$BIN" ] || { echo "FATAL: $BIN missing - build first"; exit 1; } +rig_sanity + +bench_init + +# ---- config: same default-shipped-config claim set as run-baseline.sh ------- + +cat > "$OUT/config.yaml" < "$OUT/resources.yaml" <&2 + # aisix reads AISIX_* environment variables as config overrides; nothing + # from the harness environment may leak into the measured process. + while read -r v; do unset "$v"; done < <(compgen -v | grep '^AISIX_' || true) + BENCH_AISIX_KEY=bench-token taskset -c "$GW_CORES" "$BIN" --config "$OUT/config.yaml" \ + > "$OUT/gateway.log" 2>&1 & + GW_PID=$! + # Readiness posts $BODY, so a gateway that cannot carry the large payload + # end to end fails here, before anything is measured. + wait_http_200 "http://127.0.0.1:$GW_PORT$REQ_PATH" "gateway" + assert_listener "$GW_PORT" "$GW_PID" "gateway" + sleep 3 + RSS_IDLE=$(rss_kb "$GW_PID") + TPC_WORKERS=$(ps -T -p "$GW_PID" | grep -c 'tpc-' || true) + echo " pid=$GW_PID idle_rss=${RSS_IDLE}kB tpc_workers=$TPC_WORKERS" >&2 + local gw_nproc + gw_nproc=$(taskset -c "$GW_CORES" nproc) + [ "$TPC_WORKERS" -eq "$gw_nproc" ] || + { echo "FATAL: expected $gw_nproc tpc- workers under the $GW_CORES affinity, got $TPC_WORKERS"; exit 1; } +} + +write_meta() { + cat > "$OUT/meta.json" <&2 +echo "== done: $OUT ==" >&2 +exit "$HARNESS_RC" diff --git a/crates/aisix-server/Cargo.toml b/crates/aisix-server/Cargo.toml index fb7d48fc..c1f10950 100644 --- a/crates/aisix-server/Cargo.toml +++ b/crates/aisix-server/Cargo.toml @@ -60,8 +60,13 @@ hyper-util = { version = "0.1", features = ["server-auto", "tokio"] } # bench (Linux glibc — the Docker image and both supported production # arches). Other targets (macOS dev builds, musl) keep the system # allocator rather than carry an allocator we never run in production. +# The ctl crate exists for one runtime mallctl at startup (enable the +# background purge thread, #968); it drags in the unmaintained `paste` +# proc-macro (RUSTSEC-2024-0436, build-time only) — accepted until +# jemalloc-ctl drops it upstream. [target.'cfg(all(target_os = "linux", target_env = "gnu"))'.dependencies] tikv-jemallocator = "0.6" +tikv-jemalloc-ctl = "0.6" [dev-dependencies] tempfile = "3" diff --git a/crates/aisix-server/src/main.rs b/crates/aisix-server/src/main.rs index 37394f92..5dc08c30 100644 --- a/crates/aisix-server/src/main.rs +++ b/crates/aisix-server/src/main.rs @@ -28,6 +28,38 @@ use std::sync::Arc; #[global_allocator] static GLOBAL: tikv_jemallocator::Jemalloc = tikv_jemallocator::Jemalloc; +// jemalloc parks freed pages as "dirty" and only advances their decay clock +// on later allocator activity in the same arena, so after a burst of +// large-payload traffic an idle gateway keeps its peak RSS indefinitely +// (#968: a 60s burst of ~120KiB bodies left +38MB resident, flat, on an +// otherwise idle process). The background purge thread decouples purging +// from traffic. Enabled via runtime mallctl on purpose: the equivalent +// `opt.background_thread` startup path carries an upstream warning that it +// "may cause crash or deadlock during initialization". Failure is never +// fatal — foreground decay still bounds RSS under load; only idle-time +// reclamation is lost, which the warning makes visible. +#[cfg(all(target_os = "linux", target_env = "gnu"))] +fn enable_jemalloc_background_thread() -> Result { + use tikv_jemalloc_ctl::background_thread; + // Write-then-read-back: the write is a request, the read is the fact. + // The outcome is returned so the unit test exercises this function + // itself — a broken body must fail the test, not stay silently green. + let outcome = background_thread::write(true).and_then(|()| background_thread::read()); + match &outcome { + Ok(true) => tracing::info!("jemalloc background purge thread enabled"), + Ok(false) => tracing::warn!( + "jemalloc background purge thread did not enable on this target; \ + freed memory will not return to the OS while the process is idle" + ), + Err(e) => tracing::warn!( + error = %e, + "failed to enable jemalloc background purge thread; freed memory \ + will not return to the OS while the process is idle" + ), + } + outcome +} + mod cert_bundle; mod export; mod heartbeat; @@ -188,6 +220,11 @@ async fn async_main(cfg: Config) -> anyhow::Result<()> { let _otlp = install_otlp_tracer(&cfg.observability) .map_err(|e| anyhow::anyhow!("otlp init failed: {e}"))?; + // After tracing so the enable outcome is observable in the logs; the + // returned outcome is already logged inside. + #[cfg(all(target_os = "linux", target_env = "gnu"))] + let _ = enable_jemalloc_background_thread(); + // Before any bridge builds its `reqwest::Client` — the connection // pools are constructed once and can't be reconfigured afterwards. aisix_gateway::upstream_http::init(upstream_http_config(&cfg.upstream)?) @@ -1888,6 +1925,20 @@ mod tests { use super::*; use clap::Parser; + // The shipped-target contract: the runtime mallctl enable must actually + // take effect here — an Ok(false) read-back would mean the #968 fix + // silently does nothing. Drives the delivered function, not an inline + // re-implementation of the mallctl pair; the test binary links the same + // #[global_allocator] as the shipped one. + #[cfg(all(target_os = "linux", target_env = "gnu"))] + #[test] + fn jemalloc_background_thread_enables_at_runtime() { + assert!( + matches!(enable_jemalloc_background_thread(), Ok(true)), + "background_thread did not enable on a linux-gnu target" + ); + } + #[tokio::test(start_paused = true)] async fn metrics_upkeep_runs_periodically_and_stops_on_cancel() { use std::sync::atomic::{AtomicUsize, Ordering};