Wall time minus CPU time

Measure your machineNeeds Python

Problem

A CPU profiler samples what the processor is doing, so time spent waiting (for a disk, a lock, the network) does not appear in it. When a slow operation is mostly waiting, its flamegraph shows only the small CPU part, and optimizing that part changes little. The quick test is to compare wall-clock time with CPU time: the difference is waiting.

Pick an operation that touches disk: writing 10,000 small records and calling fsync after each one. Measure wall-clock time and CPU time for the same loop. Then move the fsync out of the loop (call it once every 100 writes, a simple group commit). The run is repeated with F_FULLFSYNC, which on macOS is what actually reaches the device (plain fsync there stops at the drive's cache).

The question. What share of the loop is waiting, and what does flushing once per 100 writes do to wall time and to CPU time?

Predict

On macOS with plain fsync after every write, what share of the loop's wall time is waiting rather than on CPU?

Under 20%20 to 50%50 to 80%Over 80%

Run it

1Install uv once. It fetches Python and the lab's packages for you.
Terminal
```
curl -LsSf https://astral.sh/uv/install.sh | sh
```

2Get the script. It is the whole lab: read it, then download it.

wall-time-minus-cpu-time.py47 linesDownload

View the code

wall-time-minus-cpu-time.py

# /// script
# requires-python = ">=3.10"
# ///
# Copyright (c) 2026 Aayush Sharma · SPDX-License-Identifier: MIT
# https://thedataengineering.com/lab-code/LICENSE.txt
"""Wall time minus CPU time.

10,000 small writes with an fsync after each, timed by the wall clock and by
CPU time; then the same writes with one fsync every 100 (a simple group
commit). On macOS, --full-fsync uses F_FULLFSYNC, which is what actually
reaches the device there.
"""
import argparse, fcntl, json, os, tempfile, time

p = argparse.ArgumentParser(description=__doc__.splitlines()[0])
p.add_argument("--writes", type=int, default=10_000, help="Records to write.")
p.add_argument("--size", type=int, default=100, help="Bytes per record.")
p.add_argument("--group", type=int, default=100, help="Writes per fsync in the group-commit run.")
p.add_argument("--full-fsync", action="store_true", help="macOS: flush with F_FULLFSYNC instead of fsync.")
p.add_argument("--json", help="Also write the results to this JSON file.")
args = p.parse_args()

def sync(fd):
    if args.full_fsync: fcntl.fcntl(fd, fcntl.F_FULLFSYNC)
    else: os.fsync(fd)                                             # force the write to the disk

def loop(every):
    path = os.path.join(tempfile.mkdtemp(), "lab5.dat")
    fd = os.open(path, os.O_WRONLY | os.O_CREAT | os.O_TRUNC)
    w0, c0 = time.perf_counter(), time.process_time()
    for i in range(args.writes):
        os.write(fd, b"x" * args.size)
        if (i + 1) % every == 0: sync(fd)
    w1, c1 = time.perf_counter(), time.process_time()
    os.close(fd); os.remove(path)
    wall, cpu = w1 - w0, c1 - c0
    return {"run": f"fsync every {every} write{'s' if every > 1 else ''}", "wall_s": wall, "cpu_s": cpu, "waiting_pct": (1 - cpu / wall) * 100}

rows = [loop(1), loop(args.group)]
summary = {"speedup": rows[0]["wall_s"] / rows[1]["wall_s"], "cpu_ratio": rows[0]["cpu_s"] / rows[1]["cpu_s"]}
for r in rows: print(f"{r['run']:<22} wall={r['wall_s']:.2f}s  cpu={r['cpu_s']:.2f}s  waiting={r['waiting_pct']:.0f}%")
print(f"group commit: wall time {summary['speedup']:.0f}x lower, CPU time {summary['cpu_ratio']:.1f}x lower")

if args.json:
    with open(args.json, "w") as f:
        json.dump({"summary": summary, "tables": {"runs": rows}}, f)

3Run it in the folder you saved it to, with the defaults first. Then change a knob from the table below and run it again.
Terminal
```
uv run wall-time-minus-cpu-time.py
uv run wall-time-minus-cpu-time.py --help     # every knob
```

Knobs
Knob · default	What it changes
--writes10,000	Records to write.
--size100	Bytes per record.
--group100	Writes per fsync in the group-commit run.
--full-fsync—	macOS: flush with F_FULLFSYNC instead of fsync.

Our run

Wall against CPU

Wall against CPU
Run	Wall	CPU	Waiting
fsync every 1 write	287 ms	111 ms	61.3%
fsync every 100 writes	25.5 ms	20.9 ms	18%

Reference runApple M2 · 8 cores · 8 GB

Output · uv run wall-time-minus-cpu-time.py

fsync every 1 write    wall=0.29s  cpu=0.11s  waiting=61%
fsync every 100 writes wall=0.03s  cpu=0.02s  waiting=18%
group commit: wall time 11x lower, CPU time 5.3x lower

macOS 26.6.2 · Python 3.13.3 · run 2026-10-20 · 2 runs

What we found

With plain fsync, the loop spent 61.3% of its time waiting, and grouping 100 writes per flush cut wall time by 11.2×: on macOS plain fsync is cheap, so the effect is small. With F_FULLFSYNC, the loop spent 96.6% of its time waiting (28 s of wall time against 945 ms of CPU), and grouping cut wall time by 76.2×. CPU time fell too (16×), not "almost the same": each flush call has a CPU cost of its own.

Read it

A profile that shows only CPU is blind to the dominant cost of I/O-bound code. Compare wall and CPU time first; if most of the time is waiting, use an off-CPU view (what threads were blocked on) or simply restructure the waiting, as group commit does.

Go further

If you have Linux with perf, compare perf record (on-CPU) with an off-CPU tool such as offcputime from bcc. On macOS, compare Instruments "Time Profiler" with "System Trace".