diff --git a/.github/workflows/go.yml b/.github/workflows/go.yml index ef5fc4b..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,6 +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 + 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 ./... + 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. 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 ./... + 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..8d67839 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -20,14 +20,23 @@ 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 docker build -t hperf:latest . @@ -59,8 +68,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 +81,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 +119,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..162fabd 100644 --- a/README.md +++ b/README.md @@ -147,24 +147,63 @@ 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` | 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 | +| `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. + +`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 +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 +223,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 +261,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 +273,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 +291,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 +360,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 +401,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..bec3700 --- /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, 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 new file mode 100644 index 0000000..1c6523c --- /dev/null +++ b/client/aggregate_test.go @@ -0,0 +1,403 @@ +// 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) + } +} + +// 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, 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"} + + 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) + } + + // 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++ { + socket.reportReady(ready, errors.New("flap")) + } + }() + + select { + case <-done: + case <-time.After(5 * time.Second): + t.Fatal("reportReady 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..0e805b1 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,138 @@ 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 + + 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) 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) +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) Close() (err error) { - return c.Remove() +// 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 (c *wsClient) Remove() (err error) { - err = c.Con.Close() - websockets[c.ID] = nil - return +// 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) + } } -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 - } +// 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: } +} - 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 +187,131 @@ 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 + defer func() { - r := recover() - if r != nil { + if r := recover(); r != nil { fmt.Println(r, string(debug.Stack())) } + socket.reportReady(ready, 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 +322,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 +357,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() + 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 + // 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 +387,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 +455,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 +497,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 +515,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 +533,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 - } - printCount++ - - 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 - } + 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) } + responseLock.Unlock() - 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 +595,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 } @@ -487,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)}, ) } @@ -499,13 +669,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 +699,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,67 +714,98 @@ 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) if err != nil { return err } - defer f.Close() - for i := range responseDPS { - _, err := shared.WriteStructAndNewLineToFile(f, shared.DataPoint, responseDPS[i]) - if err != nil { + // 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 { 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 + err = w.Flush() + return err +} + +// 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 +815,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 +941,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 +953,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 +1030,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..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" @@ -32,7 +33,7 @@ type header struct { } type column struct { - value interface{} + value any width int } @@ -52,6 +53,7 @@ const ( TX TXH TXL + TXA TXT TXCount ErrCount @@ -64,9 +66,68 @@ const ( CPULow ID HumanTime + Samples 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() { headerSlice[IntNumber] = header{"#", 5} headerSlice[Created] = header{"Created", 8} @@ -76,9 +137,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,19 +156,17 @@ 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, +// and reports whether either changed so the caller can reprint the header. 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 + 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 } } @@ -123,8 +186,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,14 +201,10 @@ 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) + hs = append(hs, colWidth(fields[i]), headerSlice[fields[i]].label) } fmt.Println(HeaderStyle.Render(fmt.Sprintf(fs, hs...))) @@ -151,7 +212,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 +228,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 +257,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) } @@ -231,35 +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.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.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") @@ -271,39 +334,53 @@ 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[TTFBH].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") } } -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 +388,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 +405,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 +419,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/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/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..9b9b5cf 100644 --- a/server/file.go +++ b/server/file.go @@ -19,66 +19,128 @@ 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) { - var files []string - files, err = filepath.Glob(filepath.Join(basePath, testID+".*")) +// 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 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 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 { - return + // 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 } + + 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 files, nil +} + +func streamTestFilesToWebsocket(p *wsPeer, testID string) (err error) { + files, err := testFiles(testID) + if err != nil { + return err + } + 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 look + // for files under 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 } - var files []string - files, err = filepath.Glob(filepath.Join(basePath, signal.Config.TestID+".*")) + files, err := testFiles(signal.Config.TestID) 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 +172,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..f25a67b --- /dev/null +++ b/server/regress_test.go @@ -0,0 +1,616 @@ +// 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" + "io" + "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) + } + } +} + +// 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) { + 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) { + _, _ = drainBody(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) + } +} + +// 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 errors.Is(err, io.EOF) { + return total, nil + } + if err != nil { + return total, err + } + } +} + +// 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) }) }