speedtest-hd/README.md

# speedtest-hd

A robust, CrystalDiskMark‑style storage benchmark for Linux, built on [`fio`](https://fio.readthedocs.io/) by mReschke and my buddy Claude Opus.

It runs the same four tests CrystalDiskMark does, plus a dedicated **SLOG / sync‑write latency profile** for diagnosing ZFS ZIL performance (NFS / iSCSI / VM sync workloads). It auto‑detects the best IO engine and whether `O_DIRECT` works on the target, and falls back to a basic `dd` test when `fio` isn't installed.

---

## Table of contents

- [Features](#features)
- [Requirements](#requirements)
- [Usage](#usage)
- [Output](#output)
- [Understanding the tests](#understanding-the-tests)
- [Case study: diagnosing a "slow" Optane SLOG on TrueNAS](#case-study-diagnosing-a-slow-optane-slog-on-truenas)
- [Notes & caveats](#notes--caveats)

---

## Features

- **CrystalDiskMark‑style profile** — `SEQ1M Q8T1`, `SEQ1M Q1T1`, `RND4K Q32T16`, `RND4K Q1T1` (CrystalDiskMark's default profile), each measured for Read **and** Write, reported in both **MB/s** and **IOPS**.
- **SLOG / sync‑write latency profile** (`--slog`) — synchronous 4K writes at T1/T4/T8/T16 reporting **IOPS, MB/s, and p50/p99 commit latency**. This is the load a ZFS SLOG actually sees.
- **Auto‑detection** — picks the fastest available IO engine (`io_uring` → `libaio` → `posixaio` → `sync`) and probes whether `O_DIRECT` works on the filesystem, falling back to buffered IO when it doesn't (e.g. older OpenZFS, some NFS mounts).
- **`dd` fallback** — if `fio` isn't present, runs a basic write/read test so you still get a number.
- **Verbose mode** — `--verbose` dumps the full raw `fio` output for every run while keeping the summary table intact.

---

## Requirements

- `python3` (3.7+) — the tool itself. It parses `fio`'s JSON output using only the standard library (no third‑party packages to install).
- [`fio`](https://fio.readthedocs.io/) — recommended (`apt install fio` / `pacman -S fio`). Without it, the tool falls back to a basic `dd` test.
- `sudo` — `fio` is invoked via `sudo` so it can use `O_DIRECT` and flush device caches.

---

## Usage

```bash
./speedtest-hd.py <path> [options]
# or: python3 speedtest-hd.py <path> [options]
```

`<path>` is the directory (or mount) to benchmark. Use `.` for the current directory. The tool creates a single test file (default 1 GiB) on the target and removes it afterward, so ensure enough free space.

### Modes

| Invocation | What it does |
|---|---|
| `./speedtest-hd.py /mnt/disk` | Auto: uses `fio` if installed, else `dd` |
| `./speedtest-hd.py /mnt/disk --fio` | Force the `fio` CrystalDiskMark‑style profile |
| `./speedtest-hd.py /mnt/disk --dd` | Force the basic `dd` test |
| `./speedtest-hd.py /mnt/disk --slog` | SLOG / sync‑write latency profile |

`--fio`, `--dd`, and `--slog` are mutually exclusive.

### Tuning flags

| Flag | Effect |
|---|---|
| `--engine {io_uring,libaio,posixaio,sync}` | Force a specific IO engine (default: auto) |
| `--direct` | Force `O_DIRECT` (bypass page cache) |
| `--buffered` | Force buffered IO (e.g. when `O_DIRECT` is unsupported) |
| `--runtime SEC` | Seconds per run (default: 5, like CrystalDiskMark) |
| `--size SIZE` | Test file size (default: `1g`) |
| `--verbose` | Also print the full `fio` output for every run (summary table unchanged) |
| `-y`, `--yes` | Skip the confirmation prompt (for scripting/automation) |

> All flags accept either `--flag value` or `--flag=value` (argparse). `--direct`/`--buffered` are mutually exclusive.

### Examples

```bash
# CrystalDiskMark-style test of the current directory
./speedtest-hd.py .

# Larger file, longer runs, on an NVMe pool
./speedtest-hd.py /mnt/nvmepool --runtime=10 --size=4g

# Buffered (e.g. an NFS share that doesn't support O_DIRECT)
./speedtest-hd.py /mnt/nfsshare --buffered

# SLOG / sync latency profile, 30s per run
./speedtest-hd.py /mnt/nvme-ultra-r10/vm-root --slog --runtime=30

# Unattended (no prompt), forcing a specific engine
./speedtest-hd.py /mnt/nvmepool --yes --engine io_uring
```

> **Tip:** when running `--slog` against a ZFS dataset, watch the SLOG live in another shell:
> ```bash
> zpool iostat -vl <pool> 1
> ```

---

## Output

### CrystalDiskMark‑style profile

Representative output from a healthy local NVMe (your numbers will differ):

```
+------------------+----------------+----------------+----------------+----------------+
| Test             |    Read (MB/s) |   Write (MB/s) |    Read (IOPS) |   Write (IOPS) |
+------------------+----------------+----------------+----------------+----------------+
| SEQ1M  Q8T1      |        3650.00 |        3120.00 |           3482 |           2976 |
| SEQ1M  Q1T1      |        2680.00 |        2510.00 |           2556 |           2394 |
| RND4K  Q32T16    |        2950.00 |        2240.00 |         720215 |         546875 |
| RND4K  Q1T1      |          78.00 |          64.00 |          19043 |          15625 |
+------------------+----------------+----------------+----------------+----------------+
```

### SLOG / sync‑write latency profile (`--slog`)

```
+------------------+--------------+--------------+--------------+--------------+
| Test             |         IOPS |         MB/s |  p50 lat(us) |  p99 lat(us) |
+------------------+--------------+--------------+--------------+--------------+
| 4K sync T1       |        10687 |        43.77 |         85.5 |        185.3 |
| 4K sync T4       |        29873 |       122.36 |        117.8 |        317.4 |
| 4K sync T8       |        52612 |       215.50 |        136.2 |        391.2 |
| 4K sync T16      |        77939 |       319.24 |        180.0 |        505.9 |
+------------------+--------------+--------------+--------------+--------------+
```

---

## Understanding the tests

### The CrystalDiskMark profile

| Test | Pattern | Queue depth | Threads |
|---|---|---|---|
| `SEQ1M Q8T1` | Sequential 1 MiB | 8 | 1 |
| `SEQ1M Q1T1` | Sequential 1 MiB | 1 | 1 |
| `RND4K Q32T16` | Random 4 KiB | 32 | 16 |
| `RND4K Q1T1` | Random 4 KiB | 1 | 1 |

`Q` = queue depth (`--iodepth`), `T` = threads (`--numjobs`). Note that `--iodepth` only produces real queue depth when the IO is truly asynchronous (async engine **and** `O_DIRECT`). On filesystems where that isn't available, queue depth effectively collapses toward 1 and concurrency comes only from threads (`T`).

### The SLOG profile

`--slog` forces **synchronous** 4K random writes (`--sync=1` → `O_SYNC`) via the portable `psync` engine. Every write becomes a durable commit, so it traverses the ZFS ZIL / SLOG commit path exactly the way a `sync=always` dataset (NFS, iSCSI, VM storage) does — regardless of the dataset's own `sync` property. It sweeps thread counts (T1 → T4 → T8 → T16):

- **T1** is the headline single‑stream latency (e.g. one database committing in a tight loop).
- **The sweep** shows how the SLOG scales as concurrent sync writers pile on (multiple VMs / NFS clients) — usually the more important number for a virtualization host.

A healthy Optane SLOG (e.g. P1600X) single‑stream target is roughly **15–25k IOPS, p50 ~40–65 µs**. Much higher latency usually points at **CPU C‑states / PCIe ASPM / a BIOS power profile** throttling the host — see the case study below.

---

## Case study: diagnosing a "slow" Optane SLOG on TrueNAS

A real investigation that this tool's `--slog` mode was built to support. **Spoiler: the Optane SSD was healthy the entire time. The bottleneck was CPU power management.**

### The setup

| Component | Detail |
|---|---|
| Server | Dell PowerEdge R630 |
| CPU | Intel Xeon E5‑2680 v3 (Haswell‑EP, 12C/24T, 2.5 GHz base, 3.3 GHz turbo) |
| OS | TrueNAS SCALE 25.10 (OpenZFS 2.3) |
| Pool | `nvme-ultra-r10` — 6× 4 TB KingSpec XG7000 NVMe in RAID10 (3 mirror vdevs) |
| SLOG | Intel Optane **P1600X** |
| Dataset | `/mnt/nvme-ultra-r10/vm-root`, `sync=always` |

### The symptom

The standard benchmark looked alarming — huge reads, tiny writes:

```
+------------------+------------------+------------------+
| Test             |      Read (MB/s) |     Write (MB/s) |
+------------------+------------------+------------------+
| SEQ1M  Q8T1      |          6873.00 |             9.30 |
| SEQ1M  Q1T1      |          1608.00 |            20.00 |
| RND4K  Q32T1     |           538.00 |            10.80 |
| RND4K  Q32T16    |           689.00 |           261.00 |
+------------------+------------------+------------------+
```

9.3 MB/s sequential write on an Optane‑backed NVMe pool looks broken.

> **Note:** this investigation was captured with an earlier test profile that used `RND4K Q32T1` in place of today's `RND4K Q1T1`. The `Q32T1` vs `Q32T16` comparison below is exactly why the default later changed — see finding #3.

### Investigation

**1. The reads are RAM, not disk.** With a 1 GiB test file on ZFS, reads come straight from ARC (RAM cache). The huge read/write asymmetry is the tell — ignore the read column for judging the disks.

**2. `sync=always` makes writes latency‑bound.** Every write must be durably committed to the ZIL before it's acknowledged, so throughput ≈ (block size) ÷ (per‑commit latency). Anything running at low effective concurrency looks slow regardless of raw device speed.

**3. The `Q8`/`Q32` labels were misleading.** On this ZFS setup `--iodepth` didn't produce real queue depth, so most rows effectively ran at QD1. Proof: `RND4K Q32T1` (10.8 MB/s) vs `RND4K Q32T16` (261 MB/s) — the 24× jump came entirely from threads (`numjobs=16`), not queue depth.

**4. Large sequential sync writes bypass the SLOG.** With ZFS's default `logbias=latency`, writes larger than `zfs_immediate_write_sz` (32 KB) use an *indirect* ZIL record — the data goes straight to the main pool and only a pointer hits the Optane. So the `SEQ1M` write test was measuring the **consumer KingSpec pool's** forced‑sync performance, not the SLOG. Only small (4K) sync writes exercise the Optane.

**5. Confirm with `zpool iostat -vl <pool> 1` during a 4K sync test.** This was decisive:

- The `logs` (Optane) vdev took **all** the sync writes (~2.3–2.6k ops, ~18–20 MB/s); the data vdevs were idle between txg flushes. → **SLOG configured correctly, `logbias` fine, not bypassed.**
- But the Optane's own `disk_wait` was **~90 µs** (a P1600X should be ~10–15 µs), and the fio‑level commit latency was **~328 µs** — meaning ~238 µs was being spent *above* the device, in the host/ZFS/CPU path.

That "faster when busy, slow when idle" device latency plus huge host overhead is the classic signature of **power‑saving idle states** on a latency‑bound, QD1 workload.

**6. Find the throttle.** Checking the CPU revealed the cores pinned at **1.2 GHz** — the E5‑2680 v3's *minimum* P‑state — on a chip rated for 2.5–3.3 GHz:

```
$ grep MHz /proc/cpuinfo | sort -u
cpu MHz : 1200.069
...

$ cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_driver
intel_cpufreq                # = intel_pstate in passive mode
$ cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor
schedutil                    # picks frequency from CPU utilization
```

The vicious loop: a QD1 sync workload spends each commit **blocked** waiting on the SLOG → the `schedutil` governor sees near‑zero utilization → parks the cores at 1.2 GHz → the ZFS commit code path runs ~2–3× slower → latency climbs.

### Root cause

**CPU power management, in two layers — not the SSD, pool, or PCIe link:**

1. **BIOS System Profile = "Performance Per Watt Optimized (DAPC)"** — Dell Active Power Controller manages C‑states/P‑states in firmware and largely ignores the OS, keeping cores idling deep and clocked low.
2. **OS `schedutil` governor** (TrueNAS SCALE default) — pinned cores at the 1.2 GHz floor for this bursty, IO‑blocked workload.

### The fixes

Applied in order, biggest impact last:

**1. BIOS System Profile → Performance** (disables C‑states/C1E, raises P‑states):
```
# In BIOS (F2): System BIOS → System Profile Settings → System Profile → Performance
# Or via iDRAC:
racadm set BIOS.SysProfileSettings.SysProfile PerfOptimized
racadm jobqueue create BIOS.Setup.1-1
# reboot to apply
```

**2. Kernel parameters** (target PCIe/NVMe link power saving + residual C‑states). On TrueNAS: *System → Advanced Settings → Kernel Arguments*, then reboot:
```
intel_idle.max_cstate=1 processor.max_cstate=1 pcie_aspm=off nvme_core.default_ps_max_latency_us=0
```

**3. CPU governor → `performance`** *(the single biggest win)*:
```bash
echo performance | tee /sys/devices/system/cpu/cpu*/cpufreq/scaling_governor
```
Make it persistent on TrueNAS — *System → Advanced Settings → Init/Shutdown Scripts*, add a **Post Init** *Command*:
```
echo performance | tee /sys/devices/system/cpu/cpu*/cpufreq/scaling_governor
```
> ⚠️ Without the Post Init script the governor reverts to `schedutil` on every reboot, silently dropping you back to slow numbers.

### Results — before & after

**4K synchronous random writes** (`--slog`), per stage of the fix:

| Stage | T1 IOPS | T1 p50 | T1 MB/s | T16 IOPS | T16 MB/s | T16 p99 |
|---|---|---|---|---|---|---|
| **DAPC** (start) | ~3,050 | ~328 µs | ~12.5 | — | 38 *(regressing)* | thrashing |
| BIOS → Performance | 5,849 | 160.8 µs | 23.96 | 46,009 | 188.45 | 1057 µs |
| + kernel parameters | 6,217 | 150.5 µs | 25.46 | 47,166 | 193.19 | 684 µs |
| **+ `performance` governor** | **10,687** | **85.5 µs** | **43.77** | **77,939** | **319.24** | **506 µs** |

**Full final result:**

```
+------------------+--------------+--------------+--------------+--------------+
| Test             |         IOPS |         MB/s |  p50 lat(us) |  p99 lat(us) |
+------------------+--------------+--------------+--------------+--------------+
| 4K sync T1       |        10687 |        43.77 |         85.5 |        185.3 |
| 4K sync T4       |        29873 |       122.36 |        117.8 |        317.4 |
| 4K sync T8       |        52612 |       215.50 |        136.2 |        391.2 |
| 4K sync T16      |        77939 |       319.24 |        180.0 |        505.9 |
+------------------+--------------+--------------+--------------+--------------+
```

**Net improvement:** ~**3.5× IOPS**, ~**3.8× lower latency** at T1, and ~**8.4× aggregate throughput** at T16 — with the scaling regression eliminated entirely.

### Lessons learned

- **An Optane SLOG showing high latency is usually a host‑side power‑management problem, not the device.** Confirm where the time goes before blaming hardware.
- **`zpool iostat -vl <pool> 1` is the key diagnostic** — it shows whether the `logs` vdev is actually taking the writes and splits device latency (`disk_wait`) from host/ZFS overhead (`total_wait`).
- **Latency‑bound QD1 sync workloads are the worst case for power saving.** The CPU looks idle (blocked on IO), so governors and firmware clock it down — which directly inflates the latency you're trying to measure.
- **On TrueNAS SCALE, the default `schedutil` governor cripples sync‑write latency.** Set `performance` (and persist it).
- **Reads from a small test file measure ARC (RAM), not the disk.** Watch the read/write asymmetry.
- **Large sync writes bypass the SLOG** (indirect ZIL) — to actually test a SLOG, use small (4K) sync writes, which is exactly what `--slog` does.

### `~85 µs` is roughly the floor here

The residual gap from raw Optane (~15 µs) is ZFS ZIL‑commit overhead plus the per‑op cost of a 2014‑era Haswell core. Closing it further would need a newer/faster CPU for sharply diminishing returns. For a virtualization host the aggregate (78k IOPS / 319 MB/s) is what the workload feels, and it's healthy.

---

## Notes & caveats

- **`sudo`** is used for `fio` so it can apply `O_DIRECT` and flush device write caches at the end of write runs (`--end_fsync=1`), so cached writes can't inflate results.
- **`O_DIRECT` is auto‑detected.** If the banner shows `O_DIRECT: DISABLED (buffered ...)`, results may reflect the page cache (RAM) rather than the device.
- **A single shared test file** is reused across runs to keep the footprint to one file.
- **All profiles parse `fio`'s JSON output** (`--output-format=json`) with Python's standard library — robust, unit‑safe metrics with no fragile text scraping.
- The `--slog` profile forces synchronous IO and is intended for ZFS ZIL / SLOG and other sync‑write (NFS/iSCSI/VM) investigations.