test: record authenticated soak measurements

This commit is contained in:
SimpleTest 2026-07-19 19:08:16 +03:00
parent 4c6f757e84
commit b5a5aba202
4 changed files with 356 additions and 1 deletions

2
.gitignore vendored
View File

@ -38,6 +38,8 @@ npm-debug.log
/assets/node_modules/
/e2e/node_modules/
/.tools/
__pycache__/
*.py[cod]
# Local environment files can contain deployment credentials. Keep only the
# documented template in Git.

View File

@ -37,6 +37,16 @@ independent PostgreSQL and application secrets. Edit its `LOAD_*` inputs to
define a specific experiment. Values in `.env.load.example` are reproducible
measurement points, not recommendations.
For a one-run duration that must not rewrite `.env.load`, pass an explicit
experiment override:
```sh
LOAD_DURATION_OVERRIDE=10m ./scripts/load-run.sh local-soak-YYYYMMDD
```
The effective value and whether it came from `.env.load` or the override are
recorded in that run's `environment.txt`.
## Run and compare replica counts
```sh
@ -52,7 +62,9 @@ Each run writes ignored evidence below `output/performance/<label>/`:
- the exact inputs and Docker host observation;
- a machine-readable k6 summary and complete console report;
- periodic Docker CPU/memory/network/block-I/O/PID samples for every load
stack container;
stack container, plus a threshold-free CPU/RAM/PID JSON summary;
- read-only PostgreSQL database size and `pg_stat_database` snapshots before
and after k6, plus their machine-readable counter deltas;
- before/after application table counts, exact authenticated-write evidence,
fixture cleanup output, and a cleanup diff;
- final Compose state, readiness response, application logs, and cross-node
@ -173,6 +185,67 @@ Ignored evidence:
- `output/performance/final-load-20260719a/`
## Observed 10-minute authenticated soak
Observed on 2026-07-19 with the same 3-web/2-worker topology and the same
40 public HTTP, 40 five-second Phoenix heartbeat, and 8 authenticated
mutual-aid VUs. The duration came from the recorded
`LOAD_DURATION_OVERRIDE=10m`; it is an experiment input, not a recommended
soak duration or capacity target.
| Observation | Result |
| --- | ---: |
| Completed / interrupted iterations | 271,072 / 0 |
| Public checks | 703,995 / 703,995 passed |
| HTTP requests / failures | 767,225 / 0 |
| HTTP duration average / p95 / maximum | 2.34 / 5.71 / 175.96 ms |
| Phoenix heartbeat opened / replies | 4,800 / 4,800 |
| Authenticated logins | 8 |
| Authenticated pages / LiveView joins | 31,607 / 31,607 |
| Tracking starts / position writes / stops | 31,607 / 31,607 / 31,607 |
| Private messages written | 31,607 |
| Authenticated or WebSocket errors | 0 |
The database evidence counted exactly those 31,607 messages, tracking
sessions, and samples, plus 8 login tokens and zero current positions after
explicit stop. Its read-only `pg_stat_database` delta recorded 2,921,283
commits, zero rollbacks, 12 block reads, 33,967,340 block hits, zero temporary
files/bytes, zero deadlocks, and zero conflicts. Database size increased by
16,678,912 bytes during the write workload. The physical database size was
recorded but was not treated as a cleanup assertion; the post-cleanup count
diff across all tracked application tables was empty. The five-node PubSub
probe passed. All seven measured app/database/proxy containers remained
running, had zero observed restarts, and were not OOM-killed. The 75,058,636
byte run-scoped log had zero matches for the recorded error, warning,
exception, crash, HTTP 4xx/5xx, and deadlock search.
Each container has 199 sequential resource samples. No container resource
limit or pass/fail resource threshold was applied.
| Container | Average / max CPU | First 10 / last 10 memory average | Max memory |
| --- | ---: | ---: | ---: |
| PostgreSQL | 61.44% / 85.30% | 236.15 / 261.81 MiB | 263.60 MiB |
| Traefik | 57.25% / 73.14% | 93.44 / 103.98 MiB | 108.50 MiB |
| web 16 | 198.67% / 281.58% | 264.24 / 376.33 MiB | 397.10 MiB |
| web 17 | 195.66% / 247.46% | 259.30 / 373.79 MiB | 406.10 MiB |
| web 18 | 195.36% / 266.74% | 265.06 / 388.06 MiB | 410.80 MiB |
| worker 10 | 1.47% / 5.09% | 201.63 / 202.64 MiB | 203.80 MiB |
| worker 11 | 2.21% / 5.56% | 199.30 / 201.05 MiB | 201.80 MiB |
The web RSS increased across most of the loaded interval, so this run does
not establish a steady-state memory plateau. A separate read-only observation
at 2026-07-19T16:06:21Z, 5 minutes 23 seconds after the k6 summary timestamp,
measured web RSS at 278.2, 269.8, and 285.6 MiB. At that point the BEAM runtime
reported 142,250,344, 147,808,440, and 147,403,872 total bytes with 613, 612,
and 612 processes. This observed post-load reduction shows that a substantial
part of the loaded RSS was released after the connections closed; it does not
prove that the application is free of a longer-term memory leak. A
production-like duration and traffic distribution remain unknown.
Ignored evidence:
- `output/performance/authenticated-soak-10m-20260719/`
## Observed local resilience drills
The canonical Compose drill on 2026-07-19 used the isolated 3-web/2-worker

View File

@ -4,7 +4,9 @@ set -euo pipefail
ROOT=$(CDPATH='' cd -- "$(dirname -- "$0")/.." && pwd)
ENV_FILE="$ROOT/.env.load"
K6_IMAGE="grafana/k6@sha256:65c920dc067d5e2e00befbf982af6ad6ad0117034e8b1c65817c7975c52d4669"
PYTHON_IMAGE="python:3.14.6-alpine3.23@sha256:b165067c5afc37fa5608a3c05609cc3d51aafd808a30fbfd822ee594fef55ad4"
LABEL=${1:-"run-$(date -u +%Y%m%dT%H%M%SZ)"}
duration_override=${LOAD_DURATION_OVERRIDE:-}
if [[ ! -f "$ENV_FILE" ]]; then
echo "Missing $ENV_FILE. Run scripts/ensure-local-load-env.sh first." >&2
@ -16,6 +18,12 @@ set -a
. "$ENV_FILE"
set +a
duration_source=".env.load"
if [[ -n "$duration_override" ]]; then
LOAD_DURATION=$duration_override
duration_source="LOAD_DURATION_OVERRIDE"
fi
for name in LOAD_PROJECT LOAD_HOST LOAD_WEB_REPLICAS LOAD_WORKER_REPLICAS \
LOAD_HTTP_VUS LOAD_WS_VUS \
LOAD_DURATION LOAD_WS_HOLD_MS LOAD_WS_CONNECT_TIMEOUT_MS \
@ -56,12 +64,18 @@ compose=(
)
mapfile -t web_containers < <("${compose[@]}" ps -q web)
mapfile -t worker_containers < <("${compose[@]}" ps -q worker)
if [[ "${#web_containers[@]}" -ne "$LOAD_WEB_REPLICAS" ]]; then
echo "Expected $LOAD_WEB_REPLICAS running web replicas; observed ${#web_containers[@]}." >&2
exit 1
fi
if [[ "${#worker_containers[@]}" -ne "$LOAD_WORKER_REPLICAS" ]]; then
echo "Expected $LOAD_WORKER_REPLICAS running worker replicas; observed ${#worker_containers[@]}." >&2
exit 1
fi
network_id=$(
docker network ls \
--filter "label=com.docker.compose.project=$LOAD_PROJECT" \
@ -144,6 +158,94 @@ COMMIT;
SQL
}
snapshot_database_metrics() {
local destination=$1
# The variables below are intentionally expanded inside the database container.
# shellcheck disable=SC2016
"${compose[@]}" exec -T db sh -c \
'psql --no-psqlrc --quiet --tuples-only --no-align --set ON_ERROR_STOP=1 \
--username "$POSTGRES_USER" --dbname "$POSTGRES_DB"' \
>"$destination" <<'SQL'
BEGIN READ ONLY;
SELECT json_build_object(
'captured_at', clock_timestamp(),
'database_size_bytes', pg_database_size(current_database()),
'stats_reset', stats_reset,
'numbackends', numbackends,
'xact_commit', xact_commit,
'xact_rollback', xact_rollback,
'blks_read', blks_read,
'blks_hit', blks_hit,
'tup_returned', tup_returned,
'tup_fetched', tup_fetched,
'tup_inserted', tup_inserted,
'tup_updated', tup_updated,
'tup_deleted', tup_deleted,
'temp_files', temp_files,
'temp_bytes', temp_bytes,
'deadlocks', deadlocks,
'conflicts', conflicts
)
FROM pg_stat_database
WHERE datname = current_database();
COMMIT;
SQL
}
summarize_database_metrics() {
local before=$1
local after=$2
local destination=$3
jq -n \
--slurpfile before "$before" \
--slurpfile after "$after" '
def counters:
[
"database_size_bytes",
"xact_commit",
"xact_rollback",
"blks_read",
"blks_hit",
"tup_returned",
"tup_fetched",
"tup_inserted",
"tup_updated",
"tup_deleted",
"temp_files",
"temp_bytes",
"deadlocks",
"conflicts"
];
($before[0]) as $before |
($after[0]) as $after |
{
schema_version: 1,
measurement: "read-only pg_stat_database snapshots around the k6 run",
thresholds_applied: false,
stats_reset_before: $before.stats_reset,
stats_reset_after: $after.stats_reset,
before: $before,
after: $after,
delta: reduce counters[] as $key
({}; .[$key] = ($after[$key] - $before[$key]))
}
' >"$destination"
}
summarize_resources() {
docker run --rm \
--user "$(id -u):$(id -g)" \
--volume "$ROOT/scripts/summarize-docker-stats.py:/scripts/summarize-docker-stats.py:ro" \
--volume "$output_dir:/output" \
"$PYTHON_IMAGE" \
python /scripts/summarize-docker-stats.py \
/output/docker-stats.jsonl \
/output/resource-summary.json
}
run_fixture_tool() {
local action=$1
@ -256,11 +358,14 @@ trap cleanup_on_exit EXIT HUP INT TERM
{
printf 'observed_at=%s\n' "$run_started_at"
printf 'k6_image=%s\n' "$K6_IMAGE"
printf 'resource_summarizer_image=%s\n' "$PYTHON_IMAGE"
printf 'load_project=%s\n' "$LOAD_PROJECT"
printf 'web_replicas=%s\n' "$LOAD_WEB_REPLICAS"
printf 'worker_replicas=%s\n' "$LOAD_WORKER_REPLICAS"
printf 'http_vus=%s\n' "$LOAD_HTTP_VUS"
printf 'websocket_vus=%s\n' "$LOAD_WS_VUS"
printf 'duration=%s\n' "$LOAD_DURATION"
printf 'duration_source=%s\n' "$duration_source"
printf 'websocket_hold_ms=%s\n' "$LOAD_WS_HOLD_MS"
printf 'websocket_connect_timeout_ms=%s\n' "$LOAD_WS_CONNECT_TIMEOUT_MS"
printf 'http_think_seconds=%s\n' "$LOAD_HTTP_THINK_SECONDS"
@ -277,6 +382,7 @@ snapshot_database "$output_dir/database-pre-fixtures.txt"
run_fixture_tool prepare >"$output_dir/fixture-prepare.log" 2>&1
fixtures_prepared=true
snapshot_database "$output_dir/database-before-load.txt"
snapshot_database_metrics "$output_dir/database-metrics-before-load.json"
sample_resources &
sampler_pid=$!
@ -312,8 +418,14 @@ set -e
cleanup_sampler
sampler_pid=
summarize_resources
snapshot_database "$output_dir/database-after-load.txt"
snapshot_database_metrics "$output_dir/database-metrics-after-load.json"
summarize_database_metrics \
"$output_dir/database-metrics-before-load.json" \
"$output_dir/database-metrics-after-load.json" \
"$output_dir/database-metrics-summary.json"
diff -u "$output_dir/database-before-load.txt" "$output_dir/database-after-load.txt" \
>"$output_dir/database-load-diff.txt" || true
validate_authenticated_writes
@ -364,6 +476,7 @@ fi
run_fixture_tool cleanup >"$output_dir/fixture-cleanup.log" 2>&1
fixtures_prepared=false
snapshot_database "$output_dir/database-after-cleanup.txt"
snapshot_database_metrics "$output_dir/database-metrics-after-cleanup.json"
if ! diff -u "$output_dir/database-pre-fixtures.txt" \
"$output_dir/database-after-cleanup.txt" >"$output_dir/database-cleanup-diff.txt"; then

View File

@ -0,0 +1,167 @@
#!/usr/bin/env python3
"""Summarize Docker's machine-readable stats without applying pass/fail limits."""
from __future__ import annotations
import argparse
import json
import re
from collections import defaultdict
from decimal import Decimal
from pathlib import Path
from statistics import fmean
UNIT_BYTES = {
"B": Decimal(1),
"kB": Decimal(1_000),
"MB": Decimal(1_000_000),
"GB": Decimal(1_000_000_000),
"TB": Decimal(1_000_000_000_000),
"KiB": Decimal(1_024),
"MiB": Decimal(1_048_576),
"GiB": Decimal(1_073_741_824),
"TiB": Decimal(1_099_511_627_776),
}
def parse_size(value: str) -> int:
match = re.fullmatch(r"([0-9]+(?:\.[0-9]+)?)\s*([A-Za-z]+)", value.strip())
if match is None:
raise ValueError(f"invalid Docker size value: {value}")
number, unit = match.groups()
try:
multiplier = UNIT_BYTES[unit]
except KeyError as error:
raise ValueError(f"unsupported Docker size unit: {unit}") from error
return int(Decimal(number) * multiplier)
def parse_memory_usage(value: str) -> int:
used, separator, _limit = value.partition("/")
if not separator:
raise ValueError(f"invalid Docker MemUsage value: {value}")
return parse_size(used)
def parse_cpu(value: str) -> float:
if not value.endswith("%"):
raise ValueError(f"invalid Docker CPUPerc value: {value}")
return float(value.removesuffix("%"))
def summarize(source: Path) -> dict[str, object]:
samples: dict[str, list[dict[str, object]]] = defaultdict(list)
observed_at: list[str] = []
with source.open(encoding="utf-8") as stream:
for line_number, line in enumerate(stream, start=1):
if not line.strip():
continue
try:
row = json.loads(line)
name = str(row["Name"])
timestamp = str(row["ObservedAt"])
samples[name].append(
{
"observed_at": timestamp,
"cpu_percent": parse_cpu(str(row["CPUPerc"])),
"memory_bytes": parse_memory_usage(str(row["MemUsage"])),
"pids": int(row["PIDs"]),
}
)
observed_at.append(timestamp)
except (KeyError, TypeError, ValueError, json.JSONDecodeError) as error:
raise ValueError(f"{source}:{line_number}: {error}") from error
if not samples:
raise ValueError(f"{source}: no Docker stats samples")
containers: list[dict[str, object]] = []
for name in sorted(samples):
rows = samples[name]
cpu_values = [float(row["cpu_percent"]) for row in rows]
memory_values = [int(row["memory_bytes"]) for row in rows]
pid_values = [int(row["pids"]) for row in rows]
window_size = min(10, len(rows))
window_count = min(10, len(rows))
memory_windows: list[dict[str, object]] = []
for window_index in range(window_count):
start = window_index * len(rows) // window_count
end = (window_index + 1) * len(rows) // window_count
window_rows = rows[start:end]
window_memory = [int(row["memory_bytes"]) for row in window_rows]
memory_windows.append(
{
"index": window_index + 1,
"sample_count": len(window_rows),
"first_observed_at": str(window_rows[0]["observed_at"]),
"last_observed_at": str(window_rows[-1]["observed_at"]),
"average": fmean(window_memory),
"minimum": min(window_memory),
"maximum": max(window_memory),
"first": window_memory[0],
"last": window_memory[-1],
}
)
containers.append(
{
"name": name,
"sample_count": len(rows),
"cpu_percent": {
"average": fmean(cpu_values),
"minimum": min(cpu_values),
"maximum": max(cpu_values),
},
"memory_bytes": {
"average": fmean(memory_values),
"minimum": min(memory_values),
"maximum": max(memory_values),
"first": memory_values[0],
"last": memory_values[-1],
"first_ten_average": fmean(memory_values[:window_size]),
"last_ten_average": fmean(memory_values[-window_size:]),
"first_to_last_delta": memory_values[-1] - memory_values[0],
"sequential_windows": memory_windows,
},
"pids": {
"minimum": min(pid_values),
"maximum": max(pid_values),
"first": pid_values[0],
"last": pid_values[-1],
},
}
)
return {
"schema_version": 2,
"measurement": (
"docker stats --no-stream; the sampler sleeps one second after "
"each complete multi-container collection"
),
"thresholds_applied": False,
"first_observed_at": min(observed_at),
"last_observed_at": max(observed_at),
"containers": containers,
}
def main() -> None:
parser = argparse.ArgumentParser()
parser.add_argument("source", type=Path)
parser.add_argument("destination", type=Path)
args = parser.parse_args()
summary = summarize(args.source)
args.destination.write_text(
json.dumps(summary, indent=2, sort_keys=True) + "\n",
encoding="utf-8",
)
if __name__ == "__main__":
main()