# Zig build run is 10x faster than compiled binary?

**URL:** <https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446>\
**Category:** Help\
**Tags:** compiler, build-system\
**Created:** [March 3, 2024, 5:44pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446 "2024-03-03T17:44:59Z")\
**Posts on this page:** 18\
**Page:** 1

<div class="post-metadata">

**Author:** ![mtlynch](https://ziggit.dev/user_avatar/ziggit.dev/mtlynch/32/1254_2.png) [@mtlynch](https://ziggit.dev/u/mtlynch)\
**Post date:** [March 3, 2024, 5:44pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/1 "2024-03-03T17:44:59Z")

</div>

I’m running into strange behavior with `zig build run`, and I’m hoping others might help explain what’s happening.

I have a simple Zig app that I can run with `zig build run`. But if I run the compiled binary afterwards, the performance is 10x worse than with `zig build run`.

### `src/main.zig`

```zig
const std = @import("std");

pub fn countBytes(reader: anytype) !u32 {
    var count: u32 = 0;
    while (true) {
        _ = reader.readByte() catch |err| switch (err) {
            error.EndOfStream => {
                return count;
            },
            else => {
                return err;
            },
        };
        count += 1;
    }
}

pub fn main() !void {
    var reader = std.io.getStdIn().reader();

    var timer = try std.time.Timer.start();
    const start = timer.lap();
    const count = try countBytes(&reader);
    const end = timer.read();
    const elapsed_micros = @as(f64, @floatFromInt(end - start)) / std.time.ns_per_us;

    const output = std.io.getStdOut().writer();
    try output.print("bytes: {}\n", .{count});
    try output.print("execution time: {d:.3}µs\n", .{elapsed_micros});
}

```

### `build.zig`

```zig
const std = @import("std");

pub fn build(b: *std.Build) void {
    const target = b.standardTargetOptions(.{});
    const optimize = b.standardOptimizeOption(.{});

    const exe = b.addExecutable(.{
        .name = "count-bytes",
        .root_source_file = .{ .path = "src/main.zig" },
        .target = target,
        .optimize = optimize,
    });

    b.installArtifact(exe);

    const run_cmd = b.addRunArtifact(exe);
    run_cmd.step.dependOn(b.getInstallStep());

    if (b.args) |args| {
        run_cmd.addArgs(args);
    }

    const run_step = b.step("run", "Run the app");
    run_step.dependOn(&run_cmd.step);
}

```

```bash
$ zig version
0.11.0

```

### Measuring runtime

If I run with `zig build run`, I see performance of 13µs:

```bash
$ echo '00010203040506070809' | xxd -r -p | zig build run -Doptimize=ReleaseFast
bytes: 10
execution time: 13.549µs

```

That `zig build run` command compiles a binary, but if I run that binary, performance is over 10x worse:

```bash
$ echo '00010203040506070809' | xxd -r -p | ./zig-out/bin/count-bytes 
bytes: 10
execution time: 162.195µs

```

I see the same thing if I compile the binary explicitly and run it:

```bash
$ rm -rf zig-out && zig build -Doptimize=ReleaseFast && echo '00010203040506070809' | xxd -r -p | ./zig-out/bin/count-bytes 
bytes: 10
execution time: 191.093µs

```

Does anyone know why `zig build run` seems to be outperforming the compiled binary by such a large margin?

---

<div class="post-metadata">

**Author:** ![dimdin](https://ziggit.dev/user_avatar/ziggit.dev/dimdin/32/1457_2.png) [@dimdin](https://ziggit.dev/u/dimdin)\
**Post date:** [March 3, 2024, 6:17pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/2 "2024-03-03T18:17:19Z")

</div>

Try to use `poop` for measuring: [Performance Optimizer Observation Platform](https://github.com/andrewrk/poop)

---

<div class="post-metadata">

**Author:** ![dimdin](https://ziggit.dev/user_avatar/ziggit.dev/dimdin/32/1457_2.png) [@dimdin](https://ziggit.dev/u/dimdin)\
**Post date:** [March 3, 2024, 6:25pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/3 "2024-03-03T18:25:48Z")

</div>

The answer must be `Input Buffering`.

---

<div class="post-metadata">

**Author:** ![dimdin](https://ziggit.dev/user_avatar/ziggit.dev/dimdin/32/1457_2.png) [@dimdin](https://ziggit.dev/u/dimdin)\
**Post date:** [March 3, 2024, 6:40pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/4 "2024-03-03T18:40:55Z")

</div>

Maybe I am wrong, it can be `Output Buffering` or both input & output buffering.  
The source code is in `lib/zig/std/Build/Step/Run.zig` functions `runCommand` and `spawnChildAndCollect`.

---

<div class="post-metadata">

**Author:** ![Clinton-Nmereole](https://ziggit.dev/user_avatar/ziggit.dev/clinton-nmereole/32/1335_2.png) [@Clinton-Nmereole](https://ziggit.dev/u/Clinton-Nmereole)\
**Post date:** [March 3, 2024, 10:06pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/5 "2024-03-03T22:06:11Z")

</div>

Interesting. I just tried this on the program I am working on using [hyperfine](https://github.com/sharkdp/hyperfine) for the benchmark and I got similar results.

zig build run command:

```zig
hyperfine "zig build run" -i
Benchmark 1: zig build run
  Time (mean ± σ): 77.6 ms ± 5.4 ms [User: 45.3 ms, System: 30.8 ms]
  Range (min … max): 75.4 ms … 109.6 ms 37 runs

```

running the binary:

```zig
hyperfine "zig-out/bin/.wordle" -i
Benchmark 1: zig-out/bin/.wordle
  Time (mean ± σ): 70.9 µs ± 39.9 µs [User: 380.2 µs, System: 385.6 µs]
  Range (min … max): 0.0 µs … 482.5 µs 1463 runs

```

---

<div class="post-metadata">

**Author:** ![dee0xeed](https://ziggit.dev/letter_avatar_proxy/v4/letter/d/3ab097/32.png) [@dee0xeed](https://ziggit.dev/u/dee0xeed)\
**Post date:** [March 4, 2024, 6:49am UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/6 "2024-03-04T06:49:17Z")

</div>

> [@Clinton-Nmereole](#):
>
> got similar results

They are are _opposite_ to what OP got.  
In your benchmark `zig build run` is ~1000 times _slower_ than running executable directly.

---

<div class="post-metadata">

**Author:** ![kristoff](https://ziggit.dev/user_avatar/ziggit.dev/kristoff/32/9_2.png) [@kristoff](https://ziggit.dev/u/kristoff)\
**Post date:** [March 4, 2024, 9:42am UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/7 "2024-03-04T09:42:55Z")

</div>

Also note that `zig build run` just compiles the executable and lanuches it, it’s not interpreting Zig or anything like that.

---

<div class="post-metadata">

**Author:** ![andrewrk](https://ziggit.dev/user_avatar/ziggit.dev/andrewrk/32/7011_2.png) [@andrewrk](https://ziggit.dev/u/andrewrk)\
**Post date:** [March 4, 2024, 6:18pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/8 "2024-03-04T18:18:14Z")

</div>

Looks like you’re doing 1 syscall per byte read? That’s going to perform extremely poorly. My guess is that the extra steps of using the build system incidentally introduced some buffering. Not sure why though. The build system is making the child process inherit the file descriptors directly.

---

<div class="post-metadata">

**Author:** ![matklad](https://ziggit.dev/user_avatar/ziggit.dev/matklad/32/2462_2.png) [@matklad](https://ziggit.dev/u/matklad)\
**Post date:** [March 5, 2024, 12:27am UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/9 "2024-03-05T00:27:53Z")

</div>

> [@andrewrk](#):
>
> Looks like you’re doing 1 syscall per byte read?

I’d say `readByte` is a flawed API to have on a Reader. While you _technically_ can read a byte-at-time from something like TCP socket, it just doesn’t make sense. The reader should only allow reading into a slice.

Byte-oriented API belongs to a buffered reader.

---

<div class="post-metadata">

**Author:** ![mtlynch](https://ziggit.dev/user_avatar/ziggit.dev/mtlynch/32/1254_2.png) [@mtlynch](https://ziggit.dev/u/mtlynch)\
**Post date:** [March 5, 2024, 1:07am UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/10 "2024-03-05T01:07:07Z")

</div>

> [@andrewrk](#):
>
> Looks like you’re doing 1 syscall per byte read? That’s going to perform extremely poorly. My guess is that the extra steps of using the build system incidentally introduced some buffering. Not sure why though. The build system is making the child process inherit the file descriptors directly.

Thanks! I’m still a Zig beginner, and I hadn’t realized I was performing a syscall for each `readByte` call, but now that you point that out, it makes sense.

I tried switching to `std.io.bufferedReader`, and it makes the performance gap between `zig build run` and the compiled binary even wider, but it’s good to know that it’s not something I’m misunderstanding about Zig.

If I run the commands with `hyperfine` instead, it reports that running the compiled binary is 23x faster than `zig build run` (even when the build is cached).

---

<div class="post-metadata">

**Author:** ![andrewrk](https://ziggit.dev/user_avatar/ziggit.dev/andrewrk/32/7011_2.png) [@andrewrk](https://ziggit.dev/u/andrewrk)\
**Post date:** [March 5, 2024, 5:36am UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/11 "2024-03-05T05:36:47Z")

</div>

This never occurred to me, but now that you mention it, it makes perfect sense.

---

<div class="post-metadata">

**Author:** ![mtlynch](https://ziggit.dev/user_avatar/ziggit.dev/mtlynch/32/1254_2.png) [@mtlynch](https://ziggit.dev/u/mtlynch)\
**Post date:** [March 5, 2024, 10:31pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/12 "2024-03-05T22:31:33Z")

</div>

**tl; dr - The `zig build run` version appeared to run faster because it wasn’t waiting on `echo` or `xxd` to feed input to stdin.**

To close the loop on this, [Andrew Ayer explained the phenomenon](https://follow.agwa.name/objects/c41887a6-a863-42ea-a47f-b12961afec2c) I was observing.

My mental model was that `echo` ran, then piped its results to `xxd`, then `xxd` finished and piped its results to my Zig program.

But actually in a bash pipeline, all the commands in the pipeline start at the same time.

The reason why I measured slower performance in the `./count-bytes` invocation was that it was actually running _faster_. The binary started the timer immediately and then had to block on the `countBytes` call for input to arrive from `xxd`, which hadn’t started producing output yet.

In the `zig build run` version, what was probably happening was that calling `zig build run` rather than `./count-bytes` meant that `count-bytes` timer started later, as the overhead of `zig build` probably adds 100+ms. So, instead of `count-bytes` starting immediately and then having to wait ~100ms for `echo` and `xxd` to get input into stdin, by the time the `zig build run` version starts the program, `echo` and `xxd` have finished their work, so `count-bytes` doesn’t have to wait to read from stdin.

---

<div class="post-metadata">

**Author:** ![Clinton-Nmereole](https://ziggit.dev/user_avatar/ziggit.dev/clinton-nmereole/32/1335_2.png) [@Clinton-Nmereole](https://ziggit.dev/u/Clinton-Nmereole)\
**Post date:** [March 7, 2024, 6:07am UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/13 "2024-03-07T06:07:44Z")

</div>

apparently I either can’t read or had too much coffee when I made that post. I apologize for being an idiot.

---

<div class="post-metadata">

**Author:** ![mtlynch](https://ziggit.dev/user_avatar/ziggit.dev/mtlynch/32/1254_2.png) [@mtlynch](https://ziggit.dev/u/mtlynch)\
**Post date:** [March 19, 2024, 5:09pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/14 "2024-03-19T17:09:31Z")

</div>

Sorry for the bump, but I found this case so interesting that I did a detailed writeup on my blog with visual explanations for why the two commands had such different timings.

- [Why does an extraneous build step make my Zig app 10x faster?](https://mtlynch.io/zig-extraneous-build/)

---

<div class="post-metadata">

**Author:** ![andrewrk](https://ziggit.dev/user_avatar/ziggit.dev/andrewrk/32/7011_2.png) [@andrewrk](https://ziggit.dev/u/andrewrk)\
**Post date:** [March 19, 2024, 5:53pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/15 "2024-03-19T17:53:11Z")

</div>

Thanks for sharing! That is a well-written writeup.

---

<div class="post-metadata">

**Author:** ![rofrol](https://ziggit.dev/user_avatar/ziggit.dev/rofrol/32/231_2.png) [@rofrol](https://ziggit.dev/u/rofrol)\
**Post date:** [March 19, 2024, 9:32pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/16 "2024-03-19T21:32:11Z")

</div>

great. you may be interested in comments here about bash pipes [Pipexec – Handling pipe of commands like a single command | Hacker News](https://news.ycombinator.com/item?id=39656056)

---

<div class="post-metadata">

**Author:** ![rofrol](https://ziggit.dev/user_avatar/ziggit.dev/rofrol/32/231_2.png) [@rofrol](https://ziggit.dev/u/rofrol)\
**Post date:** [March 20, 2024, 4:58pm UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/17 "2024-03-20T16:58:06Z")

</div>

I just read this:

anonymous-panda:

My hunch is that if you added the buffered reader and kept the original xxd in the pipe you’d see similar timings.

The amount of input data is just laughably small here to result in a huge timing discrepancy.

I wonder if there’s an added element where the constant syscalls are reading on a contended mutex and that contention disappears if you delay the start of the program.

vlovich123:

Good hunch. On my machine (13900k) & zig 0.11, the latest version of the code:

`INFILE="$(mktemp)" && echo $INFILE && \ echo '60016000526001601ff3' | xxd -r -p > "${INFILE}" && \ zig build run -Doptimize=ReleaseFast < "${INFILE}" > execution time: 27.742µs`

vs

`echo '60016000526001601ff3' | xxd -r -p > "${INFILE}" | zig build run -Doptimize=ReleaseFast < "${INFILE}"EVM gas used: 18 > execution time: 27.999µs`

The idea that the overlap of execution here by itself plays a role is nonsensical. The overlap of execution + reading a byte at a time causing kernel mutex contention seems like a more plausible explanation although I would expect someone better knowledgeable (& more motivated) about capturing kernel perf measurements to confirm. If this is the explanation, I’m kind of surprised that there isn’t a lock-free path for pipes in the kernel.

> <https://news.ycombinator.com/item?id=39768022>
>
> My hunch is that if you added the buffered reader and kept the original xxd in the pipe you’d see similar timings.\<p\>The amount of input data is just laughably small here to result in a huge timing discrepancy.\<p\>I wonder if there’s an added element where the constant syscalls are reading on a contended mutex and that contention disappears if you delay the start of the program.

---

<div class="post-metadata">

**Author:** ![mtlynch](https://ziggit.dev/user_avatar/ziggit.dev/mtlynch/32/1254_2.png) [@mtlynch](https://ziggit.dev/u/mtlynch)\
**Post date:** [March 21, 2024, 12:15am UTC](https://ziggit.dev/t/zig-build-run-is-10x-faster-than-compiled-binary/3446/18 "2024-03-21T00:15:52Z")

</div>

There aren’t enough details in that post to really be sure how that person got those measurements. If I take it at face value, their test is invalid because, in test 2, `INFILE` is available for reading before `xxd` populates it because they didn’t remove the file after test 1.

Regardless, my results are public, so if you have other explanations for why the pipelining change fixed the performance discrepancy, I’m interested to hear.

- [The change](https://github.com/mtlynch/eth-zvm/pull/27)
- [Benchmarks before](https://output.circle-artifacts.com/output/job/2f6666c1-1165-4f10-b62f-267ebaf250c3/artifacts/0/benchmarks/benchmarks.html)
- [Benchmarks after](https://output.circle-artifacts.com/output/job/457cd247-dd7c-4b73-9a09-ea00db7bdfe5/artifacts/0/benchmarks/benchmarks.html)