benchmark.sh (31478B)
1 #!/bin/bash 2 # 3 # Rough measurement of what the paivana reverse proxy costs, and of 4 # what it costs to be turned away by the paywall. 5 # 6 # Runs N parallel curl clients against a fixed-size static page for a 7 # fixed period, and reports completed requests, requests/s and MB/s. 8 # There are three things it can point them at: 9 # 10 # direct straight at the Rust upstream 11 # proxy through paivana-httpd in front of that same upstream 12 # paywall at paivana's own paywall page, with no upstream involved 13 # 14 # direct-vs-proxy is what the proxy costs, and is the number this 15 # started out to produce. paywall is the other side of paivana: the 16 # 402 page an unpaid client is sent to, which paivana renders from its 17 # template once and then serves out of its own response cache, so it 18 # measures paivana answering by itself -- the cheapest thing it does, 19 # and the one an unauthenticated client can ask for without limit. 20 # 21 # Nothing is written to disk: the upstream's page comes from a buffer 22 # built once at its startup, the paywall page from paivana's cache, and 23 # every client discards the body. The whole thing runs on loopback 24 # against one upstream process and one paivana process. 25 # 26 # Usage: benchmark.sh [-c CLIENTS] [-s SIZE] [-d SECONDS] [-m MODE] 27 # 28 # -c N parallel curl clients (default 8) 29 # -s SIZE page size in bytes; k/M suffixes accepted (default 64k). 30 # Capped at 10M, which is the largest /large/ the upstream 31 # will serve. Does not apply to paywall mode, where the 32 # page size is whatever the template renders to. 33 # -d SECS how long to run each mode for (default 10) 34 # -m MODE direct, proxy, paywall, both (= direct + proxy, the 35 # default) or all 36 # -b PORT first of the three ports used (default 18600, or 37 # $PAIVANA_BENCH_PORT_BASE) 38 # -h this help 39 # 40 # Environment: PAIVANA_HTTPD, SRCDIR, BUILDDIR and KEEP_TMP have the 41 # same meaning as in test_reverse_proxy.sh. PAIVANA_BENCH_MERCHANT_URL 42 # and PAIVANA_BENCH_MERCHANT_TOKEN point paywall mode at a real 43 # merchant backend instead of the stub (see below). 44 # 45 # Exits 77 (meson: SKIP) when a binary or a port is missing, and 1 when 46 # any request failed -- a run with failures has not measured throughput, 47 # it has measured how fast something can be refused. 48 # 49 # --------------------------------------------------------------------- 50 # Four things about the setup shape the numbers, and are printed with 51 # them so nobody has to read this file to interpret a result: 52 # 53 # * Every request gets a fresh TCP connection, in BOTH modes. Not a 54 # choice: upstream_rs answers one request per connection and closes 55 # (see its client_loop()), so the direct arm could not keep-alive 56 # even if asked. paivana's client side would, though -- MHD strips 57 # the upstream's hop-by-hop `Connection: close' and decides the 58 # client connection's fate itself -- so the clients send 59 # `Connection: close' to hold both arms to the same behaviour. 60 # Otherwise the proxy would be credited with connection reuse the 61 # thing it is being compared against cannot do. 62 # 63 # The bias this leaves is a known one: a TCP setup and teardown is 64 # charged to both arms, so it is a constant added to both sides of 65 # the ratio, which pulls the ratio toward 1. The proxy's real 66 # relative cost is therefore a little worse than what is reported, 67 # never better. The same goes for the share of each run that is 68 # curl's own process startup (see BATCH_LO below): a per-request 69 # constant present in both arms, pulling the same way. 70 # 71 # How large that share is depends on how much of the machine the 72 # clients get, which is why the same box has produced both 0.20x 73 # and 0.35x for the same configuration: under contention the 74 # fastest arm loses the most. The reported CPU is the tell -- an 75 # origin at 3 cores and one at 1.5 are not the same measurement. 76 # 77 # * paivana is single-threaded by construction -- one GNUnet scheduler 78 # driving MHD and libcurl, no threads -- while upstream_rs spawns a 79 # thread per connection. On a multi-core box the direct arm is 80 # therefore free to use every core and the proxy arm is not. That 81 # is a real property of the proxy and not an artefact, but it does 82 # mean the ratio is a function of how many cores the machine has, so 83 # CPU seconds and the core count are reported alongside. 84 # 85 # * The paywall page is not the same size as -s, so paywall mode is 86 # comparable to the other two in requests/s and not in MB/s. Its 87 # size is measured and printed rather than assumed. 88 # 89 # * MB is 10^6 bytes. 90 # 91 # On the merchant backend in paywall mode: paivana does not open its 92 # listen socket until it has fetched a template from one, so paywall 93 # mode needs a backend before it can measure anything. It starts 94 # merchant_stub, which answers the two GETs of that startup exchange 95 # and nothing else. That is not a shortcut around a real backend, it 96 # is the whole of what a real backend would do here: the template is 97 # fetched once, the page is rendered locally from it, and the rendered 98 # response is cached, so from the first measured request onwards a live 99 # merchant would be exactly as idle as the stub. Nothing in this 100 # benchmark buys anything. For anyone who would rather check that than 101 # take it: set PAIVANA_BENCH_MERCHANT_URL (and, if it wants one, 102 # PAIVANA_BENCH_MERCHANT_TOKEN) and paivana is pointed at that instead 103 # -- it needs an instance carrying a `paivana' template whose ID is 104 # `premium'. 105 # --------------------------------------------------------------------- 106 107 set -u 108 109 # EPOCHREALTIME and every printf %f below assume a '.' radix character. 110 export LC_ALL=C 111 112 CLIENTS=8 113 SIZE=65536 114 DURATION=10 115 MODE=both 116 PORT_BASE="${PAIVANA_BENCH_PORT_BASE:-18600}" 117 118 # The upstream will not serve more than this from /large/; asking for 119 # more silently gets you this much, which would then be reported as the 120 # size that was asked for. 121 SIZE_MAX=$((10 * 1024 * 1024)) 122 123 # Prints the comment block above, from the first line of prose to the 124 # `# ---' divider. Delimited rather than given as a line range: a line 125 # range silently starts printing the wrong thing the first time anyone 126 # adds a paragraph up there, and it already had. 127 function usage() { 128 awk 'NR < 3 { next } /^# -----/ { exit } { sub(/^# ?/, ""); print }' "$0" 129 exit "${1:-0}" 130 } 131 132 function die() { 133 echo "FAIL: $*" >&2 134 exit 1 135 } 136 137 function parse_size() { 138 # Accepts 4096, 64k, 2M (also 64K / 2m). 139 local s="$1" mult=1 140 141 case "$s" in 142 *k | *K) mult=1024; s="${s%[kK]}" ;; 143 *m | *M) mult=$((1024 * 1024)); s="${s%[mM]}" ;; 144 esac 145 case "$s" in 146 '' | *[!0-9]*) die "not a size: $1" ;; 147 esac 148 echo $((s * mult)) 149 } 150 151 while getopts "c:s:d:m:b:h" opt; 152 do 153 case "$opt" in 154 c) CLIENTS="$OPTARG" ;; 155 s) SIZE="$(parse_size "$OPTARG")" || exit 1 ;; 156 d) DURATION="$OPTARG" ;; 157 m) MODE="$OPTARG" ;; 158 b) PORT_BASE="$OPTARG" ;; 159 h) usage 0 ;; 160 *) usage 1 ;; 161 esac 162 done 163 164 case "$CLIENTS" in '' | *[!0-9]*) die "-c wants a count, got '$CLIENTS'" ;; esac 165 case "$DURATION" in '' | *[!0-9]*) die "-d wants seconds, got '$DURATION'" ;; esac 166 case "$PORT_BASE" in '' | *[!0-9]*) die "-b wants a port, got '$PORT_BASE'" ;; esac 167 [ "$CLIENTS" -ge 1 ] || die "-c must be at least 1" 168 [ "$DURATION" -ge 1 ] || die "-d must be at least 1" 169 [ "$SIZE" -le "$SIZE_MAX" ] || 170 die "-s is capped at $SIZE_MAX bytes; upstream_rs truncates /large/ there," \ 171 "so a larger request would be reported at a size it never served" 172 case "$MODE" in 173 direct | proxy | paywall | both | all) ;; 174 *) die "-m wants direct, proxy, paywall, both or all, got '$MODE'" ;; 175 esac 176 177 # Which arms this run consists of. `both' is direct+proxy, which is 178 # what it meant before paywall mode existed and what `make benchmark' 179 # still gets; `all' is the three. 180 DO_DIRECT=0; DO_PROXY=0; DO_PAYWALL=0 181 case "$MODE" in 182 direct) DO_DIRECT=1 ;; 183 proxy) DO_PROXY=1 ;; 184 paywall) DO_PAYWALL=1 ;; 185 both) DO_DIRECT=1; DO_PROXY=1 ;; 186 all) DO_DIRECT=1; DO_PROXY=1; DO_PAYWALL=1 ;; 187 esac 188 189 # A sanitized build measures the sanitizer. Refusing is more useful 190 # than publishing a number that is a factor of several out. 191 if [ "${PAIVANA_SANITIZED:-0}" = "1" ]; 192 then 193 echo "SKIP: this is a sanitizer build; its timings measure ASan," \ 194 "not paivana" >&2 195 exit 77 196 fi 197 198 function here() { 199 cd -- "$(dirname -- "$0")" && pwd 200 } 201 202 SRCDIR="${SRCDIR:-$(here)}" 203 BUILDDIR="${BUILDDIR:-$PWD}" 204 205 PAIVANA_HTTPD="${PAIVANA_HTTPD:-$BUILDDIR/../backend/paivana-httpd}" 206 if [ ! -x "$PAIVANA_HTTPD" ] && [ -x "$SRCDIR/../backend/paivana-httpd" ]; 207 then 208 PAIVANA_HTTPD="$SRCDIR/../backend/paivana-httpd" 209 fi 210 UPSTREAM_RS="$BUILDDIR/upstream_rs" 211 MERCHANT_STUB="$BUILDDIR/merchant_stub" 212 213 # The template ID merchant_stub serves; also the last path segment of 214 # the URL paywall mode measures, so the two have to agree. Overridable 215 # only because PAIVANA_BENCH_MERCHANT_URL points at a backend whose 216 # template is named by whoever set it up. 217 TEMPLATE_ID="${PAIVANA_BENCH_TEMPLATE_ID:-premium}" 218 219 # Set from the environment: a live merchant backend to use instead of 220 # merchant_stub. Empty means "start the stub". 221 MERCHANT_URL="${PAIVANA_BENCH_MERCHANT_URL:-}" 222 # Not a credential: it is what the stub is told to expect on the same 223 # command line. A real backend's token comes from the environment and 224 # is never written to the log or the config we generate for it. 225 MERCHANT_TOKEN="${PAIVANA_BENCH_MERCHANT_TOKEN:-secret-token:benchmark-stub}" 226 227 if [ "$DO_DIRECT" = 1 ] || [ "$DO_PROXY" = 1 ]; 228 then 229 if [ ! -x "$UPSTREAM_RS" ]; 230 then 231 echo "SKIP: upstream_rs not built (no rustc?), nothing to serve the" \ 232 "page these modes measure" >&2 233 exit 77 234 fi 235 fi 236 if [ "$MODE" != direct ] && [ ! -x "$PAIVANA_HTTPD" ]; 237 then 238 echo "SKIP: paivana-httpd not found at $PAIVANA_HTTPD" >&2 239 exit 77 240 fi 241 command -v curl >/dev/null 2>&1 || { echo "SKIP: no curl" >&2; exit 77; } 242 243 # What paywall mode needs beyond the above: something to answer 244 # paivana's startup template fetch, and the paywall template itself. 245 # The latter is generated into the build tree, so a source checkout 246 # alone does not have it -- and PAIVANA_PREFIX below stages it rather 247 # than requiring `make install', which is what test_paywall.sh does for 248 # the same reason. 249 PAYWALL_TEMPLATE="" 250 if [ "$DO_PAYWALL" = 1 ]; 251 then 252 if [ -z "$MERCHANT_URL" ] && [ ! -x "$MERCHANT_STUB" ]; 253 then 254 echo "SKIP: merchant_stub not built (no rustc?) and no" \ 255 "PAIVANA_BENCH_MERCHANT_URL, so the paywall cannot be made active" >&2 256 exit 77 257 fi 258 for cand in "$BUILDDIR/../frontend/paywall.en.must" \ 259 "$SRCDIR/../frontend/paywall.en.must"; 260 do 261 [ -r "$cand" ] && { PAYWALL_TEMPLATE="$cand"; break; } 262 done 263 if [ -z "$PAYWALL_TEMPLATE" ]; 264 then 265 echo "SKIP: the paywall template has not been built, so there is no" \ 266 "paywall page to measure" >&2 267 exit 77 268 fi 269 fi 270 271 RS_PORT=$((PORT_BASE + 1)) 272 PAIVANA_PORT=$((PORT_BASE + 2)) 273 MERCHANT_PORT=$((PORT_BASE + 3)) 274 275 SCRATCH="$(mktemp -d -t paivana-bench.XXXXXX)" 276 mkdir -p "$SCRATCH/logs" "$SCRATCH/out" 277 278 # Same reason as in test_reverse_proxy.sh: paivana would otherwise pull 279 # config.d out of the install prefix rather than the build tree. 280 BASE_CONFIG_DIR="$SCRATCH/configd" 281 mkdir -p "$BASE_CONFIG_DIR" 282 export PAIVANA_BASE_CONFIG="$BASE_CONFIG_DIR" 283 284 RS_PID="" 285 PAIVANA_PID="" 286 MERCHANT_PID="" 287 WORKERS=() 288 289 function cleanup() { 290 set +e 291 for p in "${WORKERS[@]:-}"; 292 do 293 [ -n "$p" ] && kill -KILL "$p" 2>/dev/null 294 done 295 for p in "$PAIVANA_PID" "$RS_PID" "$MERCHANT_PID"; 296 do 297 [ -n "$p" ] && kill -TERM "$p" 2>/dev/null 298 done 299 sleep 0.2 300 for p in "$PAIVANA_PID" "$RS_PID" "$MERCHANT_PID"; 301 do 302 [ -n "$p" ] && kill -KILL "$p" 2>/dev/null 303 done 304 if [ "${KEEP_TMP:-0}" = "1" ]; 305 then 306 echo "Temp files kept in $SCRATCH" >&2 307 else 308 rm -rf "$SCRATCH" 309 fi 310 } 311 trap cleanup EXIT 312 trap 'echo "FAIL: interrupted" >&2; exit 1' INT TERM 313 314 # The /dev/tcp probe runs in a subshell on purpose: a failing `exec' 315 # redirection kills a non-interactive bash outright, and 2>/dev/null 316 # does not save it. 317 function port_is_free() { 318 if ( exec 7<>"/dev/tcp/127.0.0.1/$1" ) 2>/dev/null; 319 then 320 return 1 321 fi 322 return 0 323 } 324 325 function wait_for_port() { 326 local port="$1" pid="$2" tries=50 327 328 while [ "$tries" -gt 0 ]; 329 do 330 port_is_free "$port" || return 0 331 kill -0 "$pid" 2>/dev/null || return 1 332 sleep 0.1 333 tries=$((tries - 1)) 334 done 335 return 1 336 } 337 338 PORTS_NEEDED=() 339 if [ "$DO_DIRECT" = 1 ] || [ "$DO_PROXY" = 1 ]; 340 then 341 PORTS_NEEDED+=("$RS_PORT") 342 fi 343 if [ "$MODE" != direct ]; 344 then 345 PORTS_NEEDED+=("$PAIVANA_PORT") 346 fi 347 if [ "$DO_PAYWALL" = 1 ] && [ -z "$MERCHANT_URL" ]; 348 then 349 PORTS_NEEDED+=("$MERCHANT_PORT") 350 fi 351 for p in "${PORTS_NEEDED[@]}"; 352 do 353 port_is_free "$p" && continue 354 echo "SKIP: port $p is already in use; re-run with -b pointing at a" \ 355 "free block of three (current base: $PORT_BASE)" >&2 356 exit 77 357 done 358 359 # Microseconds as an integer. ${EPOCHREALTIME} always has six decimal 360 # places, so deleting the radix character is the whole conversion, and 361 # it costs no fork -- which matters in the worker loop below, where a 362 # $(date) per iteration would be a measurable part of what is being 363 # measured. 364 function now_us() { 365 local t="${EPOCHREALTIME}" 366 echo "${t/./}" 367 } 368 369 CLK_TCK="$(getconf CLK_TCK 2>/dev/null || echo 100)" 370 371 function cpu_jiffies() { 372 local pid="$1" st 373 local -a f 374 375 if [ -z "$pid" ] || [ ! -r "/proc/$pid/stat" ]; 376 then 377 echo 0 378 return 0 379 fi 380 st="$(< "/proc/$pid/stat")" || { echo 0; return 0; } 381 # The comm field is parenthesised and may contain spaces, so it is 382 # cut off rather than counted through. What is left starts at 383 # field 3, which puts utime (14) and stime (15) at 11 and 12. 384 st="${st#*") "}" 385 # shellcheck disable=SC2206 # splitting on whitespace is the point 386 f=($st) 387 echo $(( ${f[11]:-0} + ${f[12]:-0} )) 388 } 389 390 function start_upstream() { 391 ( exec "$UPSTREAM_RS" "$RS_PORT" ) >"$SCRATCH/logs/rs.log" 2>&1 & 392 RS_PID=$! 393 wait_for_port "$RS_PORT" "$RS_PID" || 394 { tail -n 20 "$SCRATCH/logs/rs.log" >&2 395 die "upstream_rs did not come up on port $RS_PORT"; } 396 } 397 398 function start_merchant_stub() { 399 # Only when we are providing the backend ourselves; with 400 # PAIVANA_BENCH_MERCHANT_URL set there is nothing to start. 401 [ -z "$MERCHANT_URL" ] || return 0 402 ( exec "$MERCHANT_STUB" "$MERCHANT_PORT" "$MERCHANT_TOKEN" \ 403 ) >"$SCRATCH/logs/merchant.log" 2>&1 & 404 MERCHANT_PID=$! 405 MERCHANT_URL="http://127.0.0.1:$MERCHANT_PORT/" 406 wait_for_port "$MERCHANT_PORT" "$MERCHANT_PID" || 407 { tail -n 20 "$SCRATCH/logs/merchant.log" >&2 408 die "merchant_stub did not come up on port $MERCHANT_PORT"; } 409 } 410 411 # $1 = paywall (paywall on, merchant backend configured) or proxy 412 # (`-n', no paywall at all). Restarting between the two arms rather 413 # than running one daemon is deliberate: `-n' is read once at startup 414 # and decides whether the paywall check runs at all, so a single 415 # process cannot be both. 416 function start_paivana() { 417 local kind="$1" 418 local -a args=(-c "$SCRATCH/paivana.conf" -L ERROR) 419 420 { 421 echo "# Generated by benchmark.sh." 422 echo "[paivana]" 423 # Required even in paywall mode, where nothing is ever 424 # forwarded and so nothing has to be listening there. 425 echo "DESTINATION_BASE_URL = http://127.0.0.1:$RS_PORT/" 426 echo "SERVE = tcp" 427 echo "PORT = $PAIVANA_PORT" 428 echo "BASE_URL = http://localhost:$PAIVANA_PORT/" 429 echo "SECRET = paivana-benchmark" 430 if [ "$kind" = paywall ]; 431 then 432 echo "MERCHANT_BACKEND_URL = $MERCHANT_URL" 433 echo "MERCHANT_ACCESS_TOKEN = $MERCHANT_TOKEN" 434 fi 435 } > "$SCRATCH/paivana.conf" 436 # The file names a bearer token, so it is readable by us alone -- 437 # $SCRATCH is a mktemp -d, but the token can also come from the 438 # environment and pointing at a real backend must not be a way to 439 # publish its token to everyone on the machine. 440 chmod 600 "$SCRATCH/paivana.conf" 441 if [ "$kind" != paywall ]; 442 then 443 args+=(-n) 444 fi 445 ( if [ "$kind" = paywall ]; then export PAIVANA_PREFIX="$SCRATCH/prefix/"; fi 446 exec "$PAIVANA_HTTPD" "${args[@]}" ) >"$SCRATCH/logs/paivana.log" 2>&1 & 447 PAIVANA_PID=$! 448 # In paywall mode this waits out the template fetch as well: the 449 # listen socket is not bound until the backend has answered, so a 450 # port that never opens is as likely to be a merchant problem as a 451 # paivana one, which is why the log tail is printed either way. 452 wait_for_port "$PAIVANA_PORT" "$PAIVANA_PID" || 453 { tail -n 20 "$SCRATCH/logs/paivana.log" >&2 454 die "paivana-httpd did not come up on port $PAIVANA_PORT"; } 455 } 456 457 function stop_paivana() { 458 [ -n "$PAIVANA_PID" ] || return 0 459 kill -TERM "$PAIVANA_PID" 2>/dev/null 460 wait "$PAIVANA_PID" 2>/dev/null 461 PAIVANA_PID="" 462 } 463 464 # A worker hands several URLs to one curl invocation, because a fork 465 # per request would put bash's process creation into the measurement. 466 # But it only looks at the clock between invocations, so the batch size 467 # is also the granularity at which the run can stop -- and the right 468 # size cannot be computed up front: how long a batch takes depends on 469 # the per-worker request rate, which falls as -c rises and is exactly 470 # what is being measured. A size picked from the page size alone 471 # overshot a 3 s run by 7% at -c 32 and would have been far worse at 472 # -c 200. 473 # 474 # So the workers converge on it instead: start small, double while a 475 # batch comes in under BATCH_LO, halve when it exceeds BATCH_HI. That 476 # bounds the overshoot at roughly BATCH_HI no matter what -c and -s 477 # are, and costs a handful of extra invocations at the start. 478 # 479 # The bounds are set by what one curl invocation costs before it sends 480 # anything: measured at 12.5 ms on the machine this was written on, 481 # which is a lot of dynamic linking (openssl, nghttp2, brotli, zstd, 482 # ldap...). Holding a batch to at least BATCH_LO keeps that under 483 # about 6% of the batch; at a fixed batch of 8 it was 44%, and the 484 # reported rate came out at half the truth. 485 BATCH_MAX=256 486 BATCH_LO=200000 # us; below this curl's own startup is too large a share 487 BATCH_HI=600000 # us; above this the deadline granularity is too coarse 488 489 # -w goes to stderr, not stdout, for a reason that is easy to trip 490 # over: -o is a *per-URL* option, so with many URLs on one command line 491 # only the first body would be redirected and the rest would land in 492 # the middle of the statistics. %{stderr} splits the two streams 493 # instead, letting stdout be discarded wholesale. stderr is unbuffered, 494 # so a line is on disk the moment the transfer ends. 495 # 496 # -m 30 keeps a hung transfer from wedging a worker until the deadline: 497 # the loop only reaches its clock check between invocations. 498 CURL_ARGS=( 499 -s 500 -m 30 501 -H 'Connection: close' 502 -w '%{stderr}%{http_code} %{size_download} 503 ' 504 ) 505 506 function worker() { 507 local out="$1" deadline_us="$2"; shift 2 508 local t t0 dt n=8 509 510 [ "$n" -gt "$BATCH_MAX" ] && n="$BATCH_MAX" 511 while :; 512 do 513 t="${EPOCHREALTIME}"; t0="${t/./}" 514 [ "$t0" -ge "$deadline_us" ] && break 515 curl "${CURL_ARGS[@]}" "${@:1:$n}" >/dev/null 2>>"$out" 516 t="${EPOCHREALTIME}"; dt=$(( ${t/./} - t0 )) 517 if [ "$dt" -lt "$BATCH_LO" ] && [ "$n" -lt "$BATCH_MAX" ]; 518 then 519 n=$((n * 2)) 520 [ "$n" -gt "$BATCH_MAX" ] && n="$BATCH_MAX" 521 elif [ "$dt" -gt "$BATCH_HI" ] && [ "$n" -gt 1 ]; 522 then 523 n=$((n / 2)) 524 fi 525 done 526 } 527 528 # Results of the last run_mode(), for the comparison at the end. 529 R_OK=0; R_BAD=0; R_BYTES=0; R_SECS=0; R_RATE=0; R_MBPS=0; R_PAGE=0 530 531 function run_mode() { 532 # $1 = label, $2 = URL, $3 = expected status, $4.. = pids whose CPU 533 # time to account 534 local label="$1" url="$2" want_status="$3"; shift 3 535 local pids=("$@") 536 local outdir="$SCRATCH/out/$label" 537 local i start_us end_us deadline_us 538 local -a urls cpu0 cpu1 539 540 rm -rf "$outdir"; mkdir -p "$outdir" 541 542 urls=() 543 for ((i = 0; i < BATCH_MAX; i++)); 544 do 545 urls+=("$url") 546 done 547 548 # Warm up: fault in the upstream's page buffer, or render and cache 549 # the paywall page, so that neither is charged to the run. It also 550 # establishes the size every later response is checked against -- 551 # measured rather than assumed, because in paywall mode the size is 552 # whatever the template renders to and nothing here knows it up 553 # front. 554 local warm 555 warm="$(curl -s -m 30 -H 'Connection: close' -o /dev/null \ 556 -w '%{http_code} %{size_download}' "$url")" || 557 die "$label: the very first request to $url failed" 558 read -r i R_PAGE <<<"$warm" 559 [ "$i" = "$want_status" ] || 560 die "$label: $url answered $i, expected $want_status" \ 561 "-- benchmarking that would measure the wrong response" 562 [ "$R_PAGE" -gt 0 ] || 563 die "$label: $url returned an empty body; there is nothing to measure" 564 # Note the redirection rather than -o: -o is per-URL, so with two 565 # URLs it would discard one body and print the other. 566 curl -s -m 30 -H 'Connection: close' "$url" "$url" >/dev/null || 567 die "$label: the warm-up request to $url failed" 568 569 cpu0=() 570 for p in "${pids[@]}"; 571 do 572 cpu0+=("$(cpu_jiffies "$p")") 573 done 574 575 start_us="$(now_us)" 576 deadline_us=$((start_us + DURATION * 1000000)) 577 WORKERS=() 578 for ((i = 0; i < CLIENTS; i++)); 579 do 580 worker "$outdir/w$i.err" "$deadline_us" "${urls[@]}" & 581 WORKERS+=($!) 582 done 583 for p in "${WORKERS[@]}"; 584 do 585 wait "$p" 586 done 587 WORKERS=() 588 end_us="$(now_us)" 589 590 cpu1=() 591 for p in "${pids[@]}"; 592 do 593 cpu1+=("$(cpu_jiffies "$p")") 594 done 595 596 local elapsed_us=$((end_us - start_us)) 597 local stats 598 stats="$(cat "$outdir"/w*.err 2>/dev/null | 599 awk -v want="$R_PAGE" -v st="$want_status" ' 600 { 601 # A short body is as much a failure as a 502: it would 602 # otherwise be counted as a request served and its 603 # missing bytes as throughput not achieved. The status 604 # is the one the warm-up got, so in paywall mode a 402 605 # is the success case and a 200 would be the failure. 606 if (st == $1 && $2 + 0 == want) { ok++; bytes += $2 } 607 else { bad++; codes[$1]++ } 608 } 609 END { 610 brk = "" 611 for (c in codes) brk = brk " " c "=" codes[c] 612 printf "%d %d %d%s\n", ok + 0, bad + 0, bytes + 0, brk 613 }')" 614 local brk 615 read -r R_OK R_BAD R_BYTES brk <<<"$stats" 616 617 R_SECS="$(awk -v u="$elapsed_us" 'BEGIN { printf "%.2f", u / 1000000 }')" 618 # The parentheses around each ternary are load-bearing: inside a 619 # printf argument list awk reads a bare `>' as an output 620 # redirection, not as a comparison. 621 R_RATE="$(awk -v n="$R_OK" -v u="$elapsed_us" \ 622 'BEGIN { printf "%.1f", (u > 0 ? n * 1000000 / u : 0) }')" 623 # bytes per microsecond is already megabytes (10^6) per second. 624 R_MBPS="$(awk -v b="$R_BYTES" -v u="$elapsed_us" \ 625 'BEGIN { printf "%.1f", (u > 0 ? b / u : 0) }')" 626 627 echo 628 echo "$label" 629 # Per-mode rather than only in the banner: the paywall page is 630 # whatever the template renders to and is not the -s size, so a 631 # single "page:" line at the top would be wrong for one of the arms. 632 printf ' page : %s bytes, HTTP %s\n' "$R_PAGE" "$want_status" 633 printf ' requests : %s ok, %s failed%s\n' \ 634 "$R_OK" "$R_BAD" "${brk:+ ($brk)}" 635 printf ' elapsed : %s s\n' "$R_SECS" 636 printf ' requests/s : %s\n' "$R_RATE" 637 printf ' throughput : %s MB/s\n' "$R_MBPS" 638 639 local n=0 line="" 640 for p in "${pids[@]}"; 641 do 642 local d=$(( ${cpu1[$n]} - ${cpu0[$n]} )) 643 line="$line${line:+, }$(awk -v j="$d" -v hz="$CLK_TCK" -v s="$R_SECS" \ 644 -v name="${PIDNAMES[$n]}" \ 645 'BEGIN { printf "%s %.2f s (%.2f cores)", name, j / hz, 646 (s > 0 ? j / hz / s : 0) }')" 647 n=$((n + 1)) 648 done 649 printf ' server cpu : %s\n' "$line" 650 } 651 652 if [ "$DO_DIRECT" = 1 ] || [ "$DO_PROXY" = 1 ]; 653 then 654 start_upstream 655 fi 656 657 echo "paivana benchmark" 658 if [ "$DO_DIRECT" = 1 ] || [ "$DO_PROXY" = 1 ]; 659 then 660 printf ' page : %s bytes, /large/%s on upstream_rs (static, no disk)\n' \ 661 "$SIZE" "$SIZE" 662 fi 663 if [ "$DO_PAYWALL" = 1 ]; 664 then 665 printf ' paywall page : /.well-known/paivana/templates/%s, rendered once\n' \ 666 "$TEMPLATE_ID" 667 printf ' and served from paivana'"'"'s own cache; size measured below\n' 668 fi 669 printf ' clients : %s parallel curl workers, up to %s URLs per invocation,\n' \ 670 "$CLIENTS" "$BATCH_MAX" 671 printf ' one fresh connection per request in every mode\n' 672 printf ' duration : %s s per mode\n' "$DURATION" 673 printf ' machine : %s CPUs\n' "$(nproc 2>/dev/null || echo '?')" 674 675 FAILED=0 676 677 if [ "$DO_DIRECT" = 1 ]; 678 then 679 PIDNAMES=(upstream_rs) 680 run_mode "direct (curl -> upstream_rs)" \ 681 "http://127.0.0.1:$RS_PORT/large/$SIZE" 200 "$RS_PID" 682 [ "$R_PAGE" -eq "$SIZE" ] || 683 die "upstream_rs served $R_PAGE bytes where $SIZE were asked for" 684 D_RATE="$R_RATE"; D_MBPS="$R_MBPS"; D_OK="$R_OK" 685 [ "$R_BAD" -gt 0 ] && FAILED=1 686 fi 687 688 if [ "$DO_PROXY" = 1 ]; 689 then 690 start_paivana proxy 691 PIDNAMES=(paivana-httpd upstream_rs) 692 run_mode "proxy (curl -> paivana-httpd -> upstream_rs)" \ 693 "http://127.0.0.1:$PAIVANA_PORT/large/$SIZE" 200 \ 694 "$PAIVANA_PID" "$RS_PID" 695 P_RATE="$R_RATE"; P_MBPS="$R_MBPS"; P_OK="$R_OK" 696 [ "$R_BAD" -gt 0 ] && FAILED=1 697 stop_paivana 698 fi 699 700 if [ "$DO_PAYWALL" = 1 ]; 701 then 702 # paivana loads the paywall page from its installation prefix, so a 703 # build tree alone is not enough; stage the one file into a prefix 704 # of our own rather than demanding `make install'. Same trick, and 705 # the same PAIVANA_PREFIX, as test_paywall.sh. 706 mkdir -p "$SCRATCH/prefix/share/paivana/templates" 707 cp "$PAYWALL_TEMPLATE" "$SCRATCH/prefix/share/paivana/templates/" || 708 die "cannot stage $PAYWALL_TEMPLATE" 709 start_merchant_stub 710 start_paivana paywall 711 # upstream_rs is not in this path at all -- the paywall answers 712 # before anything is forwarded -- so it is not accounted, and 713 # merchant_stub is not either: it saw its two requests before the 714 # clock started and is idle from here on. If that is wrong, its 715 # log says so. 716 PIDNAMES=(paivana-httpd) 717 run_mode "paywall (curl -> paivana-httpd, no upstream)" \ 718 "http://127.0.0.1:$PAIVANA_PORT/.well-known/paivana/templates/$TEMPLATE_ID" \ 719 402 "$PAIVANA_PID" 720 # No W_MBPS: the comparison below is deliberately requests/s only, 721 # since the two arms serve pages of different sizes. 722 W_RATE="$R_RATE"; W_OK="$R_OK"; W_PAGE="$R_PAGE" 723 [ "$R_BAD" -gt 0 ] && FAILED=1 724 stop_paivana 725 fi 726 727 if [ "$DO_DIRECT" = 1 ] && [ "$DO_PROXY" = 1 ]; 728 then 729 echo 730 echo "cost of the reverse proxy" 731 awk -v dr="$D_RATE" -v pr="$P_RATE" -v dm="$D_MBPS" -v pm="$P_MBPS" ' 732 BEGIN { 733 printf "%s", " requests/s : " pr " through paivana vs " dr \ 734 " direct" 735 if (dr > 0 && pr > 0) 736 printf " -> %.2fx of direct (%.2fx slower)", pr / dr, dr / pr 737 printf "\n" 738 printf " throughput : %s vs %s MB/s\n", pm, dm 739 }' 740 echo 741 echo " Read as a rough figure for this machine, not a verdict. The" 742 echo " direct arm is free to use every core and paivana is" 743 echo " single-threaded, so the ratio depends on the core count. Both" 744 echo " arms are charged a TCP setup and a share of curl's own startup" 745 echo " per request; those are constants on both sides, so they pull the" 746 echo " ratio toward 1 and the proxy's real relative cost is a little" 747 echo " worse than shown, never better. The clients compete with the" 748 echo " servers for this machine, so on a busy one the fastest arm loses" 749 echo " the most and the ratio flatters the proxy further; the core" 750 echo " counts above are what say which of those you got. See the top" 751 echo " of this script." 752 fi 753 754 if [ "$DO_PAYWALL" = 1 ] && [ "$DO_PROXY" = 1 ]; 755 then 756 echo 757 echo "cost of the paywall, against the same paivana forwarding" 758 # Requests/s only. The two arms serve different-sized pages -- the 759 # paywall page is the template's size and the proxied one is -s -- 760 # so their MB/s are not two measurements of the same thing, and 761 # printing a ratio of them would invite exactly that reading. Both 762 # sizes are shown instead. 763 awk -v wr="$W_RATE" -v pr="$P_RATE" -v wp="$W_PAGE" -v sz="$SIZE" ' 764 BEGIN { 765 printf "%s", " requests/s : " wr " turned away at the paywall vs " \ 766 pr " forwarded" 767 if (pr > 0 && wr > 0) 768 printf " -> %.2fx", wr / pr 769 printf "\n" 770 printf " page sizes : %d bytes paywall vs %d bytes forwarded\n", wp, sz 771 }' 772 echo 773 echo " The paywall arm has no upstream in the path at all -- paivana" 774 echo " answers out of its own memory -- so the only things bounding it" 775 echo " are its single thread and the clients. Which of the two it is" 776 echo " is in the core count above: if the rate stays flat as -c rises" 777 echo " while paivana sits below 1.0 cores, the thread is spending the" 778 echo " difference waiting on the kernel and more clients will not move" 779 echo " the number. Note also that this page is the one an" 780 echo " unauthenticated client can ask for without limit -- no cookie," 781 echo " no payment -- which is what makes its rate worth knowing." 782 fi 783 784 if [ "$FAILED" -ne 0 ]; 785 then 786 echo 787 echo "FAIL: some requests did not complete; the rates above are not a" \ 788 "measurement of throughput" >&2 789 # A code of 000 is curl reporting that the transfer never happened, 790 # and by far the likeliest reason here is the client running out of 791 # ephemeral ports: one connection per request against a fixed 792 # server port means the 4-tuple is pinned for the TIME_WAIT 793 # duration, and a few runs back to back can put tens of thousands 794 # of them there. Worth saying, because it is an exhausted local 795 # port range and not anything paivana did. 796 if grep -qs '^000 ' "$SCRATCH"/out/*/w*.err; 797 then 798 echo "NOTE: transfers that never connected (000) usually mean the" \ 799 "local ephemeral port range" \ 800 "($(tr '\t' '-' < /proc/sys/net/ipv4/ip_local_port_range \ 801 2>/dev/null))" \ 802 "is full of TIME_WAIT sockets" \ 803 "($(ss -tan state time-wait 2>/dev/null | wc -l) right now)." \ 804 "Wait a minute and re-run." >&2 805 fi 806 exit 1 807 fi 808 809 if [ "${D_OK:-1}" -eq 0 ] || [ "${P_OK:-1}" -eq 0 ] || [ "${W_OK:-1}" -eq 0 ]; 810 then 811 echo 812 echo "FAIL: no request completed at all" >&2 813 exit 1 814 fi 815 816 exit 0