From 72f8d08a3cae8165c9099360f2c1afa0a9c44d16 Mon Sep 17 00:00:00 2001 From: zveinn Date: Mon, 24 Aug 2026 14:53:53 +0000 Subject: [PATCH 1/2] fix scale and correctness defects, add TX(avg) and a per-host breakdown hperf was unreliable above a few dozen hosts, and several reported numbers were wrong in ways nothing surfaced. This fixes the defects, adds the average throughput column, and puts gates in CI so the concurrency work stays fixed. Crashes and leaks - test.cons was written by two goroutines while a third iterated and deleted from it. That is an unrecoverable runtime throw, not a catchable panic, and it killed the server: reproduced 2 of 4 servers dead within 2 client attach cycles. cons is now guarded, with the locking contract written out above the test struct. 38,400 attach cycles, no deaths. - The *websocket.Conn handed to a handler by gofiber/contrib is a pooled wrapper; releaseConn nils its embedded conn and returns it for the next upgrade to claim. Tests outlive their client by design, so a stored wrapper later wrote into an unrelated client's socket. New wsPeer holds the inner non-pooled conn, serializes writes, and applies a write deadline. - Non-200 responses never closed resp.Body, so each failed request burned a connection, an fd and two net/http goroutines - up to (hosts-1) x concurrency of them in one test. - streamTestFilesToWebsocket opened files in a loop with no Close: one leaked fd per file per download, for the server's lifetime. - Finished tests kept a PayloadSize buffer and an http.Client per peer alive forever (~63 MB per run at 64 hosts). Memory fiber ReadBufferSize/WriteBufferSize were 1 MB. They are allocated per concurrent connection, and a full mesh opens (hosts-1) x concurrency of them. Measured 1000 KB of RSS per inbound connection; now 64 KiB buffers and 85-99 KB per connection. In containers, peak RSS per server fell from 84-88 MiB to 36-39 MiB on 8 nodes. Silent data loss - resetTestFiles globbed id+"*" instead of id+".*", so starting "--id test" deleted test2.1 and testing.1. Verified against real files. - parseConfig's TestID switch covered "http" and "get", which match no command, and omitted "requests" - so `hperf requests` ran with an empty TestID and that glob then matched and deleted every saved test. - analyze discarded every error point: the prefix test was on b[1:], always '{', and the unmarshal included the prefix byte. download then analyze reported zero errors on a file full of them. - Client-supplied test IDs are validated before becoming a filename. Read and delete paths check containment instead, so files written by older servers stay accessible. - Sort comparators returned 1 for equal elements, violating slices.SortFunc's ordering contract, so two analyses of one file could disagree. Wrong numbers - The live table had no aggregate and no average: TX(high)/TX(low) were the extremes of per-flow per-second rates over all history, so TX(low) pinned to the ramp-up sample and never recovered (measured a 31x spread against TX(high) on 8 nodes). Renamed TX(max)/TX(min), semantics unchanged, and added TX(avg) over the same population so min <= avg <= max reads coherently. A per-host table now prints at the end of a run, slowest first, so one lagging node is visible instead of averaged away. - #Dropped summed since-boot RECEIVE drops across every interface including lo, ignoring transmit drops - the ones that matter for a saturating sender. It is now a per-test delta of RX+TX on the interface carrying the test, with -1 for "no usable counter", which is distinct from zero. - A sampling window under 100 ms is skipped rather than divided out; the final flush landed microseconds after the last sample and its rate became TX(max), inflating it 3-6x. - The live tick rescanned the whole accumulated slice every second while reading it without the lock that guards appends. Aggregation is now incremental and O(1) per data point. - A TX column of width 10 could not fit BWToString's 11 characters, shifting every later column at GB/s scale. Run completion - One unreachable host aborted the entire run. It now proceeds with the reachable subset and names the exclusions loudly, because a silently smaller mesh is the failure this tool exists to detect. - The readiness channel was reused by the reconnect path and eventually blocked forever before the read loop, dropping a host from the results with nothing left to notice. - hostsDoingWork was incremented only for hosts that connected but decremented for every reader goroutine, so with half the hosts down the counter hit zero and a 300s run exited successfully after one second having saved nothing. - A reconnecting socket now re-announces itself, so it is re-attached to the running test instead of waiting for a Done that would never arrive. - The websocket dial had no timeout at all, so reconnecting to an address that black-holes packets hung until the kernel gave up. - keepAliveLoop's grace period scales with duration instead of a flat 20s. - A run that collects nothing, and a download that returns nothing, now exit non-zero instead of reporting success. Also - --concurrency 0 built a zero-capacity semaphore with no tokens and hung forever; the computed fallback was discarded. - requests advertised --concurrency/--payload-size/--buffer-size/ --request-delay and silently overwrote all four. - Deleted cmd/hperf/stream.go: never registered in Commands, so unreachable. - helm latency-job read .Values.bandwidth.printAll/.micro, which breaks a latency-only deploy. Chart bumped to 5.2.0 for the template change. - .golangci.yml was pinned to golangci-lint 1.20.0 with four since-removed linters, so the documented lint gate had never run. Migrated to v2; it immediately found an unclosed handshake response body and three unused near-full copies of the data set in analyzeLatencyTest. - CI now lints, tests with -race, and repeats the concurrency tests at GOMAXPROCS 1 and 4. - README: three example commands passed flags their command does not register and could never have run; --insecure was documented as defaulting to false when it is a BoolT defaulting to true; percentile analysis was claimed for bandwidth tests, which produce none. Flag table now says which commands accept what, and list/delete are documented. Tests go from 9 functions to 33, covering each defect above. Verified end to end on a 4- and 8-node podman mesh: reported bytes match container NIC counters to within 0.5-0.9%, and a killed or flapping host no longer stalls or fails a run. --- .github/workflows/go.yml | 17 +- .github/workflows/release.yml | 2 +- .golangci.yml | 57 +- CLAUDE.md | 46 +- README.md | 141 +++- client/aggregate.go | 267 +++++++ client/aggregate_test.go | 402 +++++++++++ client/client.go | 660 ++++++++++++------ client/table.go | 85 ++- cmd/hperf/latency.go | 19 +- cmd/hperf/main.go | 40 +- cmd/hperf/requests.go | 15 - cmd/hperf/stream.go | 76 -- helm/hperf/Chart.yaml | 4 +- helm/hperf/templates/latency-job.yaml | 4 +- helm/hperf/values.yaml | 2 +- server/file.go | 109 ++- server/regress_test.go | 506 ++++++++++++++ server/server.go | 957 ++++++++++++++++++-------- shared/shared.go | 97 ++- shared/sorting.go | 18 +- 21 files changed, 2751 insertions(+), 773 deletions(-) create mode 100644 client/aggregate.go create mode 100644 client/aggregate_test.go delete mode 100644 cmd/hperf/stream.go create mode 100644 server/regress_test.go diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index ef5fc4b..0d478f4 100644 --- a/.github/workflows/go.yml +++ b/.github/workflows/go.yml @@ -31,6 +31,21 @@ jobs: - name: Vet run: go vet ./... shell: bash + - name: Lint + uses: golangci/golangci-lint-action@v6 + with: + version: latest + args: --timeout 5m - name: Test - run: go test -race ./... + run: go test -race -count 1 -timeout 10m ./... + shell: bash + # The concurrency fixes are the kind that pass once and fail on the tenth + # run, and single-proc scheduling exposes different interleavings. + - name: Test concurrency repeatedly + run: | + for procs in 1 4; do + GOMAXPROCS=$procs go test -race -count 10 -timeout 15m \ + -run 'RaceFree|Concurrent|Ingest|Reclaim|Duplicate|Releases' \ + ./server/... ./client/... + done shell: bash diff --git a/.github/workflows/release.yml b/.github/workflows/release.yml index 61b2d96..f5fd238 100644 --- a/.github/workflows/release.yml +++ b/.github/workflows/release.yml @@ -25,7 +25,7 @@ jobs: go-version: ${{ matrix.go-version }} check-latest: true - name: Test - run: go test ./... + run: go test -race -count 1 -timeout 10m ./... shell: bash - name: Release uses: goreleaser/goreleaser-action@v6 diff --git a/.golangci.yml b/.golangci.yml index 891e90f..2fdc656 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -1,27 +1,44 @@ -linters-settings: - golint: - min-confidence: 0 - - misspell: - locale: US +# Migrated to the v2 schema. The previous config was pinned to +# golangci-lint 1.20.0 and enabled deadcode, structcheck, golint and gosimple, +# all of which have since been removed or folded into other linters -- so +# `golangci-lint run` failed outright on any current release and the lint gate +# documented in CLAUDE.md was never actually running. +version: "2" linters: - disable-all: true + default: none enable: - - typecheck - - goimports - - misspell - govet - - golint - ineffassign - - gosimple - - deadcode - - structcheck + - misspell + - staticcheck + - unused + # Unchecked writes and closes are how the descriptor and connection leaks + # in this codebase stayed invisible. + - bodyclose + - errorlint + - unconvert + - usestdlibvars + + settings: + misspell: + locale: US + + exclusions: + presets: + - comments + rules: + # hperf's error strings are capitalized throughout and surface directly + # in the CLI output; that is a deliberate house style, not a defect. + - text: "error strings should not be capitalized" + linters: + - staticcheck + +formatters: + enable: + - gofmt + - goimports issues: - exclude-use-default: false - exclude: - - should have a package comment - - error strings should not be capitalized or end with punctuation or a newline -service: - golangci-lint-version: 1.20.0 # use the fixed version to not introduce new linters unexpectedly + max-issues-per-linter: 0 + max-same-issues: 0 diff --git a/CLAUDE.md b/CLAUDE.md index 0a34fc3..ab788a8 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -20,13 +20,20 @@ go install github.com/minio/hperf/cmd/hperf@latest ### Run tests ```bash -go test ./... +go test -race ./... ``` +CI runs the suite with `-race`, and runs the concurrency tests repeatedly at +`GOMAXPROCS=1` and `4`, because the locking bugs in this codebase pass a single +clean run and fail the tenth. ### Lint ```bash golangci-lint run ``` +`.golangci.yml` uses the v2 schema. It was previously pinned to golangci-lint +1.20.0 and enabled linters that no longer exist, so this command failed outright +and the gate never ran - if it starts erroring on a config version again, that is +what happened. ### Build Docker image ```bash @@ -59,8 +66,12 @@ docker build -t hperf:latest . ### Test Types -- **RequestTest** (latency command): Sends fixed-size HTTP PUT requests with configurable delay between requests. Measures TTFB (Time To First Byte), RMS (Round-trip time), and tracks per-request latency -- **StreamTest** (bandwidth command): Sends continuous HTTP streams with configurable concurrency. Measures throughput (TX bytes/sec) with multiple concurrent connections +- **RequestTest** (`latency` and `requests` commands): Sends fixed-size HTTP PUT requests with configurable delay between requests. Measures TTFB (Time To First Byte), RMS (Round-trip time), and tracks per-request latency. `latency` is a fixed probe (payload 1000, concurrency 1, 200 ms delay) and does not register those flags; `requests` registers them and honours them. Both share `runLatency` +- **StreamTest** (`bandwidth` command): Sends continuous HTTP streams with configurable concurrency. Measures throughput (TX bytes/sec) with multiple concurrent connections. Payload and buffer are pinned to 32000, so only `--concurrency` is tunable + +Note a stream request never completes - it ends only when the test is cancelled - +so anything derived from request completion (RMS, and a completion-based request +count) is meaningless for a bandwidth test. ### Critical Implementation Details @@ -68,22 +79,32 @@ docker build -t hperf:latest . **Address handling**: All host entries pass through `shared.NormalizeHost` in `ParseHosts`, which strips brackets and canonicalizes IP literals, so one spelling reaches the wire, the self filters and the output. Use `shared.URLHostPort` when building a URL (it percent-encodes an IPv6 zone as RFC 6874 requires), `shared.HostOnly` to drop a port for display, and `shared.SameHost` to compare hosts - never substring matching, which used to make `--real-ip 10.0.0.1` swallow the peer `10.0.0.10`. The server binds with `fiber.NetworkTCP`, so a wildcard bind is dual-stack. -**Data persistence**: Test results are saved to `--storage-path` (default: current directory + `/hperf-tests/`). Each data point is JSON with a prefix byte (0=DataPoint, 1=ErrorPoint) followed by newline. Files are named by test ID. +**Data persistence**: Test results are saved to `--storage-path` (default: current directory + `/hperf-tests/`). Each data point is JSON with a prefix byte (0=DataPoint, 1=ErrorPoint) followed by newline. Files are named `.`. Test IDs are validated by `shared.ValidateTestID` before touching the filesystem: they are a filename component supplied by whichever client asked for the test, so an unvalidated ID could escape `--storage-path`, and an empty one made the cleanup glob match every saved test. Globs that select a test's files must be anchored with the separator (`id + ".*"`, never `id + "*"`). + +**Server locking contract**: written out above `type test` in server/server.go and worth reading before touching that file. In short: `testLock` guards only the package-level `tests` slice; `t.M` guards `errors`, `errMap`, `DPS` and `cons`; `t.endedAt` carries liveness so callers can test it without `t.M`; `netPerfReader.m` guards only the TTFB/RMS watermarks and `hasStats` is atomic. The three locks are never held together, iterators snapshot under one lock and then work unlocked, and no blocking work (socket write, disk write, print) happens under `t.M` — `AddError` takes `t.M`, so persisting under it would deadlock as well as stall. + +**Websocket peers**: never retain the `*websocket.Conn` that gofiber hands a handler. gofiber/contrib pools that wrapper and nils its embedded conn when the handler returns, so a stored wrapper later writes into an unrelated client's socket. Wrap it in `wsPeer` (server/server.go), which holds the inner non-pooled `fasthttp/websocket.Conn`, serializes writes on its own leaf mutex, and applies a write deadline so a stalled client cannot stall the test. Control frames deliberately bypass that mutex. + +**Per-connection memory**: `fiber.Config.ReadBufferSize`/`WriteBufferSize` are allocated per concurrent connection, not once. A full mesh opens `(hosts-1) x concurrency` inbound connections per server, so these constants multiply by thousands — they are 64 KiB (`serverReadBufferSize`), measured at ~90 KiB RSS per connection. The only hard floor is that the largest inbound request header must fit or fasthttp answers 431; `--payload-size` is a body size and is streamed, never buffered whole. + +**Concurrency model**: Each server maintains a semaphore channel per remote host (`concurrency chan int`) limiting concurrent requests. Workers pull from this channel, send requests, then return the slot (`startPerformanceReader`/`sendRequestToHost`). The channel starts full, so any direct call to `sendRequestToHost` must take a slot first or its deferred return blocks. Every response body is drained and closed on all paths — net/http cannot release a connection whose body is still open. + +**Stats collection**: `pollHostStats` publishes an immutable `hostStats` snapshot through an `atomic.Pointer`, so `generateDataPoints` reads memory, CPU and drop counters without locking and without a nil dereference before the first poll. `cpu.Percent` blocks for a second by design, which is why it lives on its own goroutine. -**Concurrency model**: Each server maintains a semaphore channel per remote host (`concurrency chan int`) limiting concurrent requests. Workers pull from this channel, send requests, then return the slot (server/server.go:700-723). +**Dropped packets**: reported as a delta since the test started, covering receive *and* transmit drops, scoped to the interface resolved from `--real-ip`. `-1` means no usable counter, which is distinct from zero. The transmit column is the one that matters for a saturating sender. -**Stats collection**: Separate goroutine collects system stats (memory, CPU, dropped packets from `/proc/net/dev`) every second (server/server.go:260-287). Stats are locked with mutexes when updating high/low watermarks. +**Throughput reporting**: the client aggregates incrementally in `client/aggregate.go`, updated per incoming data point under `responseLock` and read once per tick — never by rescanning the accumulated slice. `TX(max)`, `TX(min)` and `TX(avg)` summarize one population (per-flow, per-second rates), so `min <= avg <= max` holds. A single flow is ~1/(hosts-1) of a host's aggregate; that is the definition, not a bug, and it is why comparing `TX(max)` to a NIC counter mismatches by roughly the host count. `generateDataPoints` divides bytes by the *measured* elapsed window, so a slow sampling loop reduces the number of samples but does not bias the rate. ## Key Configuration Parameters - `--hosts`: Supports ellipsis patterns (`10.10.1.{2...10}`), comma-separated lists, or file input (`file:/path/to/hosts`) -- `--id`: Test identifier for start/stop/listen/download operations. Auto-generated from Unix timestamp if not provided +- `--id`: Test identifier for start/stop/listen/download operations. Auto-generated from Unix timestamp if not provided (for `bandwidth`, `latency` and `requests`). Letters, digits, `-`, `_` and `.` only, max 64 characters; validated server-side before it becomes a filename - `--port`: Server port (default: 9010) -- `--concurrency`: Concurrent requests per host (default: 2 × GOMAXPROCS) +- `--concurrency`: Concurrent requests per host (default: 2 × GOMAXPROCS). Registered on `bandwidth` and `requests` only - `--duration`: Test duration in seconds (default: 30) -- `--buffer-size`: Network buffer size in bytes (default: 32000) -- `--payload-size`: HTTP payload size in bytes (default: 1000000) -- `--request-delay`: Delay between requests in milliseconds (default: 0) +- `--buffer-size`: Network buffer size in bytes (default: 32000). Registered on `requests` only +- `--payload-size`: HTTP payload size in bytes (default: 1000000). Registered on `requests` only +- `--request-delay`: Delay between requests in milliseconds (default: 0). Registered on `requests` only - `--save`: Save test results on server for later retrieval (default: true) - `--ip-family`: Address family used when resolving hostnames in `--hosts`: `auto`, `4` or `6` (default: auto) - `--dns-server`: Resolve hostnames in `--hosts` through this DNS server @@ -96,7 +117,8 @@ docker build -t hperf:latest . - System metrics: shirou/gopsutil for CPU/memory stats - UI: charmbracelet/lipgloss for terminal styling - The codebase filters servers from testing themselves: see `filterSelf` in client/client.go and `isSelfHost` in server/server.go +- `httpServer` in server/server.go is a package-level `fiber.New` singleton, so only one server can run per process. That is why there is no in-process multi-server test; end-to-end mesh testing needs separate processes or containers ## Helm Deployment -Helm chart located in `helm/hperf/` for Kubernetes deployments. Current version: 5.0.6. Includes StatefulSet, Service, ServiceAccount, and Job templates for bandwidth/latency tests. +Helm chart located in `helm/hperf/` for Kubernetes deployments. Current version: 5.2.0. Includes StatefulSet, Service, ServiceAccount, and Job templates for bandwidth/latency tests. The chart version must be bumped whenever a template changes, per the note in `Chart.yaml`. diff --git a/README.md b/README.md index edcebcc..60d4dd2 100644 --- a/README.md +++ b/README.md @@ -147,24 +147,52 @@ specific DNS server: During test execution, hperf displays aggregated statistics across all servers: -| Metric | Description | -|------------------|--------------------------------------------------------| -| `#ERR` | Total error count across all servers | -| `#TX` | Total HTTP requests made across all servers | -| `TX(high/low)` | Highest and lowest transfer rate (single server) | -| `RMS(high/low)` | Longest and fastest round-trip latency (single server) | -| `TTFB(high/low)` | Slowest and fastest time-to-first-byte (single server) | -| `#Dropped` | Highest count of dropped packets (single server) | -| `Mem(high/low)` | Highest and lowest memory usage (single server) | -| `CPU(high/low)` | Highest and lowest CPU usage (single server) | +| Metric | Description | +|------------------|-----------------------------------------------------------------| +| `#ERR` | Total error count across all servers | +| `#TX` | Total HTTP requests completed across all servers | +| `TX(max/min)` | Highest and lowest transfer rate of any single flow | +| `TX(avg)` | Mean transfer rate across every flow, over the same population | +| `TX(total)` | Total bytes transferred by the whole mesh | +| `RMS(high/low)` | Longest and fastest round-trip latency (single server) | +| `TTFB(high/low)` | Slowest and fastest time-to-first-byte (single server) | +| `#Dropped` | Packets dropped during this test, or `-1` if unavailable | +| `Mem(high/low)` | Highest and lowest memory usage (single server) | +| `CPU(high/low)` | Highest and lowest CPU usage (single server) | + +A "flow" is one server's traffic to one peer, sampled once a second. `TX(max)`, +`TX(min)` and `TX(avg)` summarize that same population, so `TX(min)` <= +`TX(avg)` <= `TX(max)` always holds. None of the three is the aggregate +throughput of a host or of the cluster: in a full mesh of N hosts each host +carries N-1 flows, so a single flow's rate is roughly 1/(N-1) of what one host's +NIC counters will show. Use `TX(total)` over the test duration, or the per-host +table below, when comparing against `ethtool` or switch counters. + +`#Dropped` counts receive plus transmit drops on the interface carrying the +test, measured from the moment the test started. It is `-1` when no counter +could be read, which is not the same as zero. On Linux the interface is derived +from `--real-ip`, falling back to summing every non-loopback interface. + +### Per-Host Throughput + +When a test finishes, hperf prints one row per host with that host's average, +slowest and fastest flow rates, sorted slowest first, so a single lagging node +is visible instead of being averaged away. Hosts averaging under half the +fleet-wide average are highlighted. ### Post-Test Analysis -After a test completes, hperf automatically analyzes results and displays percentile breakdowns: +Latency tests (`latency` and `requests`) analyze their results automatically when +they finish, and `analyze` reproduces the same breakdown from a saved file: - **P99 data points**: Shows the worst 1% of measurements - critical for understanding tail latency - **Percentile statistics**: P10, P50, P90, P99 breakdowns showing count, sum, min, average, and max values -- Results can be sorted by any metric using `--sort` flag (e.g., `--sort RMSH` for worst round-trip times) +- Sort with `--sort RMSH` (round-trip, the default) or `--sort TTFBH` (time to + first byte). Those are the only two sort keys + +Bandwidth tests do not produce a percentile breakdown; use the live table, the +per-host table above, and `--print-all` or `analyze --print-stats` for the +individual data points. ## Advanced Workflows @@ -184,6 +212,15 @@ Multiple clients can monitor the same test simultaneously. ./hperf stop --hosts 10.10.10.{2...10} --id latency-test-1 ``` +#### List and Delete Saved Tests +```bash +# What is stored on the servers +./hperf list --hosts 10.10.10.{2...10} + +# Remove one test, or every test when --id is omitted +./hperf delete --hosts 10.10.10.{2...10} --id latency-test-1 +``` + ### Analyzing Historical Results #### Download Test Results @@ -213,9 +250,11 @@ This creates `latency-test-1.json.csv` with all data points for analysis in spre ### Test Examples #### High-Frequency Latency Test -Useful for detecting intermittent network issues: +Useful for detecting intermittent network issues. Use `requests` rather than +`latency` when you want to control the request shape - `latency` is a fixed +probe and does not accept these flags: ```bash -./hperf latency --hosts file:./hosts --port 6000 --duration 300 \ +./hperf requests --hosts file:./hosts --port 6000 --duration 300 \ --concurrency 1 --request-delay 50 --buffer-size 1000 --payload-size 1000 ``` @@ -223,13 +262,17 @@ Useful for detecting intermittent network issues: Push the network to its limits: ```bash ./hperf bandwidth --hosts file:./hosts --port 6000 --duration 60 \ - --concurrency 16 --payload-size 10000000 + --concurrency 16 ``` +`bandwidth` deliberately fixes its payload and buffer at 32000 bytes, so +concurrency is the only knob it exposes. + #### Custom Payload Optimization -Find optimal buffer/payload sizes for your workload: +Find optimal buffer/payload sizes for your workload. This is what `requests` +is for: ```bash -./hperf bandwidth --hosts file:./hosts --port 6000 --duration 30 \ +./hperf requests --hosts file:./hosts --port 6000 --duration 30 \ --concurrency 8 --buffer-size 65536 --payload-size 5000000 ``` @@ -237,25 +280,41 @@ Find optimal buffer/payload sizes for your workload: ### Common Flags -| Flag | Default | Description | -|-------------------|----------------|--------------------------------------------------------------| -| `--hosts` | (required) | Target servers (comma-separated, ellipsis pattern, or file:) | -| `--port` | 9010 | Server port | -| `--id` | auto-generated | Test identifier (timestamp if not specified) | -| `--duration` | 30 | Test duration in seconds | -| `--concurrency` | 2×CPUs | Concurrent requests per server | -| `--payload-size` | 1000000 | Payload size in bytes | -| `--buffer-size` | 32000 | Network buffer size in bytes | -| `--request-delay` | 0 | Delay between requests in milliseconds | -| `--save` | true | Save test results on servers | -| `--insecure` | false | Use HTTP instead of HTTPS | -| `--dns-server` | (system) | DNS server used to resolve hostnames in `--hosts` | -| `--ip-family` | auto | Address family for hostname resolution: `auto`, `4` or `6` | -| `--debug` | false | Enable debug output | +Flags are registered per command, so not every flag is accepted everywhere. The +"Commands" column below says where each one applies. + +| Flag | Default | Commands | Description | +|-------------------|----------------|-------------------------|--------------------------------------------------------------| +| `--hosts` | (required) | all client commands | Target servers (comma-separated, ellipsis pattern, or file:) | +| `--port` | 9010 | all client commands | Server port | +| `--id` | auto-generated | all client commands | Test identifier (timestamp if not specified) | +| `--duration` | 30 | bandwidth, latency, requests | Test duration in seconds | +| `--concurrency` | 2×CPUs | bandwidth, requests | Concurrent requests per server | +| `--payload-size` | 1000000 | requests | Payload size in bytes | +| `--buffer-size` | 32000 | requests | Network buffer size in bytes | +| `--request-delay` | 0 | requests | Delay between requests in milliseconds | +| `--save` | true | bandwidth, latency, requests | Save test results on servers | +| `--dns-server` | (system) | all client commands | DNS server used to resolve hostnames in `--hosts` | +| `--ip-family` | auto | all client commands | Address family for hostname resolution: `auto`, `4` or `6` | +| `--sort` | RMSH | analyze | Sort data points: `RMSH` or `TTFBH` | +| `--insecure` | true | global (before command) | Use HTTP instead of HTTPS - **on by default** | +| `--debug` | false | global (before command) | Enable debug output | + +`--insecure` and `--debug` are application-level flags and must appear *before* +the subcommand: `./hperf --debug bandwidth --hosts ...`. Note that `--insecure` +defaults to **true**, so hperf speaks plain HTTP unless you turn it off. + +`bandwidth` and `latency` pin their own payload, buffer and delay settings and do +not accept those flags; `requests` is the tunable form of the latency test. ### Environment Variables -All flags can be set via environment variables with `HPERF_` prefix: +Most flags can be set via environment variables with the `HPERF_` prefix - +`--hosts`, `--port`, `--insecure`, `--concurrency`, `--request-delay`, +`--duration`, `--buffer-size`, `--payload-size`, `--restart-on-error`, `--save`, +`--dns-server`, `--ip-family` and `--debug`. Output and file flags (`--id`, +`--file`, `--sort`, `--micro`, `--print-*`, `--host-filter`) are flag-only. + ```bash export HPERF_HOSTS="10.10.1.{1...10}" export HPERF_PORT="6000" @@ -290,11 +349,17 @@ docker run -p 9010:9010 minio/hperf:latest server --address 0.0.0.0:9010 ### For Enterprise Deployments 1. **Use dedicated storage**: Specify `--storage-path` to a dedicated volume for test results -2. **Set realistic test IDs**: Use descriptive IDs like `prod-latency-2024-01-15` for easier result management +2. **Set realistic test IDs**: Use descriptive IDs like `prod-latency-2024-01-15` for easier result management. IDs may contain letters, digits, `-`, `_` and `.`, up to 64 characters 3. **Configure external IPs**: Always set `--real-ip` when servers have multiple interfaces 4. **Plan for scale**: Long tests with many servers generate significant data - monitor disk usage 5. **Network isolation**: Run tests on a dedicated management network when possible 6. **Automate analysis**: Use `--file` with `analyze` and `csv` commands to integrate with monitoring systems +7. **Size server memory for the mesh**: a full mesh opens `(hosts - 1) x concurrency` inbound connections per + server, each costing roughly 90 KiB of RSS. Budget about + `(hosts - 1) x concurrency x 90 KiB` plus ~50 MiB of baseline - for example + ~750 MiB at 64 hosts with `--concurrency 128`, or ~3 GiB at 256 hosts. Lower + `--concurrency` if that does not fit; note that changing it changes the + workload, so keep it pinned when comparing runs over time ### For Development and Testing @@ -325,6 +390,14 @@ docker run -p 9010:9010 minio/hperf:latest server --address 0.0.0.0:9010 **Symptom**: `#ERR` column shows many errors **Solution**: Check server logs with `--debug`, verify network stability, reduce `--concurrency` or increase `--request-delay` +### Some hosts were excluded from the test +**Symptom**: A warning naming hosts that did not answer, and a smaller mesh than configured +**Solution**: The run continues with the hosts that connected rather than aborting. Check that the named hosts are running and reachable on `--port`; their absence lowers `TX(total)` proportionally + +### Reported throughput looks far lower than NIC counters +**Symptom**: `TX(max)` is roughly 1/(hosts-1) of what `ethtool` reports +**Solution**: This is expected. `TX(max/min/avg)` describe a single flow between one pair of hosts, not a host's or the cluster's aggregate. Compare `TX(total)` over the test duration, or use the per-host table printed when the test finishes + ## License hperf is licensed under the GNU Affero General Public License v3.0. See [LICENSE](LICENSE) for details. diff --git a/client/aggregate.go b/client/aggregate.go new file mode 100644 index 0000000..2093662 --- /dev/null +++ b/client/aggregate.go @@ -0,0 +1,267 @@ +// Copyright (c) 2015-2024 MinIO, Inc. +// +// This file is part of MinIO Object Storage stack +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU Affero General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU Affero General Public License for more details. +// +// You should have received a copy of the GNU Affero General Public License +// along with this program. If not, see . + +package client + +import ( + "fmt" + "math" + "slices" + "strings" + + "github.com/minio/hperf/shared" +) + +// aggregate maintains the live summary incrementally, updated once per incoming +// data point and read once per tick. +// +// The live table used to be built by rescanning every data point received so +// far, on every tick. The client receives hosts*(hosts-1) data points a second, +// so that rescan was ~1.9 million row visits over a 30 second run at 64 hosts +// and ~2.9 billion over a 300 second run at 256 hosts -- and it read the slice +// without holding the lock that guards appends to it. +// +// All fields are guarded by responseLock. +type aggregate struct { + testType shared.TestType + samples uint64 + errCount int + + txSum uint64 + txMin uint64 + txMax uint64 + txTotal uint64 + txCount uint64 + + rmsMin int64 + rmsMax int64 + ttfbMin int64 + ttfbMax int64 + rmsN uint64 + ttfbN uint64 + + memMin int + memMax int + cpuMin int + cpuMax int + hostN int + + // dropped is the largest per-test drop delta any host has reported, or -1 + // while no host has reported a usable counter. + dropped int + + perHost map[string]*shared.HostAverage +} + +func newAggregate() *aggregate { + return &aggregate{ + txMin: math.MaxUint64, + rmsMin: math.MaxInt64, + ttfbMin: math.MaxInt64, + memMin: math.MaxInt, + cpuMin: math.MaxInt, + dropped: -1, + perHost: make(map[string]*shared.HostAverage), + } +} + +// noSample reports whether a low-watermark field carries the "nothing measured +// in this interval" sentinel rather than a measurement. Servers seed the low +// watermarks to MaxInt64 and reset them every interval, and a stream test never +// completes a request, so its RMS fields are sentinel for the whole run. +func noSample(v int64) bool { return v == math.MaxInt64 || v <= 0 } + +// add folds one data point in. host is the address the client dialed, used as +// the sender identity: DP.Local is whatever the server thinks it is, which is +// the same wildcard string on every node when --real-ip was not set. +func (a *aggregate) add(host string, dp shared.DP) { + if a.samples == 0 { + a.testType = dp.Type + } + a.samples++ + + a.txSum += dp.TX + a.txTotal += dp.TXTotal + a.txCount += dp.TXCount + a.txMin = min(a.txMin, dp.TX) + a.txMax = max(a.txMax, dp.TX) + + if !noSample(dp.RMSL) { + a.rmsMin = min(a.rmsMin, dp.RMSL) + a.rmsN++ + } + if dp.RMSH > 0 { + a.rmsMax = max(a.rmsMax, dp.RMSH) + } + if !noSample(dp.TTFBL) { + a.ttfbMin = min(a.ttfbMin, dp.TTFBL) + a.ttfbN++ + } + if dp.TTFBH > 0 { + a.ttfbMax = max(a.ttfbMax, dp.TTFBH) + } + + a.memMin = min(a.memMin, dp.MemoryUsedPercent) + a.memMax = max(a.memMax, dp.MemoryUsedPercent) + a.cpuMin = min(a.cpuMin, dp.CPUUsedPercent) + a.cpuMax = max(a.cpuMax, dp.CPUUsedPercent) + + if dp.DroppedPackets >= 0 { + a.dropped = max(a.dropped, dp.DroppedPackets) + } + + if host == "" { + host = shared.HostOnly(dp.Local) + } + h, ok := a.perHost[host] + if !ok { + h = &shared.HostAverage{Host: host, TXMin: math.MaxUint64} + a.perHost[host] = h + a.hostN++ + } + h.Samples++ + h.TXSum += dp.TX + h.TXTotal += dp.TXTotal + h.TXMin = min(h.TXMin, dp.TX) + h.TXMax = max(h.TXMax, dp.TX) +} + +func (a *aggregate) addErrors(n int) { a.errCount += n } + +// output renders the accumulated state. micro leaves the timers in +// microseconds; otherwise they are converted to milliseconds, matching what the +// per-data-point tables do. +func (a *aggregate) output(micro bool) *shared.TestOutput { + to := &shared.TestOutput{ + ErrCount: a.errCount, + Samples: a.samples, + TXC: a.txCount, + TXT: a.txTotal, + DP: a.dropped, + } + if a.samples == 0 { + return to + } + + to.TXH = a.txMax + to.TXA = a.txSum / a.samples + if a.txMin != math.MaxUint64 { + to.TXL = a.txMin + } + + if a.rmsN > 0 { + to.RMSL = a.rmsMin + } + to.RMSH = a.rmsMax + if a.ttfbN > 0 { + to.TTFBL = a.ttfbMin + } + to.TTFBH = a.ttfbMax + + if a.memMin != math.MaxInt { + to.ML = a.memMin + } + to.MH = a.memMax + if a.cpuMin != math.MaxInt { + to.CL = a.cpuMin + } + to.CH = a.cpuMax + + if !micro { + to.TTFBH /= 1000 + to.TTFBL /= 1000 + to.RMSH /= 1000 + to.RMSL /= 1000 + } + return to +} + +// hosts returns the per-host breakdown, slowest average first, so the hosts +// worth investigating are at the top. +func (a *aggregate) hosts() []shared.HostAverage { + out := make([]shared.HostAverage, 0, len(a.perHost)) + for _, h := range a.perHost { + c := *h + if c.TXMin == math.MaxUint64 { + c.TXMin = 0 + } + out = append(out, c) + } + slices.SortFunc(out, func(x, y shared.HostAverage) int { + if c := cmpUint(x.Avg(), y.Avg()); c != 0 { + return c + } + return strings.Compare(x.Host, y.Host) + }) + return out +} + +func cmpUint(a, b uint64) int { + switch { + case a < b: + return -1 + case a > b: + return 1 + default: + return 0 + } +} + +// fleetAverage is the mean flow rate across every host, used to decide which +// hosts are worth flagging. +func (a *aggregate) fleetAverage() uint64 { + if a.samples == 0 { + return 0 + } + return a.txSum / a.samples +} + +// printHostAverages prints the per-host throughput breakdown once a run ends. +// The live row is a whole-run summary across every flow; this is where you see +// which host is dragging it down. It takes a snapshot rather than the aggregate +// so the caller can release responseLock before doing terminal I/O. +func printHostAverages(hosts []shared.HostAverage, fleet uint64) { + if len(hosts) == 0 { + return + } + + fmt.Println("") + fmt.Println(" Per-host throughput (one row per host, slowest average first)") + fmt.Println("") + + printHeader([]HeaderField{Local, TXA, TXL, TXH, TXT, Samples}) + for i := range hosts { + h := hosts[i] + style := BaseStyle + // Flag any host averaging under half of the fleet-wide average: at + // scale that is the signal worth chasing, and it is invisible in a + // single aggregate number. + if fleet > 0 && h.Avg()*2 < fleet { + style = WarningStyle + } + PrintColumns( + style, + column{h.Host, headerSlice[Local].width}, + column{shared.BWToString(h.Avg()), headerSlice[TXA].width}, + column{shared.BWToString(h.TXMin), headerSlice[TXL].width}, + column{shared.BWToString(h.TXMax), headerSlice[TXH].width}, + column{shared.BToString(h.TXTotal), headerSlice[TXT].width}, + column{formatUint(h.Samples), headerSlice[Samples].width}, + ) + } + fmt.Println("") +} diff --git a/client/aggregate_test.go b/client/aggregate_test.go new file mode 100644 index 0000000..6d4f2b2 --- /dev/null +++ b/client/aggregate_test.go @@ -0,0 +1,402 @@ +// Copyright (c) 2015-2024 MinIO, Inc. +// +// This file is part of MinIO Object Storage stack +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU Affero General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU Affero General Public License for more details. +// +// You should have received a copy of the GNU Affero General Public License +// along with this program. If not, see . + +package client + +import ( + "errors" + "fmt" + "math" + "os" + "path/filepath" + "sync" + "testing" + "time" + + "github.com/minio/hperf/shared" +) + +func streamDP(host string, tx uint64) shared.DP { + return shared.DP{ + Type: shared.StreamTest, Local: host, Remote: "10.0.0.9:9010", + TX: tx, TXTotal: tx, TXCount: 1, + RMSL: math.MaxInt64, RMSH: 0, + TTFBL: math.MaxInt64, TTFBH: 0, + DroppedPackets: -1, + } +} + +// TestAggregateMinAvgMax is the property that makes the three throughput +// columns readable together: they summarize one population, so min <= avg <= max +// always holds and avg is the true mean. +func TestAggregateMinAvgMax(t *testing.T) { + a := newAggregate() + rates := []uint64{100, 200, 300, 400, 500} + var sum uint64 + for i, r := range rates { + a.add(fmt.Sprintf("10.0.0.%d", i+1), streamDP(fmt.Sprintf("10.0.0.%d", i+1), r)) + sum += r + } + + to := a.output(true) + if to.TXL != 100 { + t.Errorf("TXL = %d, want 100", to.TXL) + } + if to.TXH != 500 { + t.Errorf("TXH = %d, want 500", to.TXH) + } + if want := sum / uint64(len(rates)); to.TXA != want { + t.Errorf("TXA = %d, want %d", to.TXA, want) + } + if to.TXL > to.TXA || to.TXA > to.TXH { + t.Errorf("min <= avg <= max violated: %d %d %d", to.TXL, to.TXA, to.TXH) + } + if to.Samples != uint64(len(rates)) { + t.Errorf("Samples = %d, want %d", to.Samples, len(rates)) + } + if to.TXT != sum { + t.Errorf("TXT = %d, want %d", to.TXT, sum) + } +} + +// TestAggregateIgnoresLatencySentinels covers the sentinel leak: servers seed +// the low watermarks to MaxInt64 and a stream test never completes a request, so +// its RMS fields stay sentinel for the whole run. Rendering that as a latency +// would print a nonsense number. +func TestAggregateIgnoresLatencySentinels(t *testing.T) { + a := newAggregate() + for i := 0; i < 5; i++ { + a.add("10.0.0.1", streamDP("10.0.0.1", 1000)) + } + + to := a.output(true) + if to.RMSL != 0 { + t.Errorf("RMSL = %d, want 0 when nothing was measured", to.RMSL) + } + if to.TTFBL != 0 { + t.Errorf("TTFBL = %d, want 0 when nothing was measured", to.TTFBL) + } + + // A real measurement must still come through. + dp := streamDP("10.0.0.1", 1000) + dp.RMSL, dp.RMSH = 1500, 9000 + dp.TTFBL, dp.TTFBH = 300, 800 + a.add("10.0.0.1", dp) + + to = a.output(true) + if to.RMSL != 1500 || to.RMSH != 9000 { + t.Errorf("RMS = %d/%d, want 1500/9000", to.RMSL, to.RMSH) + } + if to.TTFBL != 300 || to.TTFBH != 800 { + t.Errorf("TTFB = %d/%d, want 300/800", to.TTFBL, to.TTFBH) + } +} + +// TestAggregateEmptyIsSafe makes sure a tick before any data point renders zeros +// rather than MaxUint64 sentinels. +func TestAggregateEmptyIsSafe(t *testing.T) { + to := newAggregate().output(false) + if to.Samples != 0 || to.TXA != 0 || to.TXL != 0 || to.TXH != 0 { + t.Errorf("empty aggregate rendered %+v", to) + } +} + +// TestAggregateMillisecondConversion pins the unit handling that the live row +// depends on. +func TestAggregateMillisecondConversion(t *testing.T) { + a := newAggregate() + dp := streamDP("10.0.0.1", 10) + dp.RMSL, dp.RMSH = 2000, 5000 + dp.TTFBL, dp.TTFBH = 1000, 3000 + a.add("10.0.0.1", dp) + + if to := a.output(true); to.RMSL != 2000 || to.RMSH != 5000 { + t.Errorf("micro: RMS = %d/%d, want 2000/5000", to.RMSL, to.RMSH) + } + if to := a.output(false); to.RMSL != 2 || to.RMSH != 5 { + t.Errorf("milli: RMS = %d/%d, want 2/5", to.RMSL, to.RMSH) + } +} + +// TestAggregatePerHost covers the per-host breakdown, including that a host is +// identified by the address the client dialed. DP.Local is whatever the server +// believes, which is the same wildcard string on every node without --real-ip. +func TestAggregatePerHost(t *testing.T) { + a := newAggregate() + // Both servers report the same useless Local value. + for _, rate := range []uint64{1000, 2000, 3000} { + dp := streamDP("0.0.0.0:9010", rate) + a.add("10.0.0.1", dp) + } + for _, rate := range []uint64{100, 200} { + dp := streamDP("0.0.0.0:9010", rate) + a.add("10.0.0.2", dp) + } + + hosts := a.hosts() + if len(hosts) != 2 { + t.Fatalf("got %d hosts, want 2 -- dialed address is not being used as identity", len(hosts)) + } + // Slowest first. + if hosts[0].Host != "10.0.0.2" { + t.Errorf("hosts[0] = %s, want the slower 10.0.0.2", hosts[0].Host) + } + if got, want := hosts[0].Avg(), uint64(150); got != want { + t.Errorf("10.0.0.2 avg = %d, want %d", got, want) + } + if got, want := hosts[1].Avg(), uint64(2000); got != want { + t.Errorf("10.0.0.1 avg = %d, want %d", got, want) + } + if hosts[0].TXMin != 100 || hosts[0].TXMax != 200 { + t.Errorf("10.0.0.2 min/max = %d/%d, want 100/200", hosts[0].TXMin, hosts[0].TXMax) + } +} + +// TestAggregateDroppedIsUnknownUntilReported keeps -1 ("no usable counter") +// distinct from 0 ("no drops"). +func TestAggregateDroppedIsUnknownUntilReported(t *testing.T) { + a := newAggregate() + a.add("h", streamDP("h", 10)) + if to := a.output(true); to.DP != -1 { + t.Errorf("DP = %d, want -1 when no host reported a counter", to.DP) + } + + dp := streamDP("h", 10) + dp.DroppedPackets = 7 + a.add("h", dp) + if to := a.output(true); to.DP != 7 { + t.Errorf("DP = %d, want 7", to.DP) + } +} + +// TestIngestIsRaceFree exercises the ingest path against a concurrent reader of +// the aggregate, which is what the live tick does. Run with -race. +func TestIngestIsRaceFree(t *testing.T) { + responseLock.Lock() + liveAggregate = newAggregate() + responseDPS = responseDPS[:0] + responseERR = responseERR[:0] + retainDPS = false + responseLock.Unlock() + + var wg sync.WaitGroup + stop := make(chan struct{}) + + for h := 0; h < 6; h++ { + wg.Add(1) + go func(id int) { + defer wg.Done() + host := fmt.Sprintf("10.0.0.%d", id) + batch := &shared.DataReponseToClient{DPS: make([]shared.DP, 32)} + for i := range batch.DPS { + batch.DPS[i] = streamDP(host, uint64(1000+i)) + } + for { + select { + case <-stop: + return + default: + } + collectDataPointv2(host, batch) + } + }(h) + } + + wg.Add(1) + go func() { + defer wg.Done() + for { + select { + case <-stop: + return + default: + } + responseLock.Lock() + _ = liveAggregate.output(false) + responseLock.Unlock() + } + }() + + time.Sleep(time.Second) + close(stop) + wg.Wait() + + responseLock.Lock() + samples := liveAggregate.samples + retained := len(responseDPS) + retainDPS = true + responseLock.Unlock() + + if samples == 0 { + t.Error("no samples were folded in") + } + if retained != 0 { + t.Errorf("retention was off but %d data points were kept", retained) + } +} + +// TestAnalyzeParsesErrorPoints covers the silent loss in `analyze`: the error +// branch tested the prefix on b[1:], which is always '{', so no error point ever +// matched and `--print-errors` reported none on a file full of them. +func TestAnalyzeParsesErrorPoints(t *testing.T) { + dir := t.TempDir() + path := filepath.Join(dir, "round.json") + + f, err := os.Create(path) + if err != nil { + t.Fatal(err) + } + dp := shared.DP{ + Type: shared.RequestTest, TestID: "rt", Created: time.Unix(1700000000, 0), + Local: "10.0.0.1", Remote: "10.0.0.2:9010", RMSH: 900, RMSL: 100, + } + if _, err := shared.WriteStructAndNewLine(f, shared.DataPoint, dp); err != nil { + t.Fatal(err) + } + for i := 0; i < 3; i++ { + te := shared.TError{Error: fmt.Sprintf("failure-%d", i), Created: time.Unix(1700000001, 0)} + if _, err := shared.WriteStructAndNewLine(f, shared.ErrorPoint, te); err != nil { + t.Fatal(err) + } + } + f.Close() + + dps, errs, err := parseTestFile(path) + if err != nil { + t.Fatalf("parseTestFile: %v", err) + } + if len(dps) != 1 { + t.Errorf("got %d data points, want 1", len(dps)) + } + if len(errs) != 3 { + t.Fatalf("got %d error points, want 3 -- error points are being dropped", len(errs)) + } + if errs[0].Error != "failure-0" { + t.Errorf("errs[0] = %q", errs[0].Error) + } +} + +// TestHostAccountingIsSymmetric guards the counter that decides when a run is +// over. hostsDoingWork reaching zero means "every host reported Done", so a +// host that never connected must not decrement it. It used to: the increment +// happened only for hosts whose first dial succeeded while the decrement ran +// for every goroutine, so with as many dead hosts as live ones the counter hit +// zero and a 300 second run exited successfully after one tick, having saved +// nothing. +func TestHostAccountingIsSymmetric(t *testing.T) { + hostsDoingWork.Store(0) + + live := &wsClient{ID: 0, Host: "10.0.0.1"} + dead := &wsClient{ID: 1, Host: "10.0.0.2"} + + // Only the reachable host is ever counted. + if !live.hold() { + t.Fatal("hold on a fresh socket did not take effect") + } + if got := hostsDoingWork.Load(); got != 1 { + t.Fatalf("after one live host: %d, want 1", got) + } + + // The unreachable host's goroutine ends and releases. It never held, so it + // must not decrement. + dead.release() + if got := hostsDoingWork.Load(); got != 1 { + t.Errorf("an unreachable host decremented the counter: %d, want 1", got) + } + + // Reconnects must not double count. + live.hold() + live.hold() + if got := hostsDoingWork.Load(); got != 1 { + t.Errorf("reconnect double counted: %d, want 1", got) + } + + // And releasing twice must not go negative. + live.release() + live.release() + if got := hostsDoingWork.Load(); got != 0 { + t.Errorf("after release: %d, want 0", got) + } +} + +// TestSignalReadyNeverBlocks covers the wedge in the reconnect path: the +// readiness channel is drained a fixed number of times and then abandoned, and +// each reconnect re-enters the handler with fresh locals, so a blocking send +// would eventually park the goroutine before its read loop -- silently dropping +// the host from the results with nothing left to notice. +func TestSignalReadyNeverBlocks(t *testing.T) { + // One host, so the buffer is one deep, and drain it as initializeClient + // would. + ready := make(chan connectResult, 1) + socket := &wsClient{ID: 0, Host: "10.0.0.1"} + + signalReady := func(e error) { + select { + case ready <- connectResult{id: socket.ID, err: e}: + default: + } + } + + signalReady(nil) + <-ready + + // Every subsequent report models one reconnect generation. None may block. + done := make(chan struct{}) + go func() { + defer close(done) + for i := 0; i < maxReconnects+5; i++ { + signalReady(errors.New("flap")) + } + }() + + select { + case <-done: + case <-time.After(5 * time.Second): + t.Fatal("signalReady blocked; a reconnecting host would be dropped from the run") + } +} + +// TestHandshakeTimeoutIsNeverUnbounded covers the reconnect hang: the config +// hardcodes DialTimeout to zero, which websocket.Dialer treats as no timeout, +// so a dial against an address that black-holes packets held the run open until +// the kernel gave up. +func TestHandshakeTimeoutIsNeverUnbounded(t *testing.T) { + if got := handshakeTimeout(&shared.Config{DialTimeout: 0}); got != defaultDialTimeout { + t.Errorf("unset DialTimeout gave %s, want %s", got, defaultDialTimeout) + } + if got := handshakeTimeout(&shared.Config{DialTimeout: -5}); got != defaultDialTimeout { + t.Errorf("negative DialTimeout gave %s, want %s", got, defaultDialTimeout) + } + // An explicit value is honored, and is read as seconds. + if got := handshakeTimeout(&shared.Config{DialTimeout: 3}); got != 3*time.Second { + t.Errorf("DialTimeout 3 gave %s, want 3s", got) + } +} + +func TestFilterSelfRemovesEveryMatch(t *testing.T) { + hosts := []string{"10.0.0.1", "10.0.0.2", "10.0.0.1", "10.0.0.10"} + got := filterSelf(hosts, "10.0.0.1") + for _, h := range got { + if h == "10.0.0.1" { + t.Fatalf("filterSelf left a copy of itself behind: %v", got) + } + } + // A prefix match must not be swallowed. + if len(got) != 2 { + t.Errorf("got %v, want the two other hosts", got) + } +} diff --git a/client/client.go b/client/client.go index 9696b4a..dfe636e 100644 --- a/client/client.go +++ b/client/client.go @@ -34,6 +34,7 @@ import ( "runtime/debug" "slices" "strconv" + "strings" "sync" "sync/atomic" "time" @@ -44,56 +45,122 @@ import ( ) var ( - responseDPS = make([]shared.DP, 0) - responseERR = make([]shared.TError, 0) - responseLock = sync.Mutex{} + responseDPS = make([]shared.DP, 0) + responseERR = make([]shared.TError, 0) + responseLock = sync.Mutex{} + + // liveAggregate is the incremental live summary. Guarded by responseLock. + liveAggregate = newAggregate() + + // retainDPS controls whether every data point is kept. Latency runs need + // them all for the percentile analysis; a bandwidth run only needs them + // for --print-all, and at 256 hosts they arrive at 65k/s. + retainDPS = true + websockets []*wsClient hostsDoingWork atomic.Int32 + + // reconnectDeadline (UnixNano, 0 = unset) bounds the reconnect window. Once + // the measurement window has passed there is nothing left to collect, so a + // host that is still down should stop retrying rather than hold the command + // open for its whole reconnect budget -- which cost ~17s of dead air after + // the data was already complete. + reconnectDeadline atomic.Int64 ) +// connectTimeout bounds how long we wait for the initial connection to every +// host before proceeding with whichever ones answered. +const connectTimeout = 10 * time.Second + +// maxReconnects bounds the reconnect loop. It used to respawn forever, which +// churned goroutines for the whole run against a host that was simply down. +const maxReconnects = 10 + +// noReattach means a reconnecting socket should not re-announce itself. Note +// shared.Err is 0, so the sentinel cannot be. +const noReattach = shared.SignalType(-1) + +// defaultDialTimeout bounds the websocket handshake when the config does not +// say. Config.DialTimeout is hardcoded to zero, which websocket.Dialer reads as +// "no timeout": a reconnect to an address that black-holes packets -- a killed +// container, a host that fell off the network -- then hangs until the kernel +// gives up minutes later, holding the whole run open past its grace period. A +// host that refuses or resets fails fast either way; this is only about the +// silent case. +const defaultDialTimeout = 10 * time.Second + +// handshakeTimeout is DialTimeout in seconds, floored so it is never unbounded. +func handshakeTimeout(c *shared.Config) time.Duration { + if d := time.Second * c.DialTimeout; d > 0 { + return d + } + return defaultDialTimeout +} + +// wsClient tracks one host's connection. The reader goroutine reconnects and +// replaces the connection while the main goroutine is iterating hosts to send +// signals, so the shared fields are atomics rather than plain values. type wsClient struct { ID int Host string - Con *websocket.Conn -} -func (c *wsClient) SendError(e error) error { - if e == nil { - return nil - } - msg := new(shared.WebsocketSignal) - msg.SType = shared.Err - msg.Error = e.Error() - return c.Con.WriteJSON(msg) + con atomic.Pointer[websocket.Conn] + counted atomic.Bool + excluded atomic.Bool + + // Owned by the reader goroutine chain, which is sequential per host: at + // most one handleWSConnection invocation is live for a given socket. + retries int } -func (c *wsClient) Close() (err error) { - return c.Remove() +func (c *wsClient) Conn() *websocket.Conn { return c.con.Load() } + +// withinReconnectWindow reports whether reconnecting could still yield data. +func withinReconnectWindow() bool { + deadline := reconnectDeadline.Load() + return deadline == 0 || time.Now().UnixNano() < deadline } -func (c *wsClient) Remove() (err error) { - err = c.Con.Close() - websockets[c.ID] = nil - return +// hold makes this host count towards hostsDoingWork, exactly once, and reports +// whether it was this call that did so. +func (c *wsClient) hold() bool { + if c.counted.CompareAndSwap(false, true) { + hostsDoingWork.Add(1) + return true + } + return false } -func filterSelf(hosts []string, self string) []string { - for i, v := range hosts { - if shared.SameHost(v, self) { - hosts = slices.Delete(hosts, i, i+1) - break - } +// release undoes hold, exactly once. Increment and decrement have to be +// symmetric: hostsDoingWork reaching zero is what tells keepAliveLoop every host +// has finished, so an unmatched decrement ends the run early. A host that never +// connected must therefore not decrement -- it never incremented. +func (c *wsClient) release() { + if c.counted.CompareAndSwap(true, false) { + hostsDoingWork.Add(-1) } +} - return hosts +// filterSelf removes every entry matching self, not just the first. A host +// listed twice used to leave one copy behind, so a server would test against +// itself through the local network stack. +func filterSelf(hosts []string, self string) []string { + return slices.DeleteFunc(hosts, func(h string) bool { + return shared.SameHost(h, self) + }) } -func itterateWebsockets(action func(c *wsClient)) { +// itterateWebsockets runs action for every host that is currently connected. +// The connection is loaded once and handed over, so it cannot be swapped out +// from under the action by a reconnect. +func itterateWebsockets(action func(c *wsClient, con *websocket.Conn)) { for i := range websockets { if websockets[i] == nil { continue } - action(websockets[i]) + if con := websockets[i].Conn(); con != nil { + action(websockets[i], con) + } } } @@ -104,80 +171,144 @@ func (c *wsClient) NewSignal(signal shared.SignalType, conf shared.Config) *shar return msg } -func (c *wsClient) Ping() (err error) { - msg := new(shared.WebsocketSignal) - msg.SType = shared.Ping - err = c.Con.WriteJSON(msg) - return -} - var ( testList = make(map[string]shared.TestInfo) testLock = sync.Mutex{} ) -func initializeClient(ctx context.Context, c *shared.Config) (err error) { +type connectResult struct { + id int + err error +} + +// initializeClient dials every host and returns the ones that answered. A +// single unreachable host used to abort the whole run; now the run proceeds +// with the reachable subset and says loudly which hosts it dropped, because a +// silently smaller mesh is exactly the failure this tool exists to detect. +// reattach is the signal a reconnecting socket re-sends so the server hands it +// back the test already in flight; pass noReattach for commands where that makes +// no sense. +func initializeClient(ctx context.Context, c *shared.Config, reattach shared.SignalType) (reachable []string, err error) { websockets = make([]*wsClient, len(c.Hosts)) + for i := range c.Hosts { + websockets[i] = &wsClient{ID: i, Host: c.Hosts[i]} + } + hostsDoingWork.Store(0) - clientID := 0 - done := make(chan struct{}, len(c.Hosts)) - for _, host := range c.Hosts { - go handleWSConnection(ctx, c, host, clientID, done) - clientID++ + // A duration of zero means the caller is not running a bounded test, so + // leave the reconnect budget alone. + if c.Duration > 0 { + reconnectDeadline.Store(time.Now().Add(time.Duration(c.Duration) * time.Second).UnixNano()) + } else { + reconnectDeadline.Store(0) } - doneCount := 0 - timeout := time.NewTicker(time.Second * 10) + responseLock.Lock() + liveAggregate = newAggregate() + responseLock.Unlock() - for { + // Reports are best-effort sends into a buffer nobody drains once this + // function returns, so the reconnect path can never block on it. + ready := make(chan connectResult, len(c.Hosts)) + for i := range websockets { + go handleWSConnection(ctx, c, websockets[i], ready, reattach) + } + + timeout := time.NewTimer(connectTimeout) + defer timeout.Stop() + + reported := make([]bool, len(c.Hosts)) + remaining := len(c.Hosts) + +waiting: + for remaining > 0 { select { - case <-done: - doneCount++ - hostsDoingWork.Add(1) - if doneCount == len(c.Hosts) { - return + case r := <-ready: + if reported[r.id] { + continue } + reported[r.id] = true + remaining-- case <-ctx.Done(): - return errors.New("Context canceled") + return nil, errors.New("Context canceled") case <-timeout.C: - return errors.New("Timeout when connecting to hosts") + break waiting } } + + excluded := make([]string, 0) + reachable = make([]string, 0, len(c.Hosts)) + for i := range websockets { + if websockets[i].Conn() != nil { + reachable = append(reachable, websockets[i].Host) + continue + } + // Stop the reconnect chain for a host that is not part of the mesh. + websockets[i].excluded.Store(true) + excluded = append(excluded, websockets[i].Host) + } + + if len(reachable) == 0 { + return nil, fmt.Errorf("Unable to connect to any of the %d configured hosts", len(c.Hosts)) + } + if len(excluded) > 0 { + PrintErrorString(fmt.Sprintf( + "WARNING: %d of %d hosts did not answer and were excluded from the test: %s", + len(excluded), len(c.Hosts), strings.Join(excluded, ", "), + )) + } + return reachable, nil } -func handleWSConnection(ctx context.Context, c *shared.Config, host string, id int, done chan struct{}) { +func handleWSConnection(ctx context.Context, c *shared.Config, socket *wsClient, ready chan connectResult, reattach shared.SignalType) { var err error + host := socket.Host + + // The send is non-blocking. initializeClient drains this channel exactly + // len(hosts) times and then abandons it, and the reconnect path re-enters + // this function with a fresh set of locals -- so a blocking send would + // eventually fill the buffer and park here forever, before the read loop, + // silently dropping the host from the results. Duplicate reports are + // harmless: initializeClient ignores any host that already reported. + signalReady := func(e error) { + select { + case ready <- connectResult{id: socket.ID, err: e}: + default: + } + } + defer func() { - r := recover() - if r != nil { + if r := recover(); r != nil { fmt.Println(r, string(debug.Stack())) } + signalReady(err) + if ctx.Err() != nil { - hostsDoingWork.Add(-1) + socket.release() return } - if c.RestartOnError && err != nil { + // Only retry a host that was part of the mesh, only a bounded number of + // times, and only while the measurement is still running. The retry + // keeps the host counted: releasing here and re-holding on reconnect + // would let the count dip to zero and end the whole run. + if c.RestartOnError && err != nil && !socket.excluded.Load() && + socket.retries < maxReconnects && withinReconnectWindow() { + socket.retries++ time.Sleep(500 * time.Millisecond) - go handleWSConnection(ctx, c, host, id, done) - } else { - hostsDoingWork.Add(-1) + go handleWSConnection(ctx, c, socket, ready, reattach) + return } + socket.release() }() - socket := websockets[id] - if socket == nil { - websockets[id] = new(wsClient) - socket = websockets[id] - socket.ID = id - } - - socket.Host = host - dialer := websocket.Dialer{ Proxy: http.ProxyFromEnvironment, - HandshakeTimeout: time.Second * c.DialTimeout, - ReadBufferSize: 1000000, - WriteBufferSize: 1000000, + HandshakeTimeout: handshakeTimeout(c), + // These are per-connection buffers. 1 MB each cost ~2 MB per host on + // the client for no benefit: the signals are small and the data-point + // batches are tens of kilobytes. + ReadBufferSize: 64 * 1024, + WriteBufferSize: 64 * 1024, } shared.DEBUG(WarningStyle.Render("Connecting to ", net.JoinHostPort(host, c.Port))) @@ -188,21 +319,31 @@ func handleWSConnection(ctx context.Context, c *shared.Config, host string, id i } connectString := scheme + "://" + shared.URLHostPort(host, c.Port) + "/ws/" + url.PathEscape(host) - con, _, dialErr := dialer.DialContext( + con, resp, dialErr := dialer.DialContext( ctx, connectString, nil) + // A failed handshake still returns a response whose body has to be closed, + // otherwise every reconnect against a host that answers but will not + // upgrade leaks a connection. + if resp != nil && resp.Body != nil { + _ = resp.Body.Close() + } if dialErr != nil { - PrintError(dialErr) - err = dialErr + err = fmt.Errorf("%s: %w", host, dialErr) + PrintError(err) return } - socket.Con = con + socket.con.Store(con) + defer func() { + socket.con.CompareAndSwap(con, nil) + _ = con.Close() + }() msg := new(shared.WebsocketSignal) err = con.ReadJSON(&msg) if err != nil { - err = fmt.Errorf("Unable to read message from server on first connect %s", err) + err = fmt.Errorf("Unable to read message from server on first connect: %w", err) PrintError(err) return } @@ -213,7 +354,26 @@ func handleWSConnection(ctx context.Context, c *shared.Config, host string, id i } shared.DEBUG(SuccessStyle.Render("Connected to ", net.JoinHostPort(host, c.Port))) - done <- struct{}{} + // Count the host only once it is actually up, so the counter is only ever + // decremented by a host that contributed to it. + socket.hold() + signalReady(nil) + + // A reconnected socket is unknown to the test already running on the + // server, so it would receive neither data points nor -- the part that + // matters -- a Done. The command would then wait out its entire grace + // period and report failure on an otherwise complete run. Re-announce it: + // the server either attaches it to the live test, or answers Done because + // no matching test exists, which ends this reader cleanly. + if socket.retries > 0 && reattach != noReattach { + if werr := con.WriteJSON(socket.NewSignal(reattach, *c)); werr != nil { + err = fmt.Errorf("%s: unable to re-attach after reconnect: %w", host, werr) + PrintError(err) + return + } + shared.DEBUG(WarningStyle.Render("Re-attached to ", host, " after reconnect")) + } + for { signal := new(shared.WebsocketSignal) err = con.ReadJSON(&signal) @@ -224,23 +384,27 @@ func handleWSConnection(ctx context.Context, c *shared.Config, host string, id i if shared.DebugEnabled { fmt.Printf("WebsocketSignal: %+v\n", signal) } + // Handled inline rather than in a goroutine per message: spawning gave + // no ordering guarantee, piled up goroutines contending on + // responseLock, and at 256 hosts meant tens of thousands of goroutines + // a second. The read loop is per-host already. switch signal.SType { case shared.Stats: // Live tests print an aggregate table of their own, attached // clients print the incoming data points as they arrive. if c.PrintLive { - go printAndCollectDataPoints(signal.DataPoint, c) + printAndCollectDataPoints(host, signal.DataPoint, c) } else { - go collectDataPointv2(signal.DataPoint) + collectDataPointv2(host, signal.DataPoint) } case shared.ListTests: - go parseTestList(signal.TestList) + parseTestList(signal.TestList) case shared.GetTest: - go receiveJSONDataPoint(signal.Data, c) + receiveJSONDataPoint(signal.Data, c) case shared.Err: - go PrintErrorString(signal.Error) + PrintErrorString(signal.Error) case shared.Done: - shared.DEBUG(SuccessStyle.Render("Host Finished: ", con.RemoteAddr().String())) + shared.DEBUG(SuccessStyle.Render("Host Finished: ", host)) return } } @@ -288,10 +452,24 @@ func receiveJSONDataPoint(data []byte, _ *shared.Config) { func keepAliveLoop(ctx context.Context, c *shared.Config, tickerfunc func() (shouldExit bool)) error { start := time.Now() + + // The normal exit is every host reporting Done, which drives + // hostsDoingWork to zero. This is only a backstop, and it has to outlast + // the servers: each runs Duration sampling intervals plus a final flush, + // and shipping stats to attached clients adds to every interval. The grace + // period was a flat 20 seconds, which a long run could exceed -- getting + // cut off and silently reported as finished. Scaling it fixes that without + // making short runs wait longer than they used to when a host dies. + grace := time.Duration(max(20, c.Duration/2)) * time.Second + limit := time.Duration(c.Duration)*time.Second + grace + for ctx.Err() == nil { time.Sleep(1 * time.Second) - if time.Since(start).Seconds() > float64(c.Duration)+20 { - return errors.New("Total duration reached 20 seconds past the configured duration") + if time.Since(start) > limit { + return fmt.Errorf( + "Hosts did not finish within %s of the configured %ds duration", + grace, c.Duration, + ) } select { @@ -316,13 +494,13 @@ func Listen(ctx context.Context, c shared.Config) (err error) { cancelContext, cancel := context.WithCancel(ctx) defer cancel() c.PrintLive = true - err = initializeClient(cancelContext, &c) + _, err = initializeClient(cancelContext, &c, shared.ListenTest) if err != nil { return } - itterateWebsockets(func(ws *wsClient) { - err = ws.Con.WriteJSON(ws.NewSignal(shared.ListenTest, c)) + itterateWebsockets(func(ws *wsClient, con *websocket.Conn) { + err = con.WriteJSON(ws.NewSignal(shared.ListenTest, c)) if err != nil { return } @@ -334,13 +512,13 @@ func Listen(ctx context.Context, c shared.Config) (err error) { func Stop(ctx context.Context, c shared.Config) (err error) { cancelContext, cancel := context.WithCancel(ctx) defer cancel() - err = initializeClient(cancelContext, &c) + _, err = initializeClient(cancelContext, &c, noReattach) if err != nil { return } - itterateWebsockets(func(ws *wsClient) { - err = ws.Con.WriteJSON(ws.NewSignal(shared.StopAllTests, c)) + itterateWebsockets(func(ws *wsClient, con *websocket.Conn) { + err = con.WriteJSON(ws.NewSignal(shared.StopAllTests, c)) if err != nil { return } @@ -352,89 +530,58 @@ func Stop(ctx context.Context, c shared.Config) (err error) { func RunTest(ctx context.Context, c shared.Config) (err error) { cancelContext, cancel := context.WithCancel(ctx) defer cancel() - err = initializeClient(cancelContext, &c) + + // A bandwidth run only needs every data point for --print-all; a latency + // run always needs them for the percentile analysis. At 256 hosts they + // arrive at 65k/s, so keeping them when nothing will read them is a + // gigabyte of garbage for nothing. + retainDPS = c.PrintAll || c.PrintStats || c.TestType == shared.RequestTest + + reachable, err := initializeClient(cancelContext, &c, shared.ListenTest) if err != nil { return } + // Only reachable hosts go into the mesh. Handing servers a peer that is + // known to be down just makes every one of them spend the test erroring + // against it. ogh := slices.Clone(c.Hosts) - itterateWebsockets(func(ws *wsClient) { - oh := slices.Clone(ogh) - c.Hosts = filterSelf(oh, ws.Host) - err = ws.Con.WriteJSON(ws.NewSignal(shared.RunTest, c)) - if err != nil { - return + itterateWebsockets(func(ws *wsClient, con *websocket.Conn) { + c.Hosts = filterSelf(slices.Clone(reachable), ws.Host) + if werr := con.WriteJSON(ws.NewSignal(shared.RunTest, c)); werr != nil { + PrintError(fmt.Errorf("%s: unable to start test: %w", ws.Host, werr)) } }) c.Hosts = ogh printCount := 0 + errorsPrinted := 0 + renderedSamples := uint64(0) printOnTick := func() bool { - if len(responseDPS) == 0 { - return false + responseLock.Lock() + to := liveAggregate.output(c.Micro) + tt := liveAggregate.testType + newErrors := make([]shared.TError, 0) + if len(responseERR) > errorsPrinted { + newErrors = append(newErrors, responseERR[errorsPrinted:]...) + errorsPrinted = len(responseERR) } - printCount++ + responseLock.Unlock() - to := new(shared.TestOutput) - to.ErrCount = len(responseERR) - to.TXL = math.MaxInt64 - to.RMSL = math.MaxInt64 - to.TTFBL = math.MaxInt64 - to.ML = responseDPS[0].MemoryUsedPercent - to.CL = responseDPS[0].CPUUsedPercent - tt := responseDPS[0].Type - - for i := range responseDPS { - to.TXC += responseDPS[i].TXCount - to.TXT += responseDPS[i].TXTotal - - if to.DP < responseDPS[i].DroppedPackets { - to.DP = responseDPS[i].DroppedPackets - } - - if to.TXL > responseDPS[i].TX { - to.TXL = responseDPS[i].TX - } - if to.RMSL > responseDPS[i].RMSL { - to.RMSL = responseDPS[i].RMSL - } - if to.TTFBL > responseDPS[i].TTFBL { - to.TTFBL = responseDPS[i].TTFBL - } - if to.ML > responseDPS[i].MemoryUsedPercent { - to.ML = responseDPS[i].MemoryUsedPercent - } - if to.CL > responseDPS[i].CPUUsedPercent { - to.CL = responseDPS[i].CPUUsedPercent - } - - if to.TXH < responseDPS[i].TX { - to.TXH = responseDPS[i].TX - } - if to.RMSH < responseDPS[i].RMSH { - to.RMSH = responseDPS[i].RMSH - } - if to.TTFBH < responseDPS[i].TTFBH { - to.TTFBH = responseDPS[i].TTFBH - } - if to.MH < responseDPS[i].MemoryUsedPercent { - to.MH = responseDPS[i].MemoryUsedPercent - } - if to.CH < responseDPS[i].CPUUsedPercent { - to.CH = responseDPS[i].CPUUsedPercent - } - } - - if !c.Micro { - to.TTFBH = to.TTFBH / 1000 - to.TTFBL = to.TTFBL / 1000 - to.RMSH = to.RMSH / 1000 - to.RMSL = to.RMSL / 1000 + // Nothing new to say. This also makes the final render after the loop + // a no-op when the last tick already covered everything, rather than + // repeating an identical row. + if to.Samples == 0 || to.Samples == renderedSamples { + return false } + renderedSamples = to.Samples + printCount++ - for i := range responseERR { - PrintErrorString(responseERR[i].Error) + // Only errors not already shown. The old loop reprinted every error + // received so far on every tick. + for i := range newErrors { + PrintErrorString(newErrors[i].Error) } if printCount%10 == 1 { @@ -445,19 +592,39 @@ func RunTest(ctx context.Context, c shared.Config) (err error) { return false } - return keepAliveLoop(ctx, &c, printOnTick) + err = keepAliveLoop(ctx, &c, printOnTick) + + // One last render. Servers flush their final interval when the run ends, + // which lands after the loop's last tick, so without this the live + // TX(total) stops short of what was actually saved. + printOnTick() + + responseLock.Lock() + hosts := liveAggregate.hosts() + fleet := liveAggregate.fleetAverage() + samples := liveAggregate.samples + responseLock.Unlock() + printHostAverages(hosts, fleet) + + // A test that produced nothing has to fail the command. Every server + // rejecting the config -- an invalid --id, for instance -- used to leave + // the client printing "Testing finished" and exiting successfully. + if err == nil && samples == 0 { + return errors.New("No data points were received from any host, the test did not run") + } + return err } func ListTests(ctx context.Context, c shared.Config) (err error) { cancelContext, cancel := context.WithCancel(ctx) defer cancel() - err = initializeClient(cancelContext, &c) + _, err = initializeClient(cancelContext, &c, noReattach) if err != nil { return } - itterateWebsockets(func(ws *wsClient) { - err = ws.Con.WriteJSON(ws.NewSignal(shared.ListTests, c)) + itterateWebsockets(func(ws *wsClient, con *websocket.Conn) { + err = con.WriteJSON(ws.NewSignal(shared.ListTests, c)) if err != nil { return } @@ -499,13 +666,13 @@ func ListTests(ctx context.Context, c shared.Config) (err error) { func DeleteTests(ctx context.Context, c shared.Config) (err error) { cancelContext, cancel := context.WithCancel(ctx) defer cancel() - err = initializeClient(cancelContext, &c) + _, err = initializeClient(cancelContext, &c, noReattach) if err != nil { return } - itterateWebsockets(func(ws *wsClient) { - err = ws.Con.WriteJSON(ws.NewSignal(shared.DeleteTests, c)) + itterateWebsockets(func(ws *wsClient, con *websocket.Conn) { + err = con.WriteJSON(ws.NewSignal(shared.DeleteTests, c)) if err != nil { return } @@ -529,13 +696,13 @@ func parseTestList(list []shared.TestInfo) { func DownloadTest(ctx context.Context, c shared.Config) (err error) { cancelContext, cancel := context.WithCancel(ctx) defer cancel() - err = initializeClient(cancelContext, &c) + _, err = initializeClient(cancelContext, &c, noReattach) if err != nil { return } - itterateWebsockets(func(ws *wsClient) { - err = ws.Con.WriteJSON(ws.NewSignal(shared.GetTest, c)) + itterateWebsockets(func(ws *wsClient, con *websocket.Conn) { + err = con.WriteJSON(ws.NewSignal(shared.GetTest, c)) if err != nil { fmt.Println(err) return @@ -544,20 +711,28 @@ func DownloadTest(ctx context.Context, c shared.Config) (err error) { _ = keepAliveLoop(ctx, &c, nil) - slices.SortFunc(responseERR, func(a shared.TError, b shared.TError) int { - if a.Created.Before(b.Created) { - return -1 - } else { - return 1 - } - }) + // Snapshot under the lock: a straggling reader goroutine can still be + // appending, and these used to be read with no lock at all. + responseLock.Lock() + dps := slices.Clone(responseDPS) + errs := slices.Clone(responseERR) + responseLock.Unlock() + + // Refuse to present an empty file as a successful download. Every host + // rejecting the id -- or simply not having the test -- used to create or + // truncate the target, write nothing, and exit 0. + if len(dps) == 0 && len(errs) == 0 { + return fmt.Errorf("No records for test (%s) were returned by any host", c.TestID) + } - slices.SortFunc(responseDPS, func(a shared.DP, b shared.DP) int { - if a.Created.Before(b.Created) { - return -1 - } else { - return 1 - } + // Compare returns 0 for equal timestamps. Returning 1 broke + // slices.SortFunc's ordering contract, which left ties in an undefined + // order and made two downloads of the same test produce different files. + slices.SortFunc(errs, func(a shared.TError, b shared.TError) int { + return a.Created.Compare(b.Created) + }) + slices.SortFunc(dps, func(a shared.DP, b shared.DP) int { + return a.Created.Compare(b.Created) }) f, err := os.Create(c.File) @@ -565,46 +740,61 @@ func DownloadTest(ctx context.Context, c shared.Config) (err error) { return err } defer f.Close() - for i := range responseDPS { - _, err := shared.WriteStructAndNewLineToFile(f, shared.DataPoint, responseDPS[i]) - if err != nil { + + w := bufio.NewWriter(f) + for i := range dps { + if _, err := shared.WriteStructAndNewLine(w, shared.DataPoint, dps[i]); err != nil { return err } } - for i := range responseERR { - _, err := shared.WriteStructAndNewLineToFile(f, shared.ErrorPoint, responseERR[i]) - if err != nil { + for i := range errs { + if _, err := shared.WriteStructAndNewLine(w, shared.ErrorPoint, errs[i]); err != nil { return err } } - return nil + return w.Flush() +} + +// snapshotResponses copies the collected data under the lock. Reading these +// globals directly raced with the reader goroutines still appending to them. +func snapshotResponses() (dps []shared.DP, errs []shared.TError) { + responseLock.Lock() + defer responseLock.Unlock() + return slices.Clone(responseDPS), slices.Clone(responseERR) } func AnalyzeBandwidthTest(ctx context.Context, c shared.Config) (err error) { _, cancel := context.WithCancel(ctx) defer cancel() + dps, errs := snapshotResponses() + if c.PrintAll { shared.INFO(" Printing all data points ..") fmt.Println("") - printSliceOfDataPoints(responseDPS, c) + printSliceOfDataPoints(dps, c) - if len(responseERR) > 0 { + if len(errs) > 0 { fmt.Println(" ____ ERRORS ____") } - for i := range responseERR { - PrintTError(responseERR[i]) + for i := range errs { + PrintTError(errs[i]) } - if len(responseERR) > 0 { + if len(errs) > 0 { fmt.Println("") } } - if len(responseDPS) == 0 { + // Retention is off for a plain bandwidth run, so an empty slice does not + // mean an empty run -- ask the aggregate, which counts every data point + // regardless of whether it was kept. + responseLock.Lock() + samples := liveAggregate.samples + responseLock.Unlock() + if samples == 0 { fmt.Println("No datapoints found") - return } return nil @@ -614,67 +804,87 @@ func AnalyzeLatencyTest(ctx context.Context, c shared.Config) (err error) { _, cancel := context.WithCancel(ctx) defer cancel() + dps, errs := snapshotResponses() + if c.PrintAll { shared.INFO(" Printing all data points ..") - printSliceOfDataPoints(responseDPS, c) + printSliceOfDataPoints(dps, c) - if len(responseERR) > 0 { + if len(errs) > 0 { fmt.Println(" ____ ERRORS ____") } - for i := range responseERR { - PrintTError(responseERR[i]) + for i := range errs { + PrintTError(errs[i]) } - if len(responseERR) > 0 { + if len(errs) > 0 { fmt.Println("") } } - if len(responseDPS) == 0 { + if len(dps) == 0 { fmt.Println("No datapoints found") return } shared.INFO(" Analyzing data ..") fmt.Println("") - analyzeLatencyTest(responseDPS, c) + analyzeLatencyTest(dps, c) return nil } -func AnalyzeTest(ctx context.Context, c shared.Config) (err error) { - _, cancel := context.WithCancel(ctx) - defer cancel() - - f, err := os.Open(c.File) +// parseTestFile reads a saved or downloaded test file. Each line is one record: +// a prefix byte identifying the type, then the JSON. +// +// Both branches test the prefix on b and unmarshal b[1:]. The error branch used +// to test the prefix on b[1:] -- which is always '{', so it never matched -- and +// then unmarshal b including the prefix byte, which could not have parsed +// either. Every error point in a file was silently discarded, so `analyze +// --print-errors` reported none on a file full of them. +func parseTestFile(path string) (dps []shared.DP, errs []shared.TError, err error) { + f, err := os.Open(path) if err != nil { - return err + return nil, nil, err } defer f.Close() - dps := make([]shared.DP, 0) - errors := make([]shared.TError, 0) + dps = make([]shared.DP, 0) + errs = make([]shared.TError, 0) s := bufio.NewScanner(f) for s.Scan() { b := s.Bytes() - if bytes.HasPrefix(b[1:], shared.ErrorPoint.String()) { + if len(b) < 2 { + continue + } + switch { + case bytes.HasPrefix(b, shared.ErrorPoint.String()): dperr := new(shared.TError) - err := json.Unmarshal(b, dperr) - if err != nil { - return err + if err := json.Unmarshal(b[1:], dperr); err != nil { + return nil, nil, err } - errors = append(errors, *dperr) - } else if bytes.HasPrefix(b, shared.DataPoint.String()) { + errs = append(errs, *dperr) + case bytes.HasPrefix(b, shared.DataPoint.String()): dp := new(shared.DP) - err := json.Unmarshal(b[1:], dp) - if err != nil { - return err + if err := json.Unmarshal(b[1:], dp); err != nil { + return nil, nil, err } dps = append(dps, *dp) - } else { + default: shared.DEBUG(ErrorStyle.Render("Unknown data point encountered: ", string(b))) } } + return dps, errs, s.Err() +} + +func AnalyzeTest(ctx context.Context, c shared.Config) (err error) { + _, cancel := context.WithCancel(ctx) + defer cancel() + + dps, errors, err := parseTestFile(c.File) + if err != nil { + return err + } if c.HostFilter != "" { dps = shared.HostFilter(c.HostFilter, dps) @@ -720,9 +930,8 @@ func analyzeLatencyTest(dps []shared.DP, c shared.Config) { dps90 := math.Floor((float64(len(dps)) / 100) * 90) dps99 := math.Floor((float64(len(dps)) / 100) * 99) - dps10s := make([]shared.DP, 0) - dps50s := make([]shared.DP, 0) - dps90s := make([]shared.DP, 0) + // Only the P99 slice is rendered. The P10/P50/P90 slices were built and + // then never read -- three near-full copies of the data set per analysis. dps99s := make([]shared.DP, 0) // count, sum, low, avg, high @@ -733,15 +942,12 @@ func analyzeLatencyTest(dps []shared.DP, c shared.Config) { for i := range dps { if i >= int(dps10) { - dps10s = append(dps10s, dps[i]) shared.UpdatePSStats(dps10stats, dps[i], c) } if i >= int(dps50) { - dps50s = append(dps50s, dps[i]) shared.UpdatePSStats(dps50stats, dps[i], c) } if i >= int(dps90) { - dps90s = append(dps90s, dps[i]) shared.UpdatePSStats(dps90stats, dps[i], c) } if i >= int(dps99) { @@ -813,7 +1019,7 @@ func MakeCSV(ctx context.Context, c shared.Config) (err error) { } // Function to get field names of the struct -func getStructFields(s interface{}) []string { +func getStructFields(s any) []string { t := reflect.TypeOf(s).Elem() fields := make([]string, t.NumField()) for i := 0; i < t.NumField(); i++ { diff --git a/client/table.go b/client/table.go index 7e2c087..6c800d4 100644 --- a/client/table.go +++ b/client/table.go @@ -32,7 +32,7 @@ type header struct { } type column struct { - value interface{} + value any width int } @@ -52,6 +52,7 @@ const ( TX TXH TXL + TXA TXT TXCount ErrCount @@ -64,9 +65,18 @@ const ( CPULow ID HumanTime + Samples header_length ) +// Headers are built once at package init. They used to be built lazily on the +// first data point, from whichever goroutine got there first, while the live +// ticker goroutine was already reading widths -- a race, and one that produced +// an unpadded row if a tick landed before any data point. +func init() { + initHeaders() +} + func initHeaders() { headerSlice[IntNumber] = header{"#", 5} headerSlice[Created] = header{"Created", 8} @@ -76,9 +86,13 @@ func initHeaders() { headerSlice[RMSL] = header{"RMS(low)", 9} headerSlice[TTFBH] = header{"TTFB(high)", 9} headerSlice[TTFBL] = header{"TTFB(low)", 9} - headerSlice[TX] = header{"TX", 10} - headerSlice[TXL] = header{"TX(low)", 10} - headerSlice[TXH] = header{"TX(high)", 10} + // BWToString emits up to 11 characters ("999.99 GB/s") and PrintColumns + // pads but never truncates, so a width of 10 shifted every later column + // right once a test reached GB/s. + headerSlice[TX] = header{"TX", 11} + headerSlice[TXL] = header{"TX(min)", 11} + headerSlice[TXH] = header{"TX(max)", 11} + headerSlice[TXA] = header{"TX(avg)", 11} headerSlice[TXT] = header{"TX(total)", 15} headerSlice[TXCount] = header{"#TX", 10} headerSlice[ErrCount] = header{"#ERR", 6} @@ -91,12 +105,14 @@ func initHeaders() { headerSlice[CPULow] = header{"CPU(low)", 9} headerSlice[ID] = header{"ID", 30} headerSlice[HumanTime] = header{"Time", 30} + headerSlice[Samples] = header{"#Samples", 9} } +// growHostColumns widens the two host columns to fit the addresses seen so +// far. Callers must hold responseLock: these are the only header entries that +// change after init, and the per-data-point table is rendered from the same +// lock-holding paths. func growHostColumns(dps []shared.DP) (grew bool) { - if headerSlice[0].width == 0 { - initHeaders() - } for i := range dps { if w := len(shared.HostOnly(dps[i].Local)); w > headerSlice[Local].width { headerSlice[Local].width = w @@ -123,8 +139,10 @@ var ( LatencyHeaders = []HeaderField{Created, Local, Remote, RMSH, RMSL, TTFBH, TTFBL, TX, TXCount, ErrCount, DroppedPackets, MemoryUsage, CPUUsage} FullDataPointHeaders = []HeaderField{Created, Local, Remote, RMSH, RMSL, TTFBH, TTFBL, TX, TXCount, ErrCount, DroppedPackets, MemoryUsage, CPUUsage} - RealTimeBandwidthHeaders = []HeaderField{ErrCount, TXCount, TXH, TXL, TXT, DroppedPackets, MemoryHigh, MemoryLow, CPUHigh, CPULow} - RealTimeLatencyHeaders = []HeaderField{ErrCount, TXCount, TXH, TXL, TXT, RMSH, RMSL, TTFBH, TTFBL, DroppedPackets, MemoryHigh, MemoryLow, CPUHigh, CPULow} + // TX(avg) is inserted next to the existing extremes; every other column + // keeps its position so the live output stays recognizable. + RealTimeBandwidthHeaders = []HeaderField{ErrCount, TXCount, TXH, TXL, TXA, TXT, DroppedPackets, MemoryHigh, MemoryLow, CPUHigh, CPULow} + RealTimeLatencyHeaders = []HeaderField{ErrCount, TXCount, TXH, TXL, TXA, TXT, RMSH, RMSL, TTFBH, TTFBL, DroppedPackets, MemoryHigh, MemoryLow, CPUHigh, CPULow} ) var ( @@ -136,11 +154,8 @@ var ( ) func printHeader(fields []HeaderField) { - if headerSlice[0].width == 0 { - initHeaders() - } fs := GenerateFormatString(len(fields)) - hs := make([]interface{}, 0) + hs := make([]any, 0) for i := range fields { h := headerSlice[fields[i]] hs = append(hs, h.width, h.label) @@ -151,7 +166,7 @@ func printHeader(fields []HeaderField) { func PrintPercentilesHeader(style lipgloss.Style, tag string, dps []int64, c shared.Config) { fs := GenerateFormatString(6) - hs := []interface{}{ + hs := []any{ 4, tag, 10, "count", 10, "sum", @@ -167,7 +182,7 @@ func PrintPercentilesHeader(style lipgloss.Style, tag string, dps []int64, c sha func PrintPercentiles(style lipgloss.Style, tag string, dps []int64, c shared.Config) { PrintPercentilesHeader(style, tag, dps, c) fs := GenerateFormatString(6) - hs := make([]interface{}, 12) + hs := make([]any, 12) hs[0] = 4 hs[1] = "" hs[2] = 10 @@ -196,7 +211,7 @@ func PrintPercentiles(style lipgloss.Style, tag string, dps []int64, c shared.Co func PrintColumns(style lipgloss.Style, columns ...column) { fs := GenerateFormatString(len(columns)) - hs := make([]interface{}, 0) + hs := make([]any, 0) for i := range columns { hs = append(hs, columns[i].width, columns[i].value) } @@ -235,6 +250,7 @@ func printRealTimeRow(style lipgloss.Style, entry *shared.TestOutput, t shared.T column{formatUint(entry.TXC), headerSlice[TXCount].width}, column{shared.BWToString(entry.TXH), headerSlice[TXH].width}, column{shared.BWToString(entry.TXL), headerSlice[TXL].width}, + column{shared.BWToString(entry.TXA), headerSlice[TXA].width}, column{shared.BToString(entry.TXT), headerSlice[TXT].width}, column{formatInt(int64(entry.DP)), headerSlice[DroppedPackets].width}, column{formatInt(int64(entry.MH)), headerSlice[MemoryHigh].width}, @@ -250,6 +266,7 @@ func printRealTimeRow(style lipgloss.Style, entry *shared.TestOutput, t shared.T column{formatUint(entry.TXC), headerSlice[TXCount].width}, column{shared.BWToString(entry.TXH), headerSlice[TXH].width}, column{shared.BWToString(entry.TXL), headerSlice[TXL].width}, + column{shared.BWToString(entry.TXA), headerSlice[TXA].width}, column{shared.BToString(entry.TXT), headerSlice[TXT].width}, column{formatInt(entry.RMSH), headerSlice[RMSH].width}, column{formatInt(entry.RMSL), headerSlice[RMSL].width}, @@ -290,7 +307,7 @@ func printTableRow(style lipgloss.Style, entry *shared.DP, t shared.TestType) { column{formatInt(entry.RMSH), headerSlice[RMSH].width}, column{formatInt(entry.RMSL), headerSlice[RMSL].width}, column{formatInt(entry.TTFBH), headerSlice[TTFBH].width}, - column{formatInt(entry.TTFBL), headerSlice[TTFBH].width}, + column{formatInt(entry.TTFBL), headerSlice[TTFBL].width}, column{shared.BWToString(entry.TX), headerSlice[TX].width}, column{formatUint(entry.TXCount), headerSlice[TXCount].width}, column{formatInt(int64(entry.ErrCount)), headerSlice[ErrCount].width}, @@ -303,7 +320,21 @@ func printTableRow(style lipgloss.Style, entry *shared.DP, t shared.TestType) { } } -func collectDataPointv2(r *shared.DataReponseToClient) { +// ingest folds a batch into the live aggregate and, when retention is on, into +// the data point slice. Callers must hold responseLock. +func ingest(host string, r *shared.DataReponseToClient) { + for i := range r.DPS { + liveAggregate.add(host, r.DPS[i]) + } + liveAggregate.addErrors(len(r.Errors)) + + if retainDPS { + responseDPS = append(responseDPS, r.DPS...) + } + responseERR = append(responseERR, r.Errors...) +} + +func collectDataPointv2(host string, r *shared.DataReponseToClient) { if r == nil { return } @@ -311,11 +342,10 @@ func collectDataPointv2(r *shared.DataReponseToClient) { responseLock.Lock() defer responseLock.Unlock() - responseDPS = append(responseDPS, r.DPS...) - responseERR = append(responseERR, r.Errors...) + ingest(host, r) } -func printAndCollectDataPoints(r *shared.DataReponseToClient, c *shared.Config) { +func printAndCollectDataPoints(host string, r *shared.DataReponseToClient, c *shared.Config) { if r == nil { return } @@ -329,8 +359,8 @@ func printAndCollectDataPoints(r *shared.DataReponseToClient, c *shared.Config) c.TestType = r.DPS[0].Type } grew := growHostColumns(r.DPS) - if len(responseDPS) > 0 { - if grew || len(responseDPS)%10 == 0 { + if printedRows > 0 { + if grew || printedRows%10 == 0 { printDataPointHeaders(c.TestType) } } else { @@ -343,16 +373,21 @@ func printAndCollectDataPoints(r *shared.DataReponseToClient, c *shared.Config) r.DPS[i].Received = time.Now() entry := r.DPS[i] printTableRow(BaseStyle, &entry, entry.Type) + printedRows++ } for i := range r.Errors { PrintTError(r.Errors[i]) } - responseDPS = append(responseDPS, r.DPS...) - responseERR = append(responseERR, r.Errors...) + ingest(host, r) } +// printedRows counts rows emitted by the attached-client view. It used to be +// derived from len(responseDPS), which stops being a row count as soon as +// retention is off. Guarded by responseLock. +var printedRows int + // Helper functions to format int/uint values for table display func formatInt(val int64) string { return strconv.FormatInt(val, 10) diff --git a/cmd/hperf/latency.go b/cmd/hperf/latency.go index 4490689..9c88608 100644 --- a/cmd/hperf/latency.go +++ b/cmd/hperf/latency.go @@ -64,12 +64,23 @@ func runLatency(ctx *cli.Context) error { return err } config.TestType = shared.RequestTest - config.BufferSize = 1000 - config.PayloadSize = 1000 - config.Concurrency = 1 - config.RequestDelay = 200 config.RestartOnError = true + // The latency command is a deliberately gentle probe, so it pins a small + // payload, one request in flight and a delay between requests. The requests + // command shares this action but advertises these flags in its own help, + // where they were silently overwritten -- so an explicitly set flag wins + // and anything left alone keeps the probe default. + setOrDefault := func(name string, dst *int, def int) { + if !ctx.IsSet(name) { + *dst = def + } + } + setOrDefault(bufferSizeFlag.Name, &config.BufferSize, 1000) + setOrDefault(payloadSizeFlag.Name, &config.PayloadSize, 1000) + setOrDefault(concurrencyFlag.Name, &config.Concurrency, 1) + setOrDefault(delayFlag.Name, &config.RequestDelay, 200) + fmt.Println("") shared.INFO(" Test ID:", config.TestID) fmt.Println("") diff --git a/cmd/hperf/main.go b/cmd/hperf/main.go index e98fd04..8cf8269 100644 --- a/cmd/hperf/main.go +++ b/cmd/hperf/main.go @@ -61,23 +61,10 @@ func InvalidFlagValueError(value interface{}, name string) error { } var ( - debug = false - insecure = false - globalFlags = []cli.Flag{ - hostsFlag, - portFlag, - insecureFlag, - concurrencyFlag, - delayFlag, - durationFlag, - bufferSizeFlag, - payloadSizeFlag, - restartOnErrorFlag, - testIDFlag, - saveTestFlag, - dnsServerFlag, - ipFamilyFlag, - } + debug = false + insecure = false + // Note: the app registers baseFlags globally; per-command flag sets are + // declared on each command. hostsFlag = cli.StringFlag{ Name: "hosts", EnvVar: "HPERF_HOSTS", @@ -250,12 +237,13 @@ func before(ctx *cli.Context) error { func parseConfig(ctx *cli.Context) (*shared.Config, error) { shared.DebugEnabled = debug + // Concurrency 0 would build a zero-capacity semaphore with no tokens in + // it, so every reader goroutine would block forever and the test would + // report nothing at all. This fallback used to be computed and then + // dropped on the floor, because the config below re-read the raw flag. concur := ctx.Int(concurrencyFlag.Name) - if concur == 0 { + if concur < 1 { concur = max(1, runtime.NumCPU()/2) - if concur == 0 { - concur = 1 - } } var config *shared.Config @@ -276,7 +264,7 @@ func parseConfig(ctx *cli.Context) (*shared.Config, error) { TestType: shared.RequestTest, Duration: ctx.Int(durationFlag.Name), RequestDelay: ctx.Int(delayFlag.Name), - Concurrency: ctx.Int(concurrencyFlag.Name), + Concurrency: concur, PayloadSize: ctx.Int(payloadSizeFlag.Name), BufferSize: ctx.Int(bufferSizeFlag.Name), Port: ctx.String(portFlag.Name), @@ -293,7 +281,11 @@ func parseConfig(ctx *cli.Context) (*shared.Config, error) { } switch ctx.Command.Name { - case "latency", "bandwidth", "http", "get": + // Every command that starts a test needs an ID. "requests" was missing + // here while "http" and "get" matched no command at all, so `hperf + // requests` ran with an empty TestID -- which made the server's + // resetTestFiles glob every file in --storage-path and delete it. + case "latency", "bandwidth", "requests": if ctx.String("id") == "" { config.TestID = strconv.Itoa(int(time.Now().Unix())) } @@ -340,7 +332,7 @@ func prettyprint(data *shared.Config, title string) { } fmt.Println(title, " ==============================") // outData := out.Bytes() - fmt.Println(string(out.Bytes())) + fmt.Println(out.String()) fmt.Println("=================") } diff --git a/cmd/hperf/requests.go b/cmd/hperf/requests.go index 10d6faf..6e2d903 100644 --- a/cmd/hperf/requests.go +++ b/cmd/hperf/requests.go @@ -19,8 +19,6 @@ package main import ( "github.com/minio/cli" - "github.com/minio/hperf/client" - "github.com/minio/hperf/shared" ) var requestsCMD = cli.Command{ @@ -65,16 +63,3 @@ EXAMPLES: {{.Prompt}} {{.HelpName}} --hosts 10.10.10.1,10.10.10.2 --request-delay 0 --concurrency 10 --payload-size 1000000 `, } - -func runRequests(ctx *cli.Context) error { - config, err := parseConfig(ctx) - if err != nil { - return cli.NewExitError(err.Error(), 1) - } - config.TestType = shared.RequestTest - err = client.RunTest(GlobalContext, *config) - if err != nil { - return cli.NewExitError(err.Error(), 1) - } - return nil -} diff --git a/cmd/hperf/stream.go b/cmd/hperf/stream.go deleted file mode 100644 index d024b05..0000000 --- a/cmd/hperf/stream.go +++ /dev/null @@ -1,76 +0,0 @@ -// Copyright (c) 2015-2024 MinIO, Inc. -// -// This file is part of MinIO Object Storage stack -// -// This program is free software: you can redistribute it and/or modify -// it under the terms of the GNU Affero General Public License as published by -// the Free Software Foundation, either version 3 of the License, or -// (at your option) any later version. -// -// This program is distributed in the hope that it will be useful -// but WITHOUT ANY WARRANTY; without even the implied warranty of -// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the -// GNU Affero General Public License for more details. -// -// You should have received a copy of the GNU Affero General Public License -// along with this program. If not, see . - -package main - -import ( - "github.com/minio/cli" - "github.com/minio/hperf/client" - "github.com/minio/hperf/shared" -) - -var streamCMD = cli.Command{ - Name: "stream", - Usage: "Start a test which uses an HTTP body stream to measure bandwidth", - Action: runStream, - Flags: []cli.Flag{ - hostsFlag, - portFlag, - concurrencyFlag, - durationFlag, - testIDFlag, - bufferSizeFlag, - payloadSizeFlag, - restartOnErrorFlag, - dnsServerFlag, - ipFamilyFlag, - saveTestFlag, - }, - CustomHelpTemplate: `NAME: - {{.HelpName}} - {{.Usage}} - -USAGE: - {{.HelpName}} [FLAGS] - -NOTE: - Matching concurrency with your thread count can often lead to - improved performance, it is even better to run concurrency at - 50% of the GOMAXPROCS. - -FLAGS: - {{range .VisibleFlags}}{{.}} - {{end}} -EXAMPLES: - 1. Run a basic test: - {{.Prompt}} {{.HelpName}} --hosts 10.10.10.1,10.10.10.2 - - 2. Run a test with custom concurrency: - {{.Prompt}} {{.HelpName}} --hosts 10.10.10.1,10.10.10.2 --concurrency 24 - - 3. Run a test with custom buffer and payload size: - {{.Prompt}} {{.HelpName}} --hosts 10.10.10.1,10.10.10.2 --bufferSize 9000 --payloadSize 9000 -`, -} - -func runStream(ctx *cli.Context) error { - config, err := parseConfig(ctx) - if err != nil { - return cli.NewExitError(err.Error(), 1) - } - config.TestType = shared.StreamTest - return client.RunTest(GlobalContext, *config) -} diff --git a/helm/hperf/Chart.yaml b/helm/hperf/Chart.yaml index d2b3c4e..f9924d5 100644 --- a/helm/hperf/Chart.yaml +++ b/helm/hperf/Chart.yaml @@ -15,10 +15,10 @@ type: application # This is the chart version. This version number should be incremented each time you make changes # to the chart and its templates, including the app version. # Versions are expected to follow Semantic Versioning (https://semver.org/) -version: v5.0.6 +version: v5.2.0 # This is the version number of the application being deployed. This version number should be # incremented each time you make changes to the application. Versions are not expected to # follow Semantic Versioning. They should reflect the version the application is using. # It is recommended to use it with quotes. -appVersion: "5.0.6" +appVersion: "5.2.0" diff --git a/helm/hperf/templates/latency-job.yaml b/helm/hperf/templates/latency-job.yaml index 6ed031f..e72b4c2 100644 --- a/helm/hperf/templates/latency-job.yaml +++ b/helm/hperf/templates/latency-job.yaml @@ -41,10 +41,10 @@ spec: - "--duration" - "{{ .Values.latency.duration }}" {{- end }} - {{- if .Values.bandwidth.printAll }} + {{- if .Values.latency.printAll }} - "--print-all" {{- end }} - {{- if .Values.bandwidth.micro }} + {{- if .Values.latency.micro }} - "--micro" {{- end }} resources: diff --git a/helm/hperf/values.yaml b/helm/hperf/values.yaml index 01c1062..0b7885c 100644 --- a/helm/hperf/values.yaml +++ b/helm/hperf/values.yaml @@ -8,7 +8,7 @@ image: repository: quay.io/minio/hperf pullPolicy: Always # Overrides the image tag whose default is the chart appVersion. - tag: v5.0.6 + tag: v5.2.0 imagePullSecrets: [] diff --git a/server/file.go b/server/file.go index 875894f..1d51004 100644 --- a/server/file.go +++ b/server/file.go @@ -19,66 +19,110 @@ package server import ( "bufio" + "errors" + "fmt" "os" "path/filepath" "strconv" "strings" - "github.com/gofiber/contrib/websocket" "github.com/minio/hperf/shared" ) -func streamTestFilesToWebsocket(con *websocket.Conn, testID string) (err error) { +// testGlob builds the pattern matching one test's files. +// +// Read and delete paths deliberately do NOT apply shared.ValidateTestID: files +// already on disk may have been written by an older server under no rules at +// all, and rejecting them here would leave a long-lived server pod listing +// tests it then refuses to serve or remove. The property that actually matters +// is that the pattern cannot escape the storage directory, which is what this +// checks. ValidateTestID still governs IDs that become NEW paths, in newTest. +func testGlob(id string) (string, error) { + if id == "" { + return "", errors.New("test id is empty") + } + base := filepath.Clean(basePath) + pattern := filepath.Join(base, id+".*") + // Join cleans its result, so an id carrying a separator or ".." moves the + // pattern out of the storage directory and its parent stops being base. + if filepath.Dir(pattern) != base { + return "", fmt.Errorf("invalid test id (%s)", id) + } + return pattern, nil +} + +func streamTestFilesToWebsocket(p *wsPeer, testID string) (err error) { + pattern, err := testGlob(testID) + if err != nil { + return err + } + var files []string - files, err = filepath.Glob(filepath.Join(basePath, testID+".*")) + files, err = filepath.Glob(pattern) if err != nil { return } msg := new(shared.WebsocketSignal) for _, path := range files { - f, err := os.Open(path) - if err != nil { + if err = streamOneTestFile(p, msg, path); err != nil { return err } - s := bufio.NewScanner(f) - for s.Scan() { - msg.Data = s.Bytes() - msg.SType = shared.GetTest - msg.Code = 200 - err = con.WriteJSON(msg) - if err != nil { - return err - } - } - if s.Err() != nil { - return s.Err() - } } return nil } -func deleteTestsFromDisk(con *websocket.Conn, signal shared.WebsocketSignal) (err error) { - defer SendDone(con) +// streamOneTestFile is a separate function so the file is closed when it +// returns. Opening inside the caller's loop leaked one descriptor per file per +// download, for the lifetime of the server, and every error return leaked too. +func streamOneTestFile(p *wsPeer, msg *shared.WebsocketSignal, path string) error { + f, err := os.Open(path) + if err != nil { + return err + } + defer f.Close() + + s := bufio.NewScanner(f) + for s.Scan() { + msg.Data = s.Bytes() + msg.SType = shared.GetTest + msg.Code = 200 + if err := p.writeJSON(msg); err != nil { + return err + } + } + return s.Err() +} + +func deleteTestsFromDisk(p *wsPeer, signal shared.WebsocketSignal) (err error) { + defer SendDone(p) + // An empty ID means "delete every test", which is what `hperf delete` + // without --id asks for. It has to return here: falling through would glob + // ".*" against a directory that no longer exists. if signal.Config.TestID == "" { - err = os.RemoveAll(basePath) - if err != nil { - SendError(con, err) + if err = os.RemoveAll(basePath); err != nil { + SendError(p, err) } + return + } + + pattern, err := testGlob(signal.Config.TestID) + if err != nil { + SendError(p, err) + return } var files []string - files, err = filepath.Glob(filepath.Join(basePath, signal.Config.TestID+".*")) + files, err = filepath.Glob(pattern) if err != nil { - SendError(con, err) + SendError(p, err) return } for _, path := range files { - err = os.Remove(path) - if err != nil { - SendError(con, err) + if err = os.Remove(path); err != nil { + SendError(p, err) } } @@ -110,8 +154,15 @@ func listTestsFromDisk() (finalList []shared.TestInfo, err error) { } func resetTestFiles(t *test) (err error) { + if err = shared.ValidateTestID(t.ID); err != nil { + return + } + + // The pattern is anchored with the separator. Without it, "--id test" + // matched -- and deleted -- test2.1, testing.1 and every other test whose + // ID merely started with "test", and an empty ID matched everything. var files []string - files, err = filepath.Glob(filepath.Join(basePath, t.ID+"*")) + files, err = filepath.Glob(filepath.Join(basePath, t.ID+".*")) if err != nil { return } diff --git a/server/regress_test.go b/server/regress_test.go new file mode 100644 index 0000000..dcbc4d2 --- /dev/null +++ b/server/regress_test.go @@ -0,0 +1,506 @@ +// Copyright (c) 2015-2024 MinIO, Inc. +// +// This file is part of MinIO Object Storage stack +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU Affero General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU Affero General Public License for more details. +// +// You should have received a copy of the GNU Affero General Public License +// along with this program. If not, see . + +package server + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "math" + "net/http" + "net/http/httptest" + "os" + "path/filepath" + "runtime" + "strings" + "sync" + "testing" + "time" + + "github.com/minio/hperf/shared" +) + +// newTestForTest builds a test with synthetic readers and a temporary storage +// path. It deliberately goes through newTest so the validation and file setup +// under examination are the real ones. +func newTestForTest(tb testing.TB, cfg shared.Config, peers ...string) *test { + tb.Helper() + + dir := tb.TempDir() + oldBase, oldReal, oldBind := basePath, realIP, bindAddress + basePath = dir + string(os.PathSeparator) + realIP = "10.99.0.1" + bindAddress = "10.99.0.1:9010" + tb.Cleanup(func() { + basePath, realIP, bindAddress = oldBase, oldReal, oldBind + testLock.Lock() + tests = make([]*test, 0) + testLock.Unlock() + }) + + if len(peers) == 0 { + peers = []string{"10.99.0.2", "10.99.0.3"} + } + cfg.Hosts = peers + if cfg.Port == "" { + cfg.Port = "9010" + } + if cfg.PayloadSize == 0 { + cfg.PayloadSize = 1024 + } + if cfg.Concurrency == 0 { + cfg.Concurrency = 2 + } + + t, err := newTest(cfg) + if err != nil { + tb.Fatalf("newTest: %v", err) + } + return t +} + +// TestConsAndStateAreRaceFree covers the crash this work started from: cons was +// written by two goroutines while a third iterated and deleted from it, which +// is an unrecoverable runtime throw rather than a catchable panic. Run with +// -race. +func TestConsAndStateAreRaceFree(t *testing.T) { + tst := newTestForTest(t, shared.Config{TestType: shared.StreamTest, TestID: "racetest"}) + + var wg sync.WaitGroup + stop := make(chan struct{}) + work := func(f func(i int)) { + wg.Add(1) + go func() { + defer wg.Done() + for i := 0; ; i++ { + select { + case <-stop: + return + default: + } + f(i) + } + }() + } + + // A client attaching, the documented --id reattach flow. + work(func(int) { tst.attach(&wsPeer{pid: fmt.Sprint(time.Now().UnixNano())}) }) + // The sampling loop shipping stats. + work(func(int) { sendAndSaveData(tst) }) + // Request goroutines reporting failures. + work(func(i int) { tst.AddError(errors.New("boom"), fmt.Sprint(i%8)) }) + // The sampler producing data points. + work(func(int) { generateDataPoints(tst) }) + // Another command walking the test list. + work(func(int) { _ = snapshotTests() }) + + time.Sleep(1500 * time.Millisecond) + close(stop) + wg.Wait() +} + +// TestStreamReaderReportsEveryInterval guards the trap in the Read fast path: +// hasStats has to be set on every chunk, not only alongside the one-shot TTFB +// registration. A stream request never completes, so gating it on the first +// chunk silently deletes every bandwidth data point after the first interval. +func TestStreamReaderReportsEveryInterval(t *testing.T) { + cfg := shared.Config{TestType: shared.StreamTest, TestID: "streamintervals"} + tst := newTestForTest(t, cfg, "10.99.0.2") + r := tst.Readers[0] + + ar := &asyncReader{pr: r, c: &tst.Config, ctx: context.Background(), start: time.Now()} + buf := make([]byte, 512) + + for interval := 1; interval <= 3; interval++ { + // One request, many chunks -- what a stream test actually does. + for i := 0; i < 20; i++ { + if _, err := ar.Read(buf); err != nil { + t.Fatalf("interval %d: read: %v", interval, err) + } + } + r.lastDataPointTime = time.Now().Add(-time.Second) + + tst.DPS = nil + generateDataPoints(tst) + + tst.M.Lock() + got := len(tst.DPS) + tst.M.Unlock() + if got != 1 { + t.Fatalf("interval %d: got %d data points, want 1 -- the reader stopped reporting", interval, got) + } + } +} + +// TestGenerateDataPointsRateUsesMeasuredWindow pins the property that makes the +// "statistics stall depresses throughput" theory false: the rate divides by the +// measured window, so a slow sampling loop cannot bias it. +func TestGenerateDataPointsRateUsesMeasuredWindow(t *testing.T) { + const offered = 100 << 20 // bytes per second + + for i, window := range []time.Duration{time.Second, 1500 * time.Millisecond, 3 * time.Second, 10 * time.Second} { + tst := newTestForTest(t, shared.Config{ + TestType: shared.StreamTest, + TestID: fmt.Sprintf("ratewindow-%d", i), + }, "10.99.0.2") + r := tst.Readers[0] + r.TX.Store(uint64(float64(offered) * window.Seconds())) + r.hasStats.Store(true) + r.lastDataPointTime = time.Now().Add(-window) + + generateDataPoints(tst) + + tst.M.Lock() + dps := tst.DPS + tst.M.Unlock() + if len(dps) != 1 { + t.Fatalf("window %s: got %d data points", window, len(dps)) + } + errPct := (float64(dps[0].TX) - offered) / offered * 100 + if math.Abs(errPct) > 1 { + t.Errorf("window %s: rate off by %.2f%% (got %d)", window, errPct, dps[0].TX) + } + } +} + +// TestShortWindowProducesNoDataPoint guards against a rate computed over a +// window too short to mean anything. The final flush lands microseconds after +// the last scheduled sample, and bytes/elapsed over that window yields a figure +// orders of magnitude above line rate -- which then becomes TX(max). Measured +// at 2.37 GB/s against a 726 MB/s steady state before this guard. +func TestShortWindowProducesNoDataPoint(t *testing.T) { + tst := newTestForTest(t, shared.Config{ + TestType: shared.StreamTest, TestID: "shortwindow", + }, "10.99.0.2") + r := tst.Readers[0] + + // A full window emits, and the bytes are attributed to it. + r.TX.Store(100 << 20) + r.hasStats.Store(true) + r.lastDataPointTime = time.Now().Add(-time.Second) + generateDataPoints(tst) + + tst.M.Lock() + first := len(tst.DPS) + tst.M.Unlock() + if first != 1 { + t.Fatalf("full window produced %d data points, want 1", first) + } + + // An immediate second pass is the final-flush case: same bytes rate, but + // microseconds of window. It must not emit. + r.TX.Store(352000) + r.hasStats.Store(true) + generateDataPoints(tst) + + tst.M.Lock() + second := len(tst.DPS) + tst.M.Unlock() + if second != first { + tst.M.Lock() + rate := tst.DPS[len(tst.DPS)-1].TX + tst.M.Unlock() + t.Errorf("sub-threshold window emitted a data point reporting %s", + shared.BWToString(rate)) + } + + // The skipped bytes must still be there, not silently dropped, so the next + // real sample accounts for them. + if got := r.TX.Load(); got != 352000 { + t.Errorf("skipped window lost its bytes: TX = %d, want 352000", got) + } + if !r.hasStats.Load() { + t.Error("skipped window cleared hasStats, so the reader would miss its next sample") + } +} + +// TestPersistedRecordFormat is the on-disk golden: one prefix byte, the JSON, +// then a newline. Anything that changes this breaks download, analyze and csv. +func TestPersistedRecordFormat(t *testing.T) { + tst := newTestForTest(t, shared.Config{ + TestType: shared.StreamTest, TestID: "formatgolden", Save: true, + }, "10.99.0.2") + + dp := shared.DP{ + Type: shared.StreamTest, TestID: "formatgolden", + Created: time.Unix(1700000000, 0).UTC(), + Local: "10.99.0.1", Remote: "10.99.0.2:9010", + TX: 1000, TXTotal: 1000, TXCount: 3, DroppedPackets: -1, + } + terr := shared.TError{Error: "boom", Created: time.Unix(1700000001, 0).UTC()} + + persist(tst, []shared.DP{dp}, []shared.TError{terr}) + if err := tst.DataFile.Sync(); err != nil { + t.Fatal(err) + } + + raw, err := os.ReadFile(tst.DataFile.Name()) + if err != nil { + t.Fatal(err) + } + lines := strings.Split(strings.TrimSuffix(string(raw), "\n"), "\n") + if len(lines) != 2 { + t.Fatalf("got %d lines, want 2: %q", len(lines), raw) + } + if lines[0][0] != '0' { + t.Errorf("data point prefix = %q, want '0'", lines[0][0]) + } + if lines[1][0] != '1' { + t.Errorf("error point prefix = %q, want '1'", lines[1][0]) + } + + var roundTripped shared.DP + if err := json.Unmarshal([]byte(lines[0][1:]), &roundTripped); err != nil { + t.Fatalf("data point does not parse: %v", err) + } + if roundTripped.TXCount != dp.TXCount || roundTripped.Remote != dp.Remote { + t.Errorf("round trip mismatch: %+v", roundTripped) + } + var errRoundTripped shared.TError + if err := json.Unmarshal([]byte(lines[1][1:]), &errRoundTripped); err != nil { + t.Fatalf("error point does not parse: %v", err) + } + if errRoundTripped.Error != "boom" { + t.Errorf("error round trip mismatch: %+v", errRoundTripped) + } +} + +// TestResetTestFilesIsAnchored covers silent data loss: the cleanup glob had no +// separator, so starting "--id test" deleted every saved test whose ID merely +// began with "test". +func TestResetTestFilesIsAnchored(t *testing.T) { + dir := t.TempDir() + oldBase := basePath + basePath = dir + string(os.PathSeparator) + t.Cleanup(func() { basePath = oldBase }) + + keep := []string{"test2.1", "testing.1", "other.1"} + for _, name := range append([]string{"test.1", "test.2"}, keep...) { + if err := os.WriteFile(filepath.Join(dir, name), []byte("x"), 0o600); err != nil { + t.Fatal(err) + } + } + + if err := resetTestFiles(&test{ID: "test"}); err != nil { + t.Fatalf("resetTestFiles: %v", err) + } + + for _, name := range keep { + if _, err := os.Stat(filepath.Join(dir, name)); err != nil { + t.Errorf("%s was deleted by a test with id \"test\"", name) + } + } + for _, name := range []string{"test.1", "test.2"} { + if _, err := os.Stat(filepath.Join(dir, name)); !os.IsNotExist(err) { + t.Errorf("%s should have been removed", name) + } + } +} + +// TestUnsafeTestIDRejected keeps a client-supplied id from escaping the storage +// directory, and keeps an empty id from matching every saved test. +func TestUnsafeTestIDRejected(t *testing.T) { + for _, id := range []string{"", "../escape", "a/b", "a*b", ".", "..", strings.Repeat("x", 65)} { + if err := shared.ValidateTestID(id); err == nil { + t.Errorf("ValidateTestID(%q) = nil, want an error", id) + } + } + for _, id := range []string{"1755600000", "bandwidth-30", "my_test.1", "A-b_c.9"} { + if err := shared.ValidateTestID(id); err != nil { + t.Errorf("ValidateTestID(%q) = %v, want nil", id, err) + } + } +} + +func openFDs(tb testing.TB) int { + tb.Helper() + if runtime.GOOS != "linux" { + tb.Skip("fd counting needs /proc") + } + entries, err := os.ReadDir("/proc/self/fd") + if err != nil { + tb.Fatal(err) + } + return len(entries) +} + +// TestStreamOneTestFileClosesFile covers the descriptor leak: the file was +// opened inside the caller's loop with no Close, so every download cost the +// server one permanently open descriptor per file. +func TestStreamOneTestFileClosesFile(t *testing.T) { + dir := t.TempDir() + path := filepath.Join(dir, "leak.1") + if err := os.WriteFile(path, []byte("0{}\n0{}\n"), 0o600); err != nil { + t.Fatal(err) + } + + // A peer with no connection makes every write fail, which exercises the + // early-return path that leaked in addition to the normal one. + peer := &wsPeer{pid: "p"} + before := openFDs(t) + for i := 0; i < 200; i++ { + _ = streamOneTestFile(peer, new(shared.WebsocketSignal), path) + } + if after := openFDs(t); after > before+2 { + t.Errorf("descriptors grew from %d to %d over 200 calls", before, after) + } +} + +// TestNonOKResponseReleasesConnection covers the other unbounded leak: a non-200 +// reply returned without closing the body, so net/http could never reuse or +// release the connection and each failure burned an fd and two goroutines. +func TestNonOKResponseReleasesConnection(t *testing.T) { + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + _, _ = io_Copy_Discard(r) + w.WriteHeader(http.StatusServiceUnavailable) + })) + defer srv.Close() + + cfg := shared.Config{ + TestType: shared.RequestTest, TestID: "leakcheck", + Insecure: true, PayloadSize: 512, Concurrency: 1, + } + host := strings.TrimPrefix(srv.URL, "http://") + hostOnly, port, _ := strings.Cut(host, ":") + tst := newTestForTest(t, cfg, hostOnly) + tst.Config.Port = port + + r := newPerformanceReaderForASingleHost(tst.Config, hostOnly, port) + tst.Readers = []*netPerfReader{r} + + // sendRequestToHost returns its slot to the concurrency semaphore on the + // way out, and the semaphore starts full, so a direct call has to take a + // slot first or the return blocks forever. + call := func() { + cid := <-r.concurrency + sendRequestToHost(tst, r, cid) + } + + // Warm up so the initial pool allocations are not counted. + for i := 0; i < 20; i++ { + call() + } + before := openFDs(t) + beforeG := runtime.NumGoroutine() + + for i := 0; i < 300; i++ { + call() + } + + time.Sleep(200 * time.Millisecond) + after := openFDs(t) + afterG := runtime.NumGoroutine() + + if after > before+8 { + t.Errorf("descriptors grew from %d to %d over 300 failed requests", before, after) + } + if afterG > beforeG+16 { + t.Errorf("goroutines grew from %d to %d over 300 failed requests", beforeG, afterG) + } +} + +func io_Copy_Discard(r *http.Request) (int64, error) { + defer r.Body.Close() + buf := make([]byte, 32*1024) + var total int64 + for { + n, err := r.Body.Read(buf) + total += int64(n) + if err != nil { + return total, nil + } + } +} + +// TestFinishReclaimsReaderBuffers covers the retention leak: a finished test +// kept one PayloadSize buffer and one http.Client per peer alive for the +// server's lifetime. +func TestFinishReclaimsReaderBuffers(t *testing.T) { + tst := newTestForTest(t, shared.Config{ + TestType: shared.StreamTest, TestID: "reclaim", PayloadSize: 1 << 20, + }, "10.99.0.2", "10.99.0.3") + + for _, r := range tst.Readers { + if len(r.buf) == 0 { + t.Fatal("reader has no payload buffer before finish") + } + } + + tst.finish() + + // The readers must be released by dropping the reference, not by zeroing + // fields on them: request goroutines still hold their own pointers and may + // be inside Read, copying from r.buf. + if tst.Readers != nil { + t.Errorf("finish() left %d readers referenced, so their payload buffers cannot be collected", len(tst.Readers)) + } + if tst.live() { + t.Error("test still reports itself as live after finish") + } + if tst.attach(&wsPeer{pid: "late"}) { + t.Error("attach succeeded on a finished test") + } +} + +// TestFinishLeavesPeersWritable guards a subtle liveness bug: createAndRunTest +// sends Done over the peer that started the test, and that send happens after +// finish() runs. If finish() retired the attached peers, the write would be +// refused, the client would never see Done, and every run would hang until its +// grace period expired instead of completing. +func TestFinishLeavesPeersWritable(t *testing.T) { + tst := newTestForTest(t, shared.Config{ + TestType: shared.StreamTest, TestID: "donepath", + }, "10.99.0.2") + + peer := &wsPeer{pid: "starter"} + if !tst.attach(peer) { + t.Fatal("attach failed on a live test") + } + + tst.finish() + + if peer.dead.Load() { + t.Fatal("finish() retired an attached peer, so Done can never be sent") + } + // The test must also have stopped tracking it, so nothing writes to a + // client the test no longer owns. + tst.M.Lock() + remaining := len(tst.cons) + tst.M.Unlock() + if remaining != 0 { + t.Errorf("finish() left %d peers attached", remaining) + } +} + +// TestDuplicateLiveTestIDRejected stops a second run from clobbering the files +// of one already in progress. +func TestDuplicateLiveTestIDRejected(t *testing.T) { + tst := newTestForTest(t, shared.Config{ + TestType: shared.StreamTest, TestID: "dupe", Save: true, + }, "10.99.0.2") + + if _, err := newTest(tst.Config); err == nil { + t.Error("a second test with a live id was accepted") + } + + tst.finish() + if _, err := newTest(tst.Config); err != nil { + t.Errorf("reusing the id of a finished test should be allowed: %v", err) + } +} diff --git a/server/server.go b/server/server.go index cc39e84..243624a 100644 --- a/server/server.go +++ b/server/server.go @@ -18,7 +18,7 @@ package server import ( - "bytes" + "bufio" "context" "encoding/json" "errors" @@ -38,6 +38,7 @@ import ( "sync/atomic" "time" + fwebsocket "github.com/fasthttp/websocket" "github.com/gofiber/contrib/websocket" "github.com/gofiber/fiber/v2" "github.com/google/uuid" @@ -46,6 +47,32 @@ import ( "github.com/shirou/gopsutil/mem" ) +const ( + // fasthttp allocates a bufio.Reader and bufio.Writer of these sizes for + // every concurrent connection, so they are a per-connection memory cost, + // not a one-off. At 1 MB each they cost ~1 MiB of RSS per inbound + // connection, and a full mesh opens (hosts-1) * concurrency of them: + // 8064 connections, ~8 GiB, on 64 hosts at the default concurrency. + // + // The only hard requirement is that the largest inbound request *header* + // fits in the read buffer, otherwise fasthttp answers 431. hperf's + // requests are PUT /stream and PUT /requests plus the websocket upgrade, + // all of which carry a handful of small headers; --payload-size affects + // the body, which is streamed and never buffered whole. 64 KiB leaves an + // order of magnitude of headroom over anything hperf generates. + serverReadBufferSize = 64 * 1024 + serverWriteBufferSize = 64 * 1024 + + // A client that stops reading must not be able to stall the test it is + // attached to, so every write to a client socket is bounded. + wsWriteTimeout = 5 * time.Second + + // minSampleWindow is the shortest interval that produces a meaningful + // rate. Anything shorter is dropped rather than divided out; see + // generateDataPoints. + minSampleWindow = 100 * time.Millisecond +) + var ( httpServer = fiber.New(fiber.Config{ Network: fiber.NetworkTCP, @@ -53,8 +80,8 @@ var ( ServerHeader: "hperf", AppName: "hperf", DisableStartupMessage: true, - ReadBufferSize: 1000000, - WriteBufferSize: 1000000, + ReadBufferSize: serverReadBufferSize, + WriteBufferSize: serverWriteBufferSize, }) bindAddress = "0.0.0.0:9000" realIP = "" @@ -64,6 +91,97 @@ var ( testLock = sync.Mutex{} ) +// wsPeer owns one client websocket, for two reasons. +// +// First, the *websocket.Conn handed to the /ws/:id handler is a pooled +// wrapper: gofiber/contrib/websocket assigns conn.Conn = fconn and, when the +// handler returns, releaseConn nils that field and puts the wrapper back in a +// sync.Pool for the next upgrade to claim. Tests deliberately outlive their +// client, so retaining the wrapper meant a later write either nil-dereferenced +// (silently, into the recover() in sendAndSaveData, once a second forever) or +// landed in an unrelated client's socket. We keep the inner conn, which is +// allocated fresh per upgrade and never pooled. +// +// Second, a test's sampling loop and any number of command handlers can target +// the same socket at once, and fasthttp/websocket panics on concurrent writes +// to the data path. wmu serializes them. It is a leaf lock: never acquire t.M +// or testLock while holding it. Control frames stay off it deliberately -- +// WriteControl serializes on its own channel mutex and the library's ping +// handler replies from the read loop, so routing pongs through wmu would queue +// them behind a slow data write and break liveness detection. +type wsPeer struct { + pid string + con *fwebsocket.Conn + wmu sync.Mutex + dead atomic.Bool +} + +func newPeer(c *websocket.Conn) *wsPeer { + return &wsPeer{pid: uuid.NewString(), con: c.Conn} +} + +func (p *wsPeer) writeJSON(v any) error { + if p == nil || p.con == nil || p.dead.Load() { + return net.ErrClosed + } + p.wmu.Lock() + defer p.wmu.Unlock() + if p.dead.Load() { + return net.ErrClosed + } + if err := p.con.SetWriteDeadline(time.Now().Add(wsWriteTimeout)); err != nil { + return err + } + return p.con.WriteJSON(v) +} + +// retire marks the peer unusable and waits for any write already in progress. +// It is called when the owning handler returns, which is when fasthttp reclaims +// the hijacked connection underneath us and puts it back in its pool -- so a +// write still inside con.WriteJSON at that moment would either hit a nil'd +// embedded conn or land in whichever connection claims the pooled object next. +// Taking the write mutex guarantees nobody is inside the conn once this returns. +func (p *wsPeer) retire() { + if p == nil { + return + } + p.wmu.Lock() + p.dead.Store(true) + p.wmu.Unlock() +} + +func (p *wsPeer) shutdown() { + if p == nil { + return + } + p.wmu.Lock() + p.dead.Store(true) + if p.con != nil { + _ = p.con.Close() + } + p.wmu.Unlock() +} + +// Locking contract for test, and the reason it is written down: the fields +// below are touched by the sampling goroutine, by every request goroutine via +// AddError, and by websocket handlers attaching clients. +// +// 1. testLock guards the package-level tests slice, and nothing else. +// 2. t.M guards errors, errMap, DPS and cons. +// 3. endedAt (UnixNano, 0 while running) carries liveness, so code that only +// needs to know whether a test is finished does not have to take t.M. +// 4. Readers, DataFile, DataFileIndex and netPerfReader.lastDataPointTime are +// owned by the single sampling goroutine, which is also the goroutine that +// runs finish(), and need no lock. Request goroutines hold their own +// *netPerfReader pointers, so those structs must never be mutated from +// here -- drop the slice reference instead and let GC reclaim them. +// 5. netPerfReader.m guards only TTFBH/TTFBL/RMSH/RMSL. hasStats is atomic. +// 6. No lock nesting: testLock, t.M and wsPeer.wmu are never held together. +// Iterators snapshot under one lock, release it, then do the work. +// 7. No blocking work -- socket write, disk write, fmt.Println -- while t.M is +// held. This is a deadlock rule as much as a stall rule: sync.Mutex is not +// reentrant and AddError takes t.M, so persisting under t.M would deadlock +// the moment a write failed and reported itself as an error. type test struct { ID string Config shared.Config @@ -72,33 +190,107 @@ type test struct { ctx context.Context cancel context.CancelCauseFunc - Readers []*netPerfReader - errors []shared.TError - errMap map[string]struct{} - errIndex atomic.Int32 - DPS []shared.DP - M sync.Mutex + Readers []*netPerfReader + errors []shared.TError + errMap map[string]struct{} + DPS []shared.DP + M sync.Mutex + + endedAt atomic.Int64 + + // dropped holds the interface drop counters sampled when the test began, + // so data points can report drops accumulated by this test rather than + // everything since boot. + dropped dropCounters DataFile *os.File DataFileIndex int - cons map[string]*websocket.Conn + cons map[string]*wsPeer } -func (t *test) AddError(err error, id string) { +func (t *test) live() bool { return t.endedAt.Load() == 0 } + +func (t *test) finish() { + if !t.endedAt.CompareAndSwap(0, time.Now().UnixNano()) { + return + } + + // Clearing cons stops the test writing to its clients, but the peers are + // deliberately NOT retired here: retiring is the owning handler's job, and + // createAndRunTest still has to send Done over the peer that started the + // test after this returns. + t.M.Lock() + t.cons = make(map[string]*wsPeer) + t.M.Unlock() + + // Reclaim the per-reader payload buffers and transports. A finished test + // used to keep one PayloadSize buffer and one http.Client per peer alive + // for the lifetime of the server -- 63 MB per run at 64 hosts with the + // default 1 MB payload. The test object itself stays in the slice so it + // remains listable and downloadable. + // + // Dropping the reference is what reclaims them. Zeroing fields on the + // readers instead would race: request goroutines hold their own pointers + // and may still be inside Read, copying from r.buf, when this runs. + readers := t.Readers + t.Readers = nil + + for _, r := range readers { + if r != nil && r.client != nil { + r.client.CloseIdleConnections() + } + } +} + +// attach registers a client socket with a running test. It reports false if the +// test has already finished, so callers can avoid handing a socket to a test +// that will never write to it again. +func (t *test) attach(p *wsPeer) bool { + if !t.live() { + return false + } + t.M.Lock() + defer t.M.Unlock() + if t.cons == nil { + return false + } + t.cons[p.pid] = p + return true +} + +func (t *test) detach(ids []string) { + if len(ids) == 0 { + return + } t.M.Lock() defer t.M.Unlock() + for _, id := range ids { + delete(t.cons, id) + } +} + +func (t *test) AddError(err error, id string) { if err == nil { return } - _, ok := t.errMap[id] - if ok { + debugOn := t.Config.Debug + + t.M.Lock() + if _, ok := t.errMap[id]; ok { + t.M.Unlock() return } - if t.Config.Debug { + t.errors = append(t.errors, shared.TError{ + Error: shared.TruncateError(err.Error()), + Created: time.Now(), + }) + t.errMap[id] = struct{}{} + t.M.Unlock() + + // Printing is I/O and must not happen under t.M. + if debugOn { fmt.Println("ERR:", err) } - t.errors = append(t.errors, shared.TError{Error: err.Error(), Created: time.Now()}) - t.errMap[id] = struct{}{} } func RunServer(ctx context.Context, address string, rIP string, storagePath string) (err error) { @@ -133,6 +325,12 @@ func RunServer(ctx context.Context, address string, rIP string, storagePath stri bindAddress = address realIP = rIP + statsInterface = resolveStatsInterface() + if statsInterface != "" { + shared.DEBUG("Reporting drop counters for interface:", statsInterface) + } else { + shared.DEBUG("Could not resolve an interface for drop counters, summing all non-loopback interfaces") + } shared.INFO("starting 'hperf' server on:", bindAddress) err = startAPIandWS(cancelContext) if err != nil { @@ -161,12 +359,16 @@ func startAPIandWS(ctx context.Context) (err error) { err error ) - err = SendPing(con) + // The wrapper con is pooled and reused by the next upgrade once this + // handler returns, so anything outliving the handler must hold the peer + // instead, and the peer must be retired here. + peer := newPeer(con) + defer peer.retire() + + err = SendPing(peer) if err != nil { shared.DEBUG("Error accepting client socket:", err) - if con != nil { - con.Close() - } + peer.shutdown() return } @@ -183,48 +385,53 @@ func startAPIandWS(ctx context.Context) (err error) { signal := new(shared.WebsocketSignal) err := json.Unmarshal(msg, signal) if err != nil { - if signal.Config.Debug { - log.Println("Unable to parse signal:", err) - } + log.Println("Unable to parse signal:", err) continue } if signal.Config.Debug { fmt.Printf("WebsocketSignal: %+v\n", signal) } + // These run inline rather than in their own goroutine. Spawning + // meant several handlers could target one socket concurrently and + // that a client could not tell when its command had been accepted; + // the read loop is per-connection already, so serializing here + // costs nothing but removes a whole class of interleaving. switch signal.SType { case shared.RunTest: - go createAndRunTest(con, *signal) + createAndRunTest(peer, *signal) case shared.ListenTest: - go listenToLiveTests(con, *signal) + listenToLiveTests(peer, *signal) case shared.ListTests: - go listAllTests(con, *signal) + listAllTests(peer, *signal) case shared.GetTest: - go getTestOnServer(con, *signal) + getTestOnServer(peer, *signal) case shared.Ping: - go replyToPing(con) + replyToPing(peer) case shared.DeleteTests: - go deleteTestsFromDisk(con, *signal) + deleteTestsFromDisk(peer, *signal) case shared.StopAllTests: - go stopAllTests(con, *signal) + stopAllTests(peer, *signal) case shared.Exit: os.Exit(1) default: - if signal.Config.Debug { - fmt.Println("unrecognized command") - } + shared.DEBUG("unrecognized command:", signal.SType) } } })) + // Both bodies are drained straight to Discard without being materialized. + // /requests used to call c.Body(), which buffers the whole payload in + // memory for every in-flight request: at the default 1 MB payload that is + // (hosts-1) * concurrency megabytes of garbage on the receive path. httpServer.Put("/requests", func(c *fiber.Ctx) error { - io.Copy(io.Discard, bytes.NewBuffer(c.Body())) + _, _ = io.Copy(io.Discard, c.Request().BodyStream()) return c.SendStatus(200) }) httpServer.Put("/stream", func(c *fiber.Ctx) error { - io.Copy(io.Discard, c.Request().BodyStream()) + _, _ = io.Copy(io.Discard, c.Request().BodyStream()) return c.SendStatus(200) }) @@ -235,7 +442,7 @@ func startAPIandWS(ctx context.Context) (err error) { listenErr <- httpServer.Listen(bindAddress) }() - routineMonitor <- 1 + go pollHostStats(ctx) for { select { @@ -244,128 +451,241 @@ func startAPIandWS(ctx context.Context) (err error) { return fmt.Errorf("unable to listen on %s: %w", bindAddress, lerr) } return nil - case id := <-routineMonitor: - if id == 1 { - go getServerStats(id) - } - default: + case <-ctx.Done(): + return httpServer.Shutdown() + case <-time.After(time.Second): } - if ctx.Err() != nil { - httpServer.Shutdown() - return - } - time.Sleep(1 * time.Second) } } -var ( - currentMemoryStat *mem.VirtualMemoryStat - droppedPackets int - cpuPercent float64 -) +// dropCounters holds cumulative interface drop counters. Both directions are +// tracked: the transmit column is the one that matters for a saturating sender +// and used to be ignored entirely. +type dropCounters struct { + rx uint64 + tx uint64 + ok bool +} -func getServerStats(id byte) { - defer func() { - r := recover() - if r != nil { - log.Println(r, string(debug.Stack())) - } - time.Sleep(1 * time.Second) - routineMonitor <- id - }() +func (d dropCounters) total() uint64 { return d.rx + d.tx } - var err error - currentMemoryStat, err = mem.VirtualMemory() - if err != nil { - fmt.Println(err) +// hostStats is an immutable snapshot published as a whole, so readers never see +// a half-updated set of values and never race with the poller. +type hostStats struct { + memUsedPercent int + cpuUsedPercent int + drops dropCounters +} + +var currentStats atomic.Pointer[hostStats] + +// statsInterface is the interface whose drop counters we report, resolved once +// from the address this server serves on. Empty means "sum every non-loopback +// interface", which is the best available answer on a wildcard bind with no +// --real-ip. +var statsInterface string + +func loadStats() hostStats { + if s := currentStats.Load(); s != nil { + return *s } + // Nothing polled yet. Reporting a zeroed snapshot with an unknown drop + // count is correct; dereferencing a nil pointer here used to panic the + // sampling goroutine, which has no recover, and take the server with it. + return hostStats{} +} - droppedPackets, err = GetDroppedPackets() - if err != nil { - fmt.Println(err) +func collectHostStats() { + s := hostStats{} + + if vm, err := mem.VirtualMemory(); err == nil && vm != nil { + s.memUsedPercent = int(math.Round(vm.UsedPercent)) + } else if err != nil { + shared.DEBUG("unable to read memory stats:", err) } - percent, err := cpu.Percent(time.Second, false) - if err != nil { - fmt.Println(err) + + // cpu.Percent blocks for the duration it is given, which is why this runs + // on its own ticker rather than inline with anything that matters. + if percent, err := cpu.Percent(time.Second, false); err == nil && len(percent) > 0 { + s.cpuUsedPercent = int(math.Round(percent[0])) + } else if err != nil { + shared.DEBUG("unable to read cpu stats:", err) } - if len(percent) > 0 { - cpuPercent = percent[0] + + s.drops = readDropCounters(statsInterface) + currentStats.Store(&s) +} + +func pollHostStats(ctx context.Context) { + // The interval is enforced here rather than relying on cpu.Percent to block + // for a second: gopsutil returns from it immediately if it cannot read the + // CPU counters, which would turn this into a tight loop re-reading + // /proc/meminfo and /proc/net/dev -- burning a core on the very host whose + // throughput is being measured. In the normal case the blocking CPU sample + // paces us and the ticker is already ready, so the period stays ~1s. + ticker := time.NewTicker(time.Second) + defer ticker.Stop() + + // The recover is per sample, so one panic costs a single reading rather + // than freezing host stats for the life of the process. + sample := func() { + defer func() { + if r := recover(); r != nil { + log.Println(r, string(debug.Stack())) + } + }() + collectHostStats() + } + + sample() + for { + select { + case <-ctx.Done(): + return + case <-ticker.C: + } + sample() } } -func GetDroppedPackets() (total int, err error) { +// readDropCounters sums the receive and transmit drop columns from +// /proc/net/dev. When iface is set only that interface is counted; otherwise +// every non-loopback, non-virtual interface is. The previous implementation +// summed the receive column across every interface including lo, wg0 and +// tunnels, and reported it as an absolute since-boot figure. +func readDropCounters(iface string) (d dropCounters) { if runtime.GOOS != "linux" { - return 0, nil + return } data, err := os.ReadFile("/proc/net/dev") if err != nil { - return 0, err + shared.DEBUG("unable to read /proc/net/dev:", err) + return } - lines := strings.Split(string(data), "\n") - for _, line := range lines[2:] { - fields := strings.Fields(line) - if len(fields) < 5 { + + for _, line := range strings.Split(string(data), "\n") { + // The name is separated by a colon and can abut it when counters are + // wide, so split on the colon rather than on whitespace. + colon := strings.IndexByte(line, ':') + if colon < 0 { continue } - dropped, err := strconv.Atoi(fields[4]) // Field 4 is for dropped packets - if err != nil { - return 0, err + name := strings.TrimSpace(line[:colon]) + if name == "" || strings.Contains(name, "|") { + continue + } + if iface != "" { + if name != iface { + continue + } + } else if name == "lo" { + continue + } + + // Receive: bytes packets errs drop fifo frame compressed multicast + // Transmit: bytes packets errs drop fifo colls carrier compressed + fields := strings.Fields(line[colon+1:]) + if len(fields) < 12 { + continue + } + rx, errRX := strconv.ParseUint(fields[3], 10, 64) + tx, errTX := strconv.ParseUint(fields[11], 10, 64) + if errRX != nil || errTX != nil { + continue } - total += dropped + d.rx += rx + d.tx += tx + d.ok = true } return } -var routineMonitor = make(chan byte, 100) +// resolveStatsInterface maps the address this server serves on to an interface +// name, so drop counters describe the link actually carrying the test. +func resolveStatsInterface() string { + candidate := realIP + if candidate == "" { + candidate = shared.HostOnly(bindAddress) + } + if candidate == "" { + return "" + } + addr, err := netip.ParseAddr(shared.NormalizeHost(candidate)) + if err != nil || addr.IsUnspecified() { + return "" + } + + interfaces, err := net.Interfaces() + if err != nil { + return "" + } + for _, intf := range interfaces { + addrs, err := intf.Addrs() + if err != nil { + continue + } + for _, a := range addrs { + prefix, err := netip.ParsePrefix(a.String()) + if err != nil { + continue + } + if prefix.Addr().Unmap() == addr.Unmap() { + return intf.Name + } + } + } + return "" +} -func replyToPing(c *websocket.Conn) { +func replyToPing(p *wsPeer) { msg := new(shared.WebsocketSignal) msg.SType = shared.Pong - _ = c.WriteJSON(msg) + _ = p.writeJSON(msg) } -func SendError(c *websocket.Conn, e error) error { +func SendError(p *wsPeer, e error) error { if e == nil { return nil } msg := new(shared.WebsocketSignal) msg.SType = shared.Err msg.Error = e.Error() - return c.WriteJSON(msg) + return p.writeJSON(msg) +} + +// snapshotTests copies the test pointers under testLock. The slice is appended +// to by newTest, so ranging over it without the lock was a torn read. +func snapshotTests() []*test { + testLock.Lock() + defer testLock.Unlock() + out := make([]*test, len(tests)) + copy(out, tests) + return out } -func stopAllTests(con *websocket.Conn, s shared.WebsocketSignal) { - defer SendDone(con) - for i := range tests { - if s.Config.TestID != "" && s.Config.TestID != tests[i].ID { +func stopAllTests(p *wsPeer, s shared.WebsocketSignal) { + defer SendDone(p) + for _, t := range snapshotTests() { + if s.Config.TestID != "" && s.Config.TestID != t.ID { continue } - if s.Config.Debug { - fmt.Println("Stopping:", tests[i].ID) - } - tests[i].cancel(fmt.Errorf("Client called StopAllTests")) + shared.DEBUG("Stopping:", t.ID) + t.cancel(errors.New("Client called StopAllTests")) } } -func SendPing(c *websocket.Conn) error { +func SendPing(p *wsPeer) error { msg := new(shared.WebsocketSignal) msg.SType = shared.Ping msg.Code = shared.OK - return c.WriteJSON(msg) -} - -func SendOK(c *websocket.Conn, t shared.SignalType) error { - msg := new(shared.WebsocketSignal) - msg.SType = t - msg.Code = shared.OK - return c.WriteJSON(msg) + return p.writeJSON(msg) } -func SendDone(c *websocket.Conn) error { +func SendDone(p *wsPeer) error { msg := new(shared.WebsocketSignal) msg.SType = shared.Done msg.Code = shared.OK - return c.WriteJSON(msg) + return p.writeJSON(msg) } // isSelfHost reports whether host points back at this server. Addresses are @@ -390,21 +710,48 @@ func isSelfHost(host string) bool { } func newTest(c shared.Config) (t *test, err error) { + // The ID becomes a filename component under --storage-path and it comes + // from the client, so it is validated before it can touch the filesystem. + if err = shared.ValidateTestID(c.TestID); err != nil { + return nil, err + } + testLock.Lock() defer testLock.Unlock() + for _, existing := range tests { + if existing.ID == c.TestID && existing.live() { + return nil, fmt.Errorf("A test with id (%s) is already running", c.TestID) + } + } + t = new(test) t.errMap = make(map[string]struct{}) - t.cons = make(map[string]*websocket.Conn) + t.cons = make(map[string]*wsPeer) t.Started = time.Now() t.Config = c t.DPS = make([]shared.DP, 0) t.ID = c.TestID t.ctx, t.cancel = context.WithCancelCause(context.Background()) + // Baseline the drop counters for this test. Prefer the poller's snapshot, + // but read directly if it has not published yet, otherwise a test started + // in the first second of the server's life reports "unknown" for its whole + // run. + t.dropped = loadStats().drops + if !t.dropped.ok { + t.dropped = readDropCounters(statsInterface) + } + if c.Save { - resetTestFiles(t) - newTestFile(t) + if err = resetTestFiles(t); err != nil { + return nil, err + } + // A test that cannot write its results should say so now rather than + // run for the full duration and silently save nothing. + if _, err = newTestFile(t); err != nil { + return nil, err + } } t.Readers = make([]*netPerfReader, 0) @@ -424,7 +771,7 @@ func newTest(c shared.Config) (t *test, err error) { } if readersCreated == 0 { - return nil, fmt.Errorf("No performance readers were created, please revise your config") + return nil, errors.New("No performance readers were created, please revise your config") } tests = append(tests, t) @@ -432,7 +779,9 @@ func newTest(c shared.Config) (t *test, err error) { } type netPerfReader struct { - hasStats bool + // hasStats is atomic because it is set on every chunk written and read by + // the sampling goroutine once a second. + hasStats atomic.Bool m sync.Mutex buf []byte @@ -447,38 +796,49 @@ type netPerfReader struct { concurrency chan int + // Guarded by m. TTFBH int64 TTFBL int64 RMSH int64 RMSL int64 + // Owned by the sampling goroutine. lastDataPointTime time.Time } type asyncReader struct { pr *netPerfReader i int64 // current reading index - prevRune int // index of previous rune; or < 0 ttfbRegistered bool start time.Time ctx context.Context c *shared.Config } +// Read feeds the request body. It runs once per chunk on every in-flight +// request, so it takes the shared reader lock only on the first chunk, to +// record TTFB. ttfbRegistered is per-asyncReader state, so testing it needs no +// lock; hasStats is atomic. Previously every chunk of every request contended +// on one mutex per peer purely to re-set a bool that was already true. func (a *asyncReader) Read(b []byte) (n int, err error) { - a.pr.m.Lock() if !a.ttfbRegistered { - since := time.Since(a.start).Microseconds() a.ttfbRegistered = true + since := time.Since(a.start).Microseconds() + a.pr.m.Lock() if since > a.pr.TTFBH { a.pr.TTFBH = since } if since < a.pr.TTFBL { a.pr.TTFBL = since } + a.pr.m.Unlock() } - a.pr.hasStats = true - a.pr.m.Unlock() + + // Must stay outside the branch above: a stream request issues one Read per + // chunk for the whole test and never starts a second request, so gating + // this on the first chunk would stop the reader reporting any data point + // after its first interval. + a.pr.hasStats.Store(true) if a.ctx.Err() != nil { return 0, io.EOF @@ -486,6 +846,11 @@ func (a *asyncReader) Read(b []byte) (n int, err error) { if a.c.TestType == shared.StreamTest { n = copy(b, a.pr.buf) + if n == 0 { + // The buffer is released when a test finishes; returning 0, nil + // forever would spin net/http. + return 0, io.EOF + } a.pr.TX.Add(uint64(n)) return n, nil } @@ -499,190 +864,236 @@ func (a *asyncReader) Read(b []byte) (n int, err error) { return n, nil } -func createAndRunTest(con *websocket.Conn, signal shared.WebsocketSignal) { - defer SendDone(con) +func createAndRunTest(p *wsPeer, signal shared.WebsocketSignal) { + defer SendDone(p) test, err := newTest(signal.Config) if err != nil { - SendError(con, err) + SendError(p, err) return } - if signal.Config.Debug { - defer func() { - fmt.Println("Test exiting:", test.ID) - }() - } - defer test.cancel(fmt.Errorf("testing finished")) + defer func() { + shared.DEBUG("Test exiting:", test.ID) + }() + // Defers run last-registered-first, so this is cancel() then finish() then + // the log line, and SendDone(p) last of all. Stopping the readers before + // marking the test finished means it never keeps generating traffic that + // nothing will sample, and finish() must not retire p -- SendDone still + // has to go out over it. + defer test.finish() + defer test.cancel(errors.New("testing finished")) - start := time.Now() for i := range test.Readers { go startPerformanceReader(test, test.Readers[i]) } - conUID := uuid.NewString() - test.cons[conUID] = con + test.attach(p) - for { - if test.ctx.Err() != nil { - return - } + // A counted loop rather than a wall-clock comparison: the old form + // re-checked elapsed time after a sleep that had already drifted by the + // generate+send work, so a run emitted a duration-dependent, nondeterministic + // number of samples. + ticker := time.NewTicker(time.Second) + defer ticker.Stop() - if time.Since(start).Seconds() > float64(test.Config.Duration) { - break - } - time.Sleep(1 * time.Second) - if signal.Config.Debug { - fmt.Println("Duration: ", signal.Config.TestID, time.Since(start).Seconds()) + for i := 0; i < test.Config.Duration; i++ { + select { + case <-test.ctx.Done(): + // Flush whatever the canceled interval accumulated instead of + // dropping it. + generateDataPoints(test) + sendAndSaveData(test) + return + case <-ticker.C: } generateDataPoints(test) - _ = sendAndSaveData(test) + sendAndSaveData(test) } -} -func listenToLiveTests(con *websocket.Conn, s shared.WebsocketSignal) { - uid := uuid.NewString() + // The loop used to break before sampling, discarding the final interval's + // bytes and any data points still queued. + generateDataPoints(test) + sendAndSaveData(test) +} - for i := range tests { - if s.Config.TestID != "" && tests[i].ID != s.Config.TestID { +func listenToLiveTests(p *wsPeer, s shared.WebsocketSignal) { + attached := 0 + for _, t := range snapshotTests() { + if s.Config.TestID != "" && t.ID != s.Config.TestID { continue } - if s.Config.Debug { - fmt.Println("Listen:", tests[i].ID, "DPS:", len(tests[i].DPS), "ERR:", len(tests[i].errors)) + if t.attach(p) { + attached++ } - - tests[i].cons[uid] = con + } + if attached == 0 { + SendError(p, fmt.Errorf("No live test matching id (%s) on this host", s.Config.TestID)) + SendDone(p) } } -type DataPointPaginator struct { - DPIndex int - ErrIndex int - After time.Time -} - -func sendAndSaveData(t *test) (err error) { +// sendAndSaveData drains the pending data points and errors under the lock, +// then persists and ships them with no lock held. Holding t.M across the disk +// write or the socket writes would both stall the sampling loop and deadlock +// against AddError. +func sendAndSaveData(t *test) { defer func() { - r := recover() - if r != nil { + if r := recover(); r != nil { log.Println(r, string(debug.Stack())) } }() - wss := new(shared.WebsocketSignal) - wss.SType = shared.Stats - wss.DataPoint = new(shared.DataReponseToClient) + t.M.Lock() + dps := t.DPS + t.DPS = make([]shared.DP, 0, len(dps)) + errs := t.errors + t.errors = make([]shared.TError, 0) + t.errMap = make(map[string]struct{}) + peers := make([]*wsPeer, 0, len(t.cons)) + for _, p := range t.cons { + peers = append(peers, p) + } + t.M.Unlock() - if t.DataFile == nil && t.Config.Save { - newTestFile(t) + if len(dps) == 0 && len(errs) == 0 { + return } - for i := range t.DPS { - wss.DataPoint.DPS = append(wss.DataPoint.DPS, t.DPS[i]) - if t.Config.Save { - fileb, err := json.Marshal(t.DPS[i]) - if err != nil { - t.AddError(err, "datapoint-marshaling") - } - t.DataFile.Write(shared.DataPoint.String()) - t.DataFile.Write(fileb) - t.DataFile.Write([]byte{10}) - } + if t.Config.Save { + persist(t, dps, errs) } - t.DPS = make([]shared.DP, 0) - t.M.Lock() - errorsClone := make([]shared.TError, 0) - for _, v := range t.errors { - errorsClone = append(errorsClone, v) + wss := &shared.WebsocketSignal{ + SType: shared.Stats, + DataPoint: &shared.DataReponseToClient{DPS: dps, Errors: errs}, } - t.errors = make([]shared.TError, 0) - t.errMap = make(map[string]struct{}) - t.M.Unlock() - for i := range errorsClone { - wss.DataPoint.Errors = append(wss.DataPoint.Errors, errorsClone[i]) - if t.Config.Save { - fileb, err := json.Marshal(errorsClone[i]) - if err != nil { - t.AddError(err, "error-marshaling") - } - t.DataFile.Write(shared.ErrorPoint.String()) - t.DataFile.Write(fileb) - t.DataFile.Write([]byte{10}) + var dead []string + for _, p := range peers { + if err := p.writeJSON(wss); err != nil { + shared.DEBUG("Unable to send data point:", err) + p.shutdown() + dead = append(dead, p.pid) } } + t.detach(dead) +} - for i := range t.cons { - if t.cons[i] == nil { - continue +// persist writes the batch to the test's data file. Errors here are logged +// rather than routed through AddError, so a failing disk cannot generate one +// error per interval forever. +func persist(t *test, dps []shared.DP, errs []shared.TError) { + if t.DataFile == nil { + if _, err := newTestFile(t); err != nil { + shared.DEBUG("Unable to open a test file:", err) + return } + } - err = t.cons[i].WriteJSON(wss) - if err != nil { - if t.Config.Debug { - fmt.Println("Unable to send data point:", err) - } - t.cons[i].Close() - delete(t.cons, i) - continue + w := bufio.NewWriter(t.DataFile) + for i := range dps { + if _, err := shared.WriteStructAndNewLine(w, shared.DataPoint, dps[i]); err != nil { + shared.DEBUG("Unable to persist data point:", err) + return } } - return + for i := range errs { + if _, err := shared.WriteStructAndNewLine(w, shared.ErrorPoint, errs[i]); err != nil { + shared.DEBUG("Unable to persist error point:", err) + return + } + } + if err := w.Flush(); err != nil { + shared.DEBUG("Unable to flush test file:", err) + } } func generateDataPoints(t *test) { - for ri, rv := range t.Readers { - if rv == nil { - continue + defer func() { + if r := recover(); r != nil { + log.Println(r, string(debug.Stack())) } + }() - if !rv.hasStats { - continue - } + stats := loadStats() - r := t.Readers[ri] + local := realIP + if local == "" { + local = bindAddress + } - tx := r.TX.Swap(0) - totalSecs := time.Since(r.lastDataPointTime).Seconds() - r.lastDataPointTime = time.Now() - txtotal := float64(tx) / totalSecs + // Drops are reported as the delta since this test started. The counter + // used to be an absolute since-boot total summed over every interface, + // which made it a large constant that said nothing about the test. + dropDelta := -1 + if stats.drops.ok && t.dropped.ok && stats.drops.total() >= t.dropped.total() { + dropDelta = int(stats.drops.total() - t.dropped.total()) + } - d := shared.DP{ - Type: t.Config.TestType, - TestID: t.ID, - Created: time.Now(), - TX: uint64(txtotal), - TXTotal: tx, - TXCount: r.TXCount.Load(), - Remote: r.addr, - TTFBL: r.TTFBL, - TTFBH: r.TTFBH, - RMSL: r.RMSL, - RMSH: r.RMSH, - ErrCount: len(t.errors), - DroppedPackets: droppedPackets, - MemoryUsedPercent: int(currentMemoryStat.UsedPercent), - CPUUsedPercent: int(cpuPercent), + t.M.Lock() + errCount := len(t.errors) + t.M.Unlock() + + batch := make([]shared.DP, 0, len(t.Readers)) + now := time.Now() + + for _, r := range t.Readers { + if r == nil || !r.hasStats.Load() { + continue } - if realIP != "" { - d.Local = realIP - } else { - d.Local = bindAddress + // A rate is bytes divided by the measured window, so a very short + // window yields a number orders of magnitude above anything real -- + // and that number then becomes TX(max). The final flush lands + // microseconds after the last scheduled sample, which is exactly that + // case. Skip the reader instead, leaving its counter and timestamp + // alone so the bytes land in the next sample rather than being lost. + elapsed := now.Sub(r.lastDataPointTime) + if elapsed < minSampleWindow { + continue } + r.hasStats.Store(false) + tx := r.TX.Swap(0) + r.lastDataPointTime = now + rate := uint64(float64(tx) / elapsed.Seconds()) + r.m.Lock() - r.hasStats = false + ttfbL, ttfbH, rmsL, rmsH := r.TTFBL, r.TTFBH, r.RMSL, r.RMSH r.TTFBH = 0 r.TTFBL = math.MaxInt64 r.RMSH = 0 r.RMSL = math.MaxInt64 r.m.Unlock() - t.DPS = append(t.DPS, d) + batch = append(batch, shared.DP{ + Type: t.Config.TestType, + TestID: t.ID, + Created: now, + Local: local, + Remote: r.addr, + TX: rate, + TXTotal: tx, + TXCount: r.TXCount.Load(), + TTFBL: ttfbL, + TTFBH: ttfbH, + RMSL: rmsL, + RMSH: rmsH, + ErrCount: errCount, + DroppedPackets: dropDelta, + MemoryUsedPercent: stats.memUsedPercent, + CPUUsedPercent: stats.cpuUsedPercent, + }) } - return + + if len(batch) == 0 { + return + } + + t.M.Lock() + t.DPS = append(t.DPS, batch...) + t.M.Unlock() } func newTransport(c *shared.Config) *http.Transport { @@ -743,7 +1154,7 @@ func startPerformanceReader(t *test, r *netPerfReader) { select { case cid = <-r.concurrency: go sendRequestToHost(t, r, cid) - case _ = <-t.ctx.Done(): + case <-t.ctx.Done(): return } } @@ -810,8 +1221,12 @@ func sendRequestToHost(t *test, r *netPerfReader, cid int) { req.ContentLength = -1 } - sent := time.Now() + // Counted when the request is issued, not when it completes: a stream + // request only ends when the test is canceled, so counting completions + // would leave #TX permanently zero for every bandwidth run. r.TXCount.Add(1) + + sent := time.Now() resp, err = r.client.Do(req) if err != nil { if errors.Is(err, context.Canceled) { @@ -821,8 +1236,21 @@ func sendRequestToHost(t *test, r *netPerfReader, cid int) { return } + // Drain and close on every path. The non-200 branch used to return without + // closing, and net/http cannot reuse or release a connection whose body is + // still open: each failed request permanently burned a connection, an fd + // and its two net/http goroutines. A peer returning errors could leak + // (hosts-1) * concurrency of them in a single test. + defer func() { + _, _ = io.Copy(io.Discard, resp.Body) + _ = resp.Body.Close() + }() + if resp.StatusCode != http.StatusOK { - t.AddError(fmt.Errorf("Status code was %d, expected 200 from host %s", resp.StatusCode, r.addr), "invalid-status-code") + t.AddError( + fmt.Errorf("Status code was %d, expected 200 from host %s", resp.StatusCode, r.addr), + "invalid-status-code-"+r.addr, + ) return } @@ -836,58 +1264,31 @@ func sendRequestToHost(t *test, r *netPerfReader, cid int) { if done < r.RMSL { r.RMSL = done } - r.hasStats = true r.m.Unlock() - - io.Copy(io.Discard, resp.Body) - resp.Body.Close() - - return + r.hasStats.Store(true) } -func listAllTests(con *websocket.Conn, s shared.WebsocketSignal) { - defer SendDone(con) +func listAllTests(p *wsPeer, s shared.WebsocketSignal) { + defer SendDone(p) var err error s.TestList, err = listTestsFromDisk() if err != nil { - SendError(con, err) + SendError(p, err) return } s.Code = 200 s.SType = shared.ListTests - err = con.WriteJSON(s) - if err != nil { - fmt.Println(err) + if err = p.writeJSON(s); err != nil { + shared.DEBUG("Unable to send test list:", err) } } -func getTestOnServer(con *websocket.Conn, s shared.WebsocketSignal) { - defer SendDone(con) - err := streamTestFilesToWebsocket(con, s.Config.TestID) +func getTestOnServer(p *wsPeer, s shared.WebsocketSignal) { + defer SendDone(p) + err := streamTestFilesToWebsocket(p, s.Config.TestID) if err != nil { - SendError(con, err) - } -} - -func sendAllDataPoints(con *websocket.Conn, t *test) error { - wss := new(shared.WebsocketSignal) - wss.SType = shared.Stats - dataResponse := new(shared.DataReponseToClient) - - for i := range t.DPS { - dataResponse.DPS = append(dataResponse.DPS, t.DPS[i]) + SendError(p, err) } - - for i := range t.errors { - dataResponse.Errors = append(dataResponse.Errors, t.errors[i]) - } - - wss.DataPoint = dataResponse - err := con.WriteJSON(wss) - if err != nil { - return err - } - return nil } diff --git a/shared/shared.go b/shared/shared.go index 5cfcd01..92e1e5f 100644 --- a/shared/shared.go +++ b/shared/shared.go @@ -23,6 +23,7 @@ import ( "encoding/json" "errors" "fmt" + "io" "net" "net/netip" "os" @@ -57,6 +58,7 @@ type TestOutput struct { TXC uint64 TXL uint64 TXH uint64 + TXA uint64 TXT uint64 RMSL int64 RMSH int64 @@ -67,6 +69,31 @@ type TestOutput struct { MH int CL int CH int + + // Samples is how many data points TXL/TXH/TXA were computed from. It is + // not displayed, but a zero value means the throughput columns carry no + // measurement yet and TXA must not be divided out. + Samples uint64 +} + +// HostAverage is the per-host throughput breakdown printed once a run ends. +// Host is the address the client dialed, which is stable even when a server +// reports a wildcard bind address because --real-ip was not set. +type HostAverage struct { + Host string + Samples uint64 + TXSum uint64 + TXTotal uint64 + TXMin uint64 + TXMax uint64 +} + +// Avg is the mean per-second throughput of one flow out of this host. +func (h HostAverage) Avg() uint64 { + if h.Samples == 0 { + return 0 + } + return h.TXSum / h.Samples } type ( @@ -173,6 +200,47 @@ type Config struct { HostFilter string `json:"-"` } +// maxErrorLength caps a persisted error string. Data points and errors are +// stored one per line and read back with a bufio.Scanner, whose default token +// limit is 64 KiB -- a pathological error chain longer than that would abort a +// download mid-file. +const maxErrorLength = 4 << 10 + +func TruncateError(s string) string { + if len(s) <= maxErrorLength { + return s + } + return s[:maxErrorLength] + "... (truncated)" +} + +// ValidateTestID rejects IDs that are unsafe as a filename component. The ID +// arrives from whichever client asked for the test and is concatenated into a +// path under --storage-path, so without this an ID of "../../x" would write +// outside the storage directory and an empty ID would make the server's +// cleanup glob match -- and delete -- every saved test it has. +func ValidateTestID(id string) error { + if id == "" { + return errors.New("test id is empty") + } + if len(id) > 64 { + return fmt.Errorf("test id is longer than 64 characters (%d)", len(id)) + } + if id == "." || id == ".." { + return fmt.Errorf("invalid test id (%s)", id) + } + for _, r := range id { + switch { + case r >= 'a' && r <= 'z', + r >= 'A' && r <= 'Z', + r >= '0' && r <= '9', + r == '-', r == '_', r == '.': + default: + return fmt.Errorf("test id (%s) may only contain letters, digits, '-', '_' and '.'", id) + } + } + return nil +} + func INFO(items ...any) { fmt.Println(items...) } @@ -292,7 +360,7 @@ func ParseHosts(hosts string, dnsServer string, family string) (list []string, e } // this is just to trip out carrage return - hb = bytes.Replace(hb, []byte{13}, []byte{}, -1) + hb = bytes.ReplaceAll(hb, []byte{13}, []byte{}) var splitLines [][]byte if bytes.Contains(hb, []byte(",")) { @@ -302,7 +370,7 @@ func ParseHosts(hosts string, dnsServer string, family string) (list []string, e } if len(splitLines) < 1 { - err = errors.New("Hosts within the file ( " + fs[1] + " ) should be per line or comma seperated") + err = errors.New("Hosts within the file ( " + fs[1] + " ) should be per line or comma separated") return } @@ -410,19 +478,24 @@ func GetInterfaceAddresses() (list []string, err error) { return } -func WriteStructAndNewLineToFile(f *os.File, prefix FilePrefix, s interface{}) (int, error) { +// WriteStructAndNewLine writes one record in the on-disk format: a single +// prefix byte identifying the record type, the JSON, then a newline. +func WriteStructAndNewLine(w io.Writer, prefix FilePrefix, s any) (int, error) { outb, err := json.Marshal(s) if err != nil { return 0, err } - n, err := f.Write(prefix.String()) - if err != nil { - return n, err - } - n, err = f.Write(outb) - if err != nil { - return n, err + total := 0 + for _, chunk := range [][]byte{prefix.String(), outb, {10}} { + n, err := w.Write(chunk) + total += n + if err != nil { + return total, err + } } - n, err = f.Write([]byte{10}) - return n, err + return total, nil +} + +func WriteStructAndNewLineToFile(f *os.File, prefix FilePrefix, s any) (int, error) { + return WriteStructAndNewLine(f, prefix, s) } diff --git a/shared/sorting.go b/shared/sorting.go index c9e6655..8cf6503 100644 --- a/shared/sorting.go +++ b/shared/sorting.go @@ -1,6 +1,7 @@ package shared import ( + "cmp" "slices" ) @@ -40,22 +41,19 @@ func SortDataPoints(dps []DP, c Config) { } } +// The comparators return 0 for equal elements. Returning 1 instead, as these +// used to, breaks the strict weak ordering slices.SortFunc requires, which +// leaves the order of tied elements undefined: two analyses of the same file +// could disagree. Ties are common because a data point with no samples in its +// interval reports RMSH/TTFBH of 0. func SortDataPointRMSH(dps []DP) { slices.SortFunc(dps, func(a DP, b DP) int { - if a.RMSH < b.RMSH { - return -1 - } else { - return 1 - } + return cmp.Compare(a.RMSH, b.RMSH) }) } func SortDataPointTTFBH(dps []DP) { slices.SortFunc(dps, func(a DP, b DP) int { - if a.TTFBH < b.TTFBH { - return -1 - } else { - return 1 - } + return cmp.Compare(a.TTFBH, b.TTFBH) }) } From 346b91c6c4b0949bfa8a8d615515eabe4d139e6c Mon Sep 17 00:00:00 2001 From: zveinn Date: Tue, 1 Sep 2026 12:00:35 +0000 Subject: [PATCH 2/2] address PR review: test ids are not patterns, fix the lint gate Eleven of the twelve review findings were valid; each was reproduced before being fixed. server/file.go: a test id reaching filepath.Glob is a *pattern*, so `delete --id '*'` destroyed every saved test and `--id '[ab]*'` destroyed a chosen subset. Verified through the real handler: 4 of 4 unrelated tests gone. This is the same failure as the unanchored pattern in resetTestFiles, arriving by a different route -- the read/delete path accepts looser ids than newTest so that files written by an older server stay reachable, and that path globbed. It now matches directory entries by exact prefix, which has no pattern semantics, and requires the numeric index suffix newTestFile has always written. That also stops "my_test" claiming "my_test.1.1", which belongs to the test named "my_test.1". client/table.go: the two host-column widths are the only header entries that change after init, and growHostColumns has callers both inside and outside responseLock while the end-of-run summary reads them outside it. Reproduced as a DATA RACE. They are now atomics behind colWidth(), widened with a compare-and-swap so a concurrent widening cannot be dropped. .github/workflows/go.yml: the lint step I added never ran. golangci-lint-action with "version: latest" installs a v1 build made with Go 1.24, which can neither read the v2 config nor accept a Go 1.26 module -- the job failed with "the Go language version used to build golangci-lint is lower than the targeted Go version". It is now installed from source with the job's own toolchain at a pinned v2.12.2, so the two match by construction; that also removes an unpinned third-party action. Verified by installing that exact version and running it against this module. The repeated-race step took a -run subset whose pattern matched five fewer tests than intended and, worse, `go test -run` exits 0 when a pattern matches nothing, so a rename would have silently disabled the gate. It now repeats the whole suite: 20-40s per GOMAXPROCS setting, measured. Also from the review: - Added permissions: contents: read; nothing in the job writes to the repo. - client.go: DownloadTest reported its Close error instead of discarding it, in the one function whose purpose is leaving a correct file on disk. - The readiness send is now a method, wsClient.reportReady, and its test calls it. The test previously declared its own copy of the closure, so it would have passed against the blocking implementation it existed to guard. - README: #TX counts requests *issued*, not completed, and is a sum of running totals -- for a bandwidth test it tracks in-flight streams, since a stream ends only when the test does. TX(total) is the whole-mesh total, so comparing it to one host's NIC counters needs dividing by the reporting host count, or reading that host's row from the per-host table. - Renamed the test helper io_Copy_Discard to drainBody and stopped it reporting a non-EOF read error as success. - CLAUDE.md fenced-block spacing. Declined: using version 5.2.0 rather than v5.2.0 in Chart.yaml. Helm's semver accepts the prefix, the chart carried v5.0.6 before this branch, and appVersion has never carried it -- dropping it from one field only moves the inconsistency. New tests: test ids are not patterns (metacharacters select nothing, legacy ids still resolve, deleting one test leaves the others), suffix attribution, and host-column width races. TestGrowHostColumns now resets through resetHeaders and asserts via colWidth. --- .github/workflows/go.yml | 32 +++++--- CLAUDE.md | 2 + README.md | 17 ++++- client/aggregate.go | 12 +-- client/aggregate_test.go | 33 ++++---- client/client.go | 55 ++++++++------ client/table.go | 160 +++++++++++++++++++++++++-------------- client/table_test.go | 70 +++++++++++++++-- server/file.go | 80 ++++++++++++-------- server/regress_test.go | 116 +++++++++++++++++++++++++++- 10 files changed, 425 insertions(+), 152 deletions(-) diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index 0d478f4..e2fbb61 100644 --- a/.github/workflows/go.yml +++ b/.github/workflows/go.yml @@ -8,6 +8,11 @@ on: branches: - master - main + +# Least privilege: nothing in this job writes to the repository. +permissions: + contents: read + jobs: build: name: Build and test @@ -31,21 +36,30 @@ jobs: - name: Vet run: go vet ./... shell: bash + # Built from source with this job's own Go toolchain rather than pulled as a + # release binary. golangci-lint refuses to run when the Go version it was + # built with is older than the module's go directive, and the published + # binaries lag Go 1.26 -- golangci-lint-action@v6 with "version: latest" + # installed a v1 build on Go 1.24, which could neither read the v2 config + # nor accept the module. Installing it here makes the two match by + # construction and pins an exact, tested version instead of a moving one. - name: Lint - uses: golangci/golangci-lint-action@v6 - with: - version: latest - args: --timeout 5m + run: | + go install github.com/golangci/golangci-lint/v2/cmd/golangci-lint@v2.12.2 + golangci-lint run --timeout 5m + shell: bash - name: Test run: go test -race -count 1 -timeout 10m ./... shell: bash # The concurrency fixes are the kind that pass once and fail on the tenth - # run, and single-proc scheduling exposes different interleavings. - - name: Test concurrency repeatedly + # run, and single-proc scheduling exposes different interleavings. The whole + # suite is repeated rather than a -run subset: a name pattern silently + # selects nothing when a test is renamed, and `go test -run` exits 0 in that + # case, so the gate would quietly stop testing anything. The full suite at + # -count 10 takes about 40s per GOMAXPROCS setting. + - name: Test repeatedly for flakiness run: | for procs in 1 4; do - GOMAXPROCS=$procs go test -race -count 10 -timeout 15m \ - -run 'RaceFree|Concurrent|Ingest|Reclaim|Duplicate|Releases' \ - ./server/... ./client/... + GOMAXPROCS=$procs go test -race -count 10 -timeout 15m ./... done shell: bash diff --git a/CLAUDE.md b/CLAUDE.md index ab788a8..8d67839 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -22,6 +22,7 @@ go install github.com/minio/hperf/cmd/hperf@latest ```bash go test -race ./... ``` + CI runs the suite with `-race`, and runs the concurrency tests repeatedly at `GOMAXPROCS=1` and `4`, because the locking bugs in this codebase pass a single clean run and fail the tenth. @@ -30,6 +31,7 @@ clean run and fail the tenth. ```bash golangci-lint run ``` + `.golangci.yml` uses the v2 schema. It was previously pinned to golangci-lint 1.20.0 and enabled linters that no longer exist, so this command failed outright and the gate never ran - if it starts erroring on a config version again, that is diff --git a/README.md b/README.md index 60d4dd2..162fabd 100644 --- a/README.md +++ b/README.md @@ -150,7 +150,7 @@ During test execution, hperf displays aggregated statistics across all servers: | Metric | Description | |------------------|-----------------------------------------------------------------| | `#ERR` | Total error count across all servers | -| `#TX` | Total HTTP requests completed across all servers | +| `#TX` | Requests issued, summed across servers (see note below) | | `TX(max/min)` | Highest and lowest transfer rate of any single flow | | `TX(avg)` | Mean transfer rate across every flow, over the same population | | `TX(total)` | Total bytes transferred by the whole mesh | @@ -165,8 +165,19 @@ A "flow" is one server's traffic to one peer, sampled once a second. `TX(max)`, `TX(avg)` <= `TX(max)` always holds. None of the three is the aggregate throughput of a host or of the cluster: in a full mesh of N hosts each host carries N-1 flows, so a single flow's rate is roughly 1/(N-1) of what one host's -NIC counters will show. Use `TX(total)` over the test duration, or the per-host -table below, when comparing against `ethtool` or switch counters. +NIC counters will show. + +`TX(total)` is the byte total for the **whole mesh**, so +`TX(total) / duration` is the cluster-wide aggregate rate. To compare against +one host's `ethtool` or switch counters, divide again by the number of reporting +hosts — or read that host's row straight off the per-host table below, which is +already per-host. + +`#TX` counts requests *issued*, not completed, and it is a sum of each server's +running total across every data point — so treat it as a relative indicator of +load, not as a request count. For a bandwidth test a request is a single +long-lived stream that only ends when the test does, so the figure tracks +in-flight streams rather than completed work. `#Dropped` counts receive plus transmit drops on the interface carrying the test, measured from the moment the test started. It is `-1` when no counter diff --git a/client/aggregate.go b/client/aggregate.go index 2093662..bec3700 100644 --- a/client/aggregate.go +++ b/client/aggregate.go @@ -255,12 +255,12 @@ func printHostAverages(hosts []shared.HostAverage, fleet uint64) { } PrintColumns( style, - column{h.Host, headerSlice[Local].width}, - column{shared.BWToString(h.Avg()), headerSlice[TXA].width}, - column{shared.BWToString(h.TXMin), headerSlice[TXL].width}, - column{shared.BWToString(h.TXMax), headerSlice[TXH].width}, - column{shared.BToString(h.TXTotal), headerSlice[TXT].width}, - column{formatUint(h.Samples), headerSlice[Samples].width}, + column{h.Host, colWidth(Local)}, + column{shared.BWToString(h.Avg()), colWidth(TXA)}, + column{shared.BWToString(h.TXMin), colWidth(TXL)}, + column{shared.BWToString(h.TXMax), colWidth(TXH)}, + column{shared.BToString(h.TXTotal), colWidth(TXT)}, + column{formatUint(h.Samples), colWidth(Samples)}, ) } fmt.Println("") diff --git a/client/aggregate_test.go b/client/aggregate_test.go index 6d4f2b2..1c6523c 100644 --- a/client/aggregate_test.go +++ b/client/aggregate_test.go @@ -333,40 +333,41 @@ func TestHostAccountingIsSymmetric(t *testing.T) { } } -// TestSignalReadyNeverBlocks covers the wedge in the reconnect path: the +// TestReportReadyNeverBlocks covers the wedge in the reconnect path: the // readiness channel is drained a fixed number of times and then abandoned, and -// each reconnect re-enters the handler with fresh locals, so a blocking send -// would eventually park the goroutine before its read loop -- silently dropping -// the host from the results with nothing left to notice. -func TestSignalReadyNeverBlocks(t *testing.T) { +// each reconnect re-enters the handler, so a blocking send would eventually +// park the goroutine before its read loop -- silently dropping the host from the +// results with nothing left to notice. +// +// This calls the production wsClient.reportReady. An earlier version of this +// test declared its own copy of the closure, which meant it would have passed +// against the blocking implementation it was supposed to be guarding. +func TestReportReadyNeverBlocks(t *testing.T) { // One host, so the buffer is one deep, and drain it as initializeClient // would. ready := make(chan connectResult, 1) socket := &wsClient{ID: 0, Host: "10.0.0.1"} - signalReady := func(e error) { - select { - case ready <- connectResult{id: socket.ID, err: e}: - default: - } + socket.reportReady(ready, nil) + got := <-ready + if got.id != socket.ID || got.err != nil { + t.Fatalf("first report = %+v, want id 0 and no error", got) } - signalReady(nil) - <-ready - - // Every subsequent report models one reconnect generation. None may block. + // Every subsequent report models one reconnect generation against a channel + // nobody is draining any more. None may block. done := make(chan struct{}) go func() { defer close(done) for i := 0; i < maxReconnects+5; i++ { - signalReady(errors.New("flap")) + socket.reportReady(ready, errors.New("flap")) } }() select { case <-done: case <-time.After(5 * time.Second): - t.Fatal("signalReady blocked; a reconnecting host would be dropped from the run") + t.Fatal("reportReady blocked; a reconnecting host would be dropped from the run") } } diff --git a/client/client.go b/client/client.go index dfe636e..0e805b1 100644 --- a/client/client.go +++ b/client/client.go @@ -141,6 +141,22 @@ func (c *wsClient) release() { } } +// reportReady announces this host's connect outcome to initializeClient. +// +// The send must not block. initializeClient drains this channel exactly +// len(hosts) times and then abandons it, while the reconnect path re-enters +// handleWSConnection with fresh locals -- so a blocking send would eventually +// fill the buffer and park the reader goroutine here, before its read loop, +// silently dropping that host from the results with nothing left to notice. +// Duplicate reports are harmless: initializeClient ignores a host that has +// already reported. +func (c *wsClient) reportReady(ready chan connectResult, err error) { + select { + case ready <- connectResult{id: c.ID, err: err}: + default: + } +} + // filterSelf removes every entry matching self, not just the first. A host // listed twice used to leave one copy behind, so a server would test against // itself through the local network stack. @@ -264,24 +280,11 @@ func handleWSConnection(ctx context.Context, c *shared.Config, socket *wsClient, var err error host := socket.Host - // The send is non-blocking. initializeClient drains this channel exactly - // len(hosts) times and then abandons it, and the reconnect path re-enters - // this function with a fresh set of locals -- so a blocking send would - // eventually fill the buffer and park here forever, before the read loop, - // silently dropping the host from the results. Duplicate reports are - // harmless: initializeClient ignores any host that already reported. - signalReady := func(e error) { - select { - case ready <- connectResult{id: socket.ID, err: e}: - default: - } - } - defer func() { if r := recover(); r != nil { fmt.Println(r, string(debug.Stack())) } - signalReady(err) + socket.reportReady(ready, err) if ctx.Err() != nil { socket.release() @@ -357,7 +360,7 @@ func handleWSConnection(ctx context.Context, c *shared.Config, socket *wsClient, // Count the host only once it is actually up, so the counter is only ever // decremented by a host that contributed to it. socket.hold() - signalReady(nil) + socket.reportReady(ready, nil) // A reconnected socket is unknown to the test already running on the // server, so it would receive neither data points nor -- the part that @@ -654,9 +657,9 @@ func ListTests(ctx context.Context, c shared.Config) (err error) { for i := range keys { PrintColumns( tableStyle, - column{strconv.Itoa(i), headerSlice[IntNumber].width}, - column{keys[i], headerSlice[ID].width}, - column{testList[keys[i]].Time.Format("02/01/2006 3:04 PM"), headerSlice[ID].width}, + column{strconv.Itoa(i), colWidth(IntNumber)}, + column{keys[i], colWidth(ID)}, + column{testList[keys[i]].Time.Format("02/01/2006 3:04 PM"), colWidth(ID)}, ) } @@ -739,21 +742,29 @@ func DownloadTest(ctx context.Context, c shared.Config) (err error) { if err != nil { return err } - defer f.Close() + // Close is reported rather than discarded: this function's whole purpose is + // to leave a correct file on disk, and a deferred write can fail at Close + // even after Flush succeeded. + defer func() { + if cerr := f.Close(); cerr != nil && err == nil { + err = cerr + } + }() w := bufio.NewWriter(f) for i := range dps { - if _, err := shared.WriteStructAndNewLine(w, shared.DataPoint, dps[i]); err != nil { + if _, err = shared.WriteStructAndNewLine(w, shared.DataPoint, dps[i]); err != nil { return err } } for i := range errs { - if _, err := shared.WriteStructAndNewLine(w, shared.ErrorPoint, errs[i]); err != nil { + if _, err = shared.WriteStructAndNewLine(w, shared.ErrorPoint, errs[i]); err != nil { return err } } - return w.Flush() + err = w.Flush() + return err } // snapshotResponses copies the collected data under the lock. Reading these diff --git a/client/table.go b/client/table.go index 6c800d4..4e3bede 100644 --- a/client/table.go +++ b/client/table.go @@ -20,6 +20,7 @@ package client import ( "fmt" "strconv" + "sync/atomic" "time" "github.com/charmbracelet/lipgloss" @@ -69,12 +70,62 @@ const ( header_length ) +// The two host columns are the only header widths that change after init: they +// grow to fit the longest address seen. They are read by the end-of-run summary +// while reader goroutines may still be widening them, and growHostColumns is +// called both under responseLock and outside it, so they live outside +// headerSlice as atomics. Every other entry in headerSlice is immutable once +// init has run, which is what makes reading the rest without synchronization +// safe. +var ( + localColWidth atomic.Int64 + remoteColWidth atomic.Int64 +) + // Headers are built once at package init. They used to be built lazily on the // first data point, from whichever goroutine got there first, while the live // ticker goroutine was already reading widths -- a race, and one that produced // an unpadded row if a tick landed before any data point. func init() { + resetHeaders() +} + +// resetHeaders builds the static table and seeds the two mutable widths from +// it. Tests use it to get back to a known state; nothing else should. +func resetHeaders() { initHeaders() + // Seed from the static table, not via colWidth: the atomics are what + // colWidth reads for these two fields, and they are still zero here. + localColWidth.Store(int64(headerSlice[Local].width)) + remoteColWidth.Store(int64(headerSlice[Remote].width)) +} + +// colWidth returns the render width of a header field, reading the two mutable +// host columns atomically. Always use this rather than headerSlice[f].width. +func colWidth(f HeaderField) int { + switch f { + case Local: + return int(localColWidth.Load()) + case Remote: + return int(remoteColWidth.Load()) + default: + return headerSlice[f].width + } +} + +// growTo widens w to at least n and reports whether it changed it. The compare +// and swap matters: growHostColumns has more than one caller and they are not +// all under the same lock, so a plain load-then-store could drop a widening. +func growTo(w *atomic.Int64, n int) bool { + for { + cur := w.Load() + if int64(n) <= cur { + return false + } + if w.CompareAndSwap(cur, int64(n)) { + return true + } + } } func initHeaders() { @@ -108,18 +159,14 @@ func initHeaders() { headerSlice[Samples] = header{"#Samples", 9} } -// growHostColumns widens the two host columns to fit the addresses seen so -// far. Callers must hold responseLock: these are the only header entries that -// change after init, and the per-data-point table is rendered from the same -// lock-holding paths. +// growHostColumns widens the two host columns to fit the addresses seen so far, +// and reports whether either changed so the caller can reprint the header. func growHostColumns(dps []shared.DP) (grew bool) { for i := range dps { - if w := len(shared.HostOnly(dps[i].Local)); w > headerSlice[Local].width { - headerSlice[Local].width = w + if growTo(&localColWidth, len(shared.HostOnly(dps[i].Local))) { grew = true } - if w := len(shared.HostOnly(dps[i].Remote)); w > headerSlice[Remote].width { - headerSlice[Remote].width = w + if growTo(&remoteColWidth, len(shared.HostOnly(dps[i].Remote))) { grew = true } } @@ -157,8 +204,7 @@ func printHeader(fields []HeaderField) { fs := GenerateFormatString(len(fields)) hs := make([]any, 0) for i := range fields { - h := headerSlice[fields[i]] - hs = append(hs, h.width, h.label) + hs = append(hs, colWidth(fields[i]), headerSlice[fields[i]].label) } fmt.Println(HeaderStyle.Render(fmt.Sprintf(fs, hs...))) @@ -246,37 +292,37 @@ func printRealTimeRow(style lipgloss.Style, entry *shared.TestOutput, t shared.T case shared.StreamTest: PrintColumns( style, - column{formatInt(int64(entry.ErrCount)), headerSlice[ErrCount].width}, - column{formatUint(entry.TXC), headerSlice[TXCount].width}, - column{shared.BWToString(entry.TXH), headerSlice[TXH].width}, - column{shared.BWToString(entry.TXL), headerSlice[TXL].width}, - column{shared.BWToString(entry.TXA), headerSlice[TXA].width}, - column{shared.BToString(entry.TXT), headerSlice[TXT].width}, - column{formatInt(int64(entry.DP)), headerSlice[DroppedPackets].width}, - column{formatInt(int64(entry.MH)), headerSlice[MemoryHigh].width}, - column{formatInt(int64(entry.ML)), headerSlice[MemoryLow].width}, - column{formatInt(int64(entry.CH)), headerSlice[CPUHigh].width}, - column{formatInt(int64(entry.CL)), headerSlice[CPULow].width}, + column{formatInt(int64(entry.ErrCount)), colWidth(ErrCount)}, + column{formatUint(entry.TXC), colWidth(TXCount)}, + column{shared.BWToString(entry.TXH), colWidth(TXH)}, + column{shared.BWToString(entry.TXL), colWidth(TXL)}, + column{shared.BWToString(entry.TXA), colWidth(TXA)}, + column{shared.BToString(entry.TXT), colWidth(TXT)}, + column{formatInt(int64(entry.DP)), colWidth(DroppedPackets)}, + column{formatInt(int64(entry.MH)), colWidth(MemoryHigh)}, + column{formatInt(int64(entry.ML)), colWidth(MemoryLow)}, + column{formatInt(int64(entry.CH)), colWidth(CPUHigh)}, + column{formatInt(int64(entry.CL)), colWidth(CPULow)}, ) return case shared.RequestTest: PrintColumns( style, - column{formatInt(int64(entry.ErrCount)), headerSlice[ErrCount].width}, - column{formatUint(entry.TXC), headerSlice[TXCount].width}, - column{shared.BWToString(entry.TXH), headerSlice[TXH].width}, - column{shared.BWToString(entry.TXL), headerSlice[TXL].width}, - column{shared.BWToString(entry.TXA), headerSlice[TXA].width}, - column{shared.BToString(entry.TXT), headerSlice[TXT].width}, - column{formatInt(entry.RMSH), headerSlice[RMSH].width}, - column{formatInt(entry.RMSL), headerSlice[RMSL].width}, - column{formatInt(entry.TTFBH), headerSlice[TTFBH].width}, - column{formatInt(entry.TTFBL), headerSlice[TTFBL].width}, - column{formatInt(int64(entry.DP)), headerSlice[DroppedPackets].width}, - column{formatInt(int64(entry.MH)), headerSlice[MemoryHigh].width}, - column{formatInt(int64(entry.ML)), headerSlice[MemoryLow].width}, - column{formatInt(int64(entry.CH)), headerSlice[CPUHigh].width}, - column{formatInt(int64(entry.CL)), headerSlice[CPULow].width}, + column{formatInt(int64(entry.ErrCount)), colWidth(ErrCount)}, + column{formatUint(entry.TXC), colWidth(TXCount)}, + column{shared.BWToString(entry.TXH), colWidth(TXH)}, + column{shared.BWToString(entry.TXL), colWidth(TXL)}, + column{shared.BWToString(entry.TXA), colWidth(TXA)}, + column{shared.BToString(entry.TXT), colWidth(TXT)}, + column{formatInt(entry.RMSH), colWidth(RMSH)}, + column{formatInt(entry.RMSL), colWidth(RMSL)}, + column{formatInt(entry.TTFBH), colWidth(TTFBH)}, + column{formatInt(entry.TTFBL), colWidth(TTFBL)}, + column{formatInt(int64(entry.DP)), colWidth(DroppedPackets)}, + column{formatInt(int64(entry.MH)), colWidth(MemoryHigh)}, + column{formatInt(int64(entry.ML)), colWidth(MemoryLow)}, + column{formatInt(int64(entry.CH)), colWidth(CPUHigh)}, + column{formatInt(int64(entry.CL)), colWidth(CPULow)}, ) default: shared.DEBUG("Unknown test type, not printing table") @@ -288,32 +334,32 @@ func printTableRow(style lipgloss.Style, entry *shared.DP, t shared.TestType) { case shared.StreamTest: PrintColumns( style, - column{entry.Created.Format("15:04:05"), headerSlice[Created].width}, - column{shared.HostOnly(entry.Local), headerSlice[Local].width}, - column{shared.HostOnly(entry.Remote), headerSlice[Remote].width}, - column{shared.BWToString(entry.TX), headerSlice[TX].width}, - column{formatInt(int64(entry.ErrCount)), headerSlice[ErrCount].width}, - column{formatInt(int64(entry.DroppedPackets)), headerSlice[DroppedPackets].width}, - column{formatInt(int64(entry.MemoryUsedPercent)), headerSlice[MemoryUsage].width}, - column{formatInt(int64(entry.CPUUsedPercent)), headerSlice[CPUUsage].width}, + column{entry.Created.Format("15:04:05"), colWidth(Created)}, + column{shared.HostOnly(entry.Local), colWidth(Local)}, + column{shared.HostOnly(entry.Remote), colWidth(Remote)}, + column{shared.BWToString(entry.TX), colWidth(TX)}, + column{formatInt(int64(entry.ErrCount)), colWidth(ErrCount)}, + column{formatInt(int64(entry.DroppedPackets)), colWidth(DroppedPackets)}, + column{formatInt(int64(entry.MemoryUsedPercent)), colWidth(MemoryUsage)}, + column{formatInt(int64(entry.CPUUsedPercent)), colWidth(CPUUsage)}, ) return case shared.RequestTest: PrintColumns( style, - column{entry.Created.Format("15:04:05"), headerSlice[Created].width}, - column{shared.HostOnly(entry.Local), headerSlice[Local].width}, - column{shared.HostOnly(entry.Remote), headerSlice[Remote].width}, - column{formatInt(entry.RMSH), headerSlice[RMSH].width}, - column{formatInt(entry.RMSL), headerSlice[RMSL].width}, - column{formatInt(entry.TTFBH), headerSlice[TTFBH].width}, - column{formatInt(entry.TTFBL), headerSlice[TTFBL].width}, - column{shared.BWToString(entry.TX), headerSlice[TX].width}, - column{formatUint(entry.TXCount), headerSlice[TXCount].width}, - column{formatInt(int64(entry.ErrCount)), headerSlice[ErrCount].width}, - column{formatInt(int64(entry.DroppedPackets)), headerSlice[DroppedPackets].width}, - column{formatInt(int64(entry.MemoryUsedPercent)), headerSlice[MemoryUsage].width}, - column{formatInt(int64(entry.CPUUsedPercent)), headerSlice[CPUUsage].width}, + column{entry.Created.Format("15:04:05"), colWidth(Created)}, + column{shared.HostOnly(entry.Local), colWidth(Local)}, + column{shared.HostOnly(entry.Remote), colWidth(Remote)}, + column{formatInt(entry.RMSH), colWidth(RMSH)}, + column{formatInt(entry.RMSL), colWidth(RMSL)}, + column{formatInt(entry.TTFBH), colWidth(TTFBH)}, + column{formatInt(entry.TTFBL), colWidth(TTFBL)}, + column{shared.BWToString(entry.TX), colWidth(TX)}, + column{formatUint(entry.TXCount), colWidth(TXCount)}, + column{formatInt(int64(entry.ErrCount)), colWidth(ErrCount)}, + column{formatInt(int64(entry.DroppedPackets)), colWidth(DroppedPackets)}, + column{formatInt(int64(entry.MemoryUsedPercent)), colWidth(MemoryUsage)}, + column{formatInt(int64(entry.CPUUsedPercent)), colWidth(CPUUsage)}, ) default: shared.DEBUG("Unknown test type, not printing table") diff --git a/client/table_test.go b/client/table_test.go index 13dfc32..3865395 100644 --- a/client/table_test.go +++ b/client/table_test.go @@ -18,30 +18,90 @@ package client import ( + "strings" + "sync" "testing" + "time" "github.com/minio/hperf/shared" ) func TestGrowHostColumns(t *testing.T) { - initHeaders() + resetHeaders() + t.Cleanup(resetHeaders) if grew := growHostColumns([]shared.DP{{Local: "10.10.1.2", Remote: "10.10.1.3:9010"}}); grew { t.Error("IPv4 addresses should fit the default column width") } - if headerSlice[Local].width != 15 || headerSlice[Remote].width != 15 { - t.Errorf("widths changed for IPv4: local=%d remote=%d", headerSlice[Local].width, headerSlice[Remote].width) + if colWidth(Local) != 15 || colWidth(Remote) != 15 { + t.Errorf("widths changed for IPv4: local=%d remote=%d", colWidth(Local), colWidth(Remote)) } v6 := "2607:6bc0:8107:432:8e91:3aff:fec5:79ee" if grew := growHostColumns([]shared.DP{{Local: v6, Remote: "[" + v6 + "]:9010"}}); !grew { t.Error("IPv6 addresses should widen the host columns") } - if headerSlice[Local].width != len(v6) || headerSlice[Remote].width != len(v6) { - t.Errorf("widths not grown to %d: local=%d remote=%d", len(v6), headerSlice[Local].width, headerSlice[Remote].width) + if colWidth(Local) != len(v6) || colWidth(Remote) != len(v6) { + t.Errorf("widths not grown to %d: local=%d remote=%d", len(v6), colWidth(Local), colWidth(Remote)) } if grew := growHostColumns([]shared.DP{{Local: "10.10.1.2", Remote: "10.10.1.3:9010"}}); grew { t.Error("columns should not shrink or report a change for narrower addresses") } } + +// TestHostColumnWidthIsRaceFree pins the fix for the width race: the end-of-run +// per-host summary reads these widths outside responseLock while reader +// goroutines are still widening them, which is reachable whenever the run ends +// on its grace timeout. Run with -race. +func TestHostColumnWidthIsRaceFree(t *testing.T) { + resetHeaders() + t.Cleanup(resetHeaders) + + var wg sync.WaitGroup + stop := make(chan struct{}) + + // Writers, as ingest does. + for w := 0; w < 3; w++ { + wg.Add(1) + go func(id int) { + defer wg.Done() + for i := 0; ; i++ { + select { + case <-stop: + return + default: + } + host := strings.Repeat("h", 10+(i+id)%40) + growHostColumns([]shared.DP{{Local: host, Remote: host + ":9010"}}) + } + }(w) + } + + // Readers, as the summary and the live table do. + for r := 0; r < 2; r++ { + wg.Add(1) + go func() { + defer wg.Done() + for { + select { + case <-stop: + return + default: + } + _ = colWidth(Local) + _ = colWidth(Remote) + _ = colWidth(TXA) + } + }() + } + + time.Sleep(300 * time.Millisecond) + close(stop) + wg.Wait() + + // Widths only ever grow, so the result must be the widest host seen. + if got := colWidth(Local); got < 10 { + t.Errorf("local width = %d, expected it to have grown", got) + } +} diff --git a/server/file.go b/server/file.go index 1d51004..9b9b5cf 100644 --- a/server/file.go +++ b/server/file.go @@ -29,39 +29,64 @@ import ( "github.com/minio/hperf/shared" ) -// testGlob builds the pattern matching one test's files. +// testFiles returns the on-disk files belonging to one test. // // Read and delete paths deliberately do NOT apply shared.ValidateTestID: files -// already on disk may have been written by an older server under no rules at -// all, and rejecting them here would leave a long-lived server pod listing -// tests it then refuses to serve or remove. The property that actually matters -// is that the pattern cannot escape the storage directory, which is what this -// checks. ValidateTestID still governs IDs that become NEW paths, in newTest. -func testGlob(id string) (string, error) { +// already on disk may have been written by an older server under looser rules, +// and rejecting them here would leave a long-lived server pod listing tests it +// then refuses to serve or remove. +// +// They must not glob, though. An ID handed to filepath.Glob is a *pattern*, so +// "*" matched every test's files and "[ab]*" matched a chosen subset -- which +// made `delete --id '*'` destroy every saved test, the same failure as the +// unanchored pattern in resetTestFiles. Matching directory entries by exact +// prefix has no pattern semantics, so a metacharacter in an ID is just a +// character. +// +// The suffix must be the numeric index newTestFile assigns. That has always +// been the format, so it costs no legacy compatibility, and it stops "my_test" +// from claiming "my_test.1.1" -- which belongs to the test named "my_test.1". +func testFiles(id string) ([]string, error) { if id == "" { - return "", errors.New("test id is empty") + return nil, errors.New("test id is empty") + } + // An entry name can never contain a separator, so these could only ever + // match nothing; rejecting them gives a clearer answer than silence. + if strings.ContainsRune(id, '/') || strings.ContainsRune(id, os.PathSeparator) || + id == "." || id == ".." { + return nil, fmt.Errorf("invalid test id (%s)", id) + } + + entries, err := os.ReadDir(basePath) + if err != nil { + // A missing storage directory simply holds no tests, which is what the + // previous glob reported too. + if os.IsNotExist(err) { + return nil, nil + } + return nil, err } - base := filepath.Clean(basePath) - pattern := filepath.Join(base, id+".*") - // Join cleans its result, so an id carrying a separator or ".." moves the - // pattern out of the storage directory and its parent stops being base. - if filepath.Dir(pattern) != base { - return "", fmt.Errorf("invalid test id (%s)", id) + + prefix := id + "." + files := make([]string, 0, 4) + for _, e := range entries { + if e.IsDir() || !strings.HasPrefix(e.Name(), prefix) { + continue + } + if _, convErr := strconv.Atoi(strings.TrimPrefix(e.Name(), prefix)); convErr != nil { + continue + } + files = append(files, filepath.Join(basePath, e.Name())) } - return pattern, nil + return files, nil } func streamTestFilesToWebsocket(p *wsPeer, testID string) (err error) { - pattern, err := testGlob(testID) + files, err := testFiles(testID) if err != nil { return err } - var files []string - files, err = filepath.Glob(pattern) - if err != nil { - return - } msg := new(shared.WebsocketSignal) for _, path := range files { if err = streamOneTestFile(p, msg, path); err != nil { @@ -98,8 +123,8 @@ func deleteTestsFromDisk(p *wsPeer, signal shared.WebsocketSignal) (err error) { defer SendDone(p) // An empty ID means "delete every test", which is what `hperf delete` - // without --id asks for. It has to return here: falling through would glob - // ".*" against a directory that no longer exists. + // without --id asks for. It has to return here: falling through would look + // for files under a directory that no longer exists. if signal.Config.TestID == "" { if err = os.RemoveAll(basePath); err != nil { SendError(p, err) @@ -107,14 +132,7 @@ func deleteTestsFromDisk(p *wsPeer, signal shared.WebsocketSignal) (err error) { return } - pattern, err := testGlob(signal.Config.TestID) - if err != nil { - SendError(p, err) - return - } - - var files []string - files, err = filepath.Glob(pattern) + files, err := testFiles(signal.Config.TestID) if err != nil { SendError(p, err) return diff --git a/server/regress_test.go b/server/regress_test.go index dcbc4d2..f25a67b 100644 --- a/server/regress_test.go +++ b/server/regress_test.go @@ -22,6 +22,7 @@ import ( "encoding/json" "errors" "fmt" + "io" "math" "net/http" "net/http/httptest" @@ -313,6 +314,110 @@ func TestResetTestFilesIsAnchored(t *testing.T) { } } +// TestTestIDIsNotAPattern covers the second time an unanchored pattern let one +// test reach another's files. The read and delete paths accept looser IDs than +// newTest does, so that files written by an older server stay reachable -- but +// they must not treat the ID as a glob. Before this, `delete --id '*'` removed +// every saved test and `--id '[ab]*'` removed a chosen subset. +func TestTestIDIsNotAPattern(t *testing.T) { + dir := t.TempDir() + oldBase := basePath + basePath = dir + string(os.PathSeparator) + t.Cleanup(func() { basePath = oldBase }) + + planted := []string{ + "alpha.1", "beta.1", "gamma.2", "prod-latency.1", + // IDs an older server would have accepted but ValidateTestID would not. + "legacy test.1", "my@test.1", + // Files whose names contain metacharacters, so a pattern-matching + // implementation cannot pass this test by accident. + "star.1", + } + for _, name := range planted { + if err := os.WriteFile(filepath.Join(dir, name), []byte("0{}\n"), 0o600); err != nil { + t.Fatal(err) + } + } + + // A metacharacter must select nothing, not everything. + for _, pattern := range []string{"*", "[ab]*", "?lpha", "alph[a]", "*a*"} { + files, err := testFiles(pattern) + if err != nil { + continue // rejecting outright is also acceptable + } + if len(files) != 0 { + t.Errorf("testFiles(%q) matched %v; an id must never be a pattern", pattern, files) + } + } + + // Deleting through the real handler must leave everything alone. + sig := shared.WebsocketSignal{} + sig.Config.TestID = "*" + _ = deleteTestsFromDisk(nil, sig) + for _, name := range planted { + if _, err := os.Stat(filepath.Join(dir, name)); err != nil { + t.Errorf("delete --id '*' destroyed %s", name) + } + } + + // Legacy IDs must still resolve, which is the whole reason this path is + // looser than ValidateTestID. + for _, id := range []string{"legacy test", "my@test", "alpha", "prod-latency"} { + files, err := testFiles(id) + if err != nil { + t.Errorf("testFiles(%q): %v", id, err) + continue + } + if len(files) != 1 { + t.Errorf("testFiles(%q) returned %v, want exactly one file", id, files) + } + } + + // And a real delete must remove only its own test. + sig.Config.TestID = "alpha" + _ = deleteTestsFromDisk(nil, sig) + if _, err := os.Stat(filepath.Join(dir, "alpha.1")); !os.IsNotExist(err) { + t.Error("alpha.1 should have been deleted") + } + for _, name := range planted[1:] { + if _, err := os.Stat(filepath.Join(dir, name)); err != nil { + t.Errorf("deleting alpha also removed %s", name) + } + } +} + +// TestTestIDSuffixAttribution: files are ., so "my_test" must not +// claim "my_test.1.1" -- that belongs to the test named "my_test.1". The old +// glob of id+".*" did claim it. +func TestTestIDSuffixAttribution(t *testing.T) { + dir := t.TempDir() + oldBase := basePath + basePath = dir + string(os.PathSeparator) + t.Cleanup(func() { basePath = oldBase }) + + for _, name := range []string{"my_test.1", "my_test.1.1", "my_test.notanindex"} { + if err := os.WriteFile(filepath.Join(dir, name), []byte("0{}\n"), 0o600); err != nil { + t.Fatal(err) + } + } + + outer, err := testFiles("my_test") + if err != nil { + t.Fatal(err) + } + if len(outer) != 1 || filepath.Base(outer[0]) != "my_test.1" { + t.Errorf(`testFiles("my_test") = %v, want just my_test.1`, outer) + } + + inner, err := testFiles("my_test.1") + if err != nil { + t.Fatal(err) + } + if len(inner) != 1 || filepath.Base(inner[0]) != "my_test.1.1" { + t.Errorf(`testFiles("my_test.1") = %v, want just my_test.1.1`, inner) + } +} + // TestUnsafeTestIDRejected keeps a client-supplied id from escaping the storage // directory, and keeps an empty id from matching every saved test. func TestUnsafeTestIDRejected(t *testing.T) { @@ -367,7 +472,7 @@ func TestStreamOneTestFileClosesFile(t *testing.T) { // release the connection and each failure burned an fd and two goroutines. func TestNonOKResponseReleasesConnection(t *testing.T) { srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - _, _ = io_Copy_Discard(r) + _, _ = drainBody(r) w.WriteHeader(http.StatusServiceUnavailable) })) defer srv.Close() @@ -415,16 +520,21 @@ func TestNonOKResponseReleasesConnection(t *testing.T) { } } -func io_Copy_Discard(r *http.Request) (int64, error) { +// drainBody reads a request body to completion. A clean end is io.EOF; anything +// else is returned, so a truncated or reset body is distinguishable from success. +func drainBody(r *http.Request) (int64, error) { defer r.Body.Close() buf := make([]byte, 32*1024) var total int64 for { n, err := r.Body.Read(buf) total += int64(n) - if err != nil { + if errors.Is(err, io.EOF) { return total, nil } + if err != nil { + return total, err + } } }