过去几个月，我一直对两项技术很感兴趣：Zig 编程语言和以太坊（Ethereum）加密货币。为了同时深入了解这两者，我一直在用 Zig 编写一个以太坊虚拟机（Ethereum Virtual Machine）的字节码解释器。

Zig 是一门非常适合性能优化的语言，因为它让你能够对内存和控制流进行细粒度的控制。为了激励自己，我一直在把我的以太坊实现与官方的 Go 实现进行基准测试对比。

最近，我对基准测试脚本做了一个我认为很简单的重构，但应用的性能却大幅下滑。我把问题定位到了这两条命令的差异上：

$ echo '60016000526001601ff3' | xxd -r -p | zig build run -Doptimize=ReleaseFast
execution time:  58.808µs

$ echo '60016000526001601ff3' | xxd -r -p | ./zig-out/bin/eth-zvm
execution time:  438.059µs

zig build run 只是一个快捷命令，用于编译二进制文件并执行它。它应该等价于下面两条命令：

zig build
./zig-out/bin/eth-zvm

一个额外的构建步骤怎么会让我的程序运行得快了近 10 倍？

创建该现象的最小复现

为了调试这个性能谜团，我尝试不断简化我的应用，直到它不再是一个字节码解释器，而只是一个统计从 stdin 读取的字节数的程序：

// src/main.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});
}

用简化后的应用，我仍然能看到性能差异。当我用 zig build run 运行字节计数器时，它在 13 微秒内完成：

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

而当我直接运行编译好的二进制文件时，耗时是前者的 12 倍，用时 162 微秒：

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

我的测试由 bash 管道中的三条命令组成：

1. echo 打印十个十六进制编码的字节（0x00、0x01……）。
2. xxd 把 echo 的十六进制编码字节转换成二进制编码字节。
3. zig build run 编译并执行我的字节计数器程序，统计 xxd 输出的二进制编码字节的个数。

zig build run 与 ./zig-out/bin/count-bytes 之间唯一的区别是，第二条命令运行的是已经编译好的应用，而第一条命令会重新编译应用。

我又一次被搞糊涂了。

一个额外的编译步骤怎么会让程序变得更快？Zig 应用难道是刚出炉的时候跑得更快？

向 Zig 社区求助

到了这一步，我被难住了。我把源代码反复读了好几遍，还是无法理解为什么“编译并运行一个应用”会比“运行已编译的二进制文件”更快。

Zig 还是一门很新的语言，所以肯定是我对 Zig 的某个方面理解有误。如果有经验丰富的 Zig 程序员看看我的代码，他们肯定能立刻发现我的错误。

我把问题发到了 Ziggit 上，这是 Zig 的一个讨论论坛。最初几条回复说我的问题出在“输入缓冲（input buffering）”上，但没有给出具体的修复或进一步排查的建议。

Zig 的创始人兼首席开发者 Andrew Kelly（安德鲁·凯利）在这个帖子里意外现身。他无法解释我看到的现象，但他指出我犯了另一个性能错误：

最终，我的朋友 Andrew Ayer（安德鲁·艾尔）在 Mastodon 上看到我关于此事的帖子，并解开了这个谜团：

Andrew Ayer 说得完全正确，我会在下面详细拆解。

题外话：Andrew Ayer 还曾凭借一个关键洞察解开了我上一个性能谜团。

我对 bash 管道的认知模型是错的

我从来没有仔细思考过 bash 管道，但 Andrew 的评论让我意识到我的认知模型是错的。

设想一条简单的 bash 管道，如下所示：

./jobA | ./jobB

我的认知模型是：jobA 先启动并运行到完成，然后 jobB 再启动，以 jobA 的输出作为输入。

事实是，bash 管道中的所有命令是同时启动的。

为了演示 bash 管道中的并行执行，我用两个简单的 bash 脚本写了一个概念验证。

jobA 启动后，睡眠三秒，向 stdout 打印内容，再睡两秒，然后退出：

#!/usr/bin/env bash

function print_status() {
    local message="$1"
    local timestamp=$(date +"%T.%3N")
    echo "$timestamp $message" >&2
}

print_status 'jobA is starting'

sleep 3

echo 'result of jobA is...'

sleep 2

echo '42'

print_status 'jobA is terminating'

下载 jobA

jobB 启动后，等待 stdin 上的输入，然后把能从 stdin 读到的一切打印出来，直到 stdin 关闭：

#!/usr/bin/env bash

function print_status() {
    local message="$1"
    local timestamp=$(date +"%T.%3N")
    echo "$timestamp $message" >&2
}

print_status 'jobB is starting'

print_status 'jobB is waiting on input'
while read line; do
  print_status "jobB read '${line}' from input"
done < /dev/stdin
print_status 'jobB is done reading input'

print_status 'jobB is terminating'

下载 jobB

如果我把 jobA 和 jobB 放在一条 bash 管道里运行，从 jobB is starting 到 jobB is terminating 两条消息之间恰好经过 5.009 秒：

$ ./jobA | ./jobB
09:11:53.326 jobA is starting
09:11:53.326 jobB is starting
09:11:53.328 jobB is waiting on input
09:11:56.330 jobB read 'result of jobA is...' from input
09:11:58.331 jobA is terminating
09:11:58.331 jobB read '42' from input
09:11:58.333 jobB is done reading input
09:11:58.335 jobB is terminating

如果我调整执行方式，让 jobA 和 jobB 顺序运行而不是通过管道，那么 jobB 的 starting 和 terminating 消息之间只经过 0.008 秒：

$ ./jobA > /tmp/output && ./jobB < /tmp/output
16:52:10.406 jobA is starting
16:52:15.410 jobA is terminating
16:52:15.415 jobB is starting
16:52:15.417 jobB is waiting on input
16:52:15.418 jobB read 'result of jobA is...' from input
16:52:15.420 jobB read '42' from input
16:52:15.421 jobB is done reading input
16:52:15.423 jobB is terminating

重新审视我的字节计数器

一旦我明白了 bash 管道中的所有命令都是并行运行的，我在字节计数器中看到的行为就说得通了：

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

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

看起来，管道中 echo '00010203040506070809' | xxd -r -p 这部分的运行时间约为 150 微秒。而 zig build run 这一步至少需要 150 微秒。

等到 zig build 版本中的 count-bytes 应用真正开始运行时，它已经不需要等待前面的任务完成了。输入早已在 stdin 上等着它。

而当我跳过 zig build 步骤、直接运行编译好的二进制文件时，count-bytes 立刻启动，计时器也随之开始。问题在于，count-bytes 必须干等着约 150 微秒，直到 echo 和 xxd 命令把输入送到 stdin。

修复我的基准测试

修复我的基准测试很简单。我不再把应用作为 bash 管道的一部分运行，而是把准备阶段和执行阶段拆成独立的命令：

# Convert the hex-encoded input to binary encoding.
$ INPUT_FILE_BINARY="$(mktemp)"
$ echo '60016000526001601ff3' | xxd -r -p > "${INPUT_FILE_BINARY}"

# Read the binary-encoded input into the virtual machine.
$ ./zig-out/bin/eth-zvm < "${INPUT_FILE_BINARY}"
execution time:  67.378µs

我的基准测试耗时从之前的 438 微秒降到了 67 微秒。

应用 Andrew Kelly 的性能修复

还记得 Andrew Kelly 指出我每读取一个字节就进行一次系统调用（syscall）吗？

var reader = std.io.getStdIn().reader();
...
while (true) {
      _ = reader.readByte() { // Slow! One syscall per byte
          ...
      };
      ...
  }

也就是说，每次我的应用在循环中调用 readByte 时，它都得暂停执行，向操作系统请求读取一个输入字节，然后等操作系统交付这单个字节后再恢复执行。

修复很简单。我必须使用带缓冲的读取器（buffered reader）。我不再一次从操作系统读取单个字节，而是改用 Zig 内置的 std.io.bufferedReader，它让我的应用一次从操作系统读取大块数据。这样，我只需进行一小部分的系统调用。

以下是完整的改动：

diff --git a/src/main.zig b/src/main.zig
index d6e50b2..a46f8fa 100644
--- a/src/main.zig
+++ b/src/main.zig
@@ -7,7 +7,9 @@ pub fn main() !void {
     const allocator = gpa.allocator();
     defer _ = gpa.deinit();

-    var reader = std.io.getStdIn().reader();
+    const in = std.io.getStdIn();
+    var buf = std.io.bufferedReader(in.reader());
+    var reader = buf.reader();

     var evm = vm.VM{};
     evm.init(allocator);

我重新运行了示例，性能又提升了 11 微秒，是一个 16% 的适度提速。

$ zig build -Doptimize=ReleaseFast && ./zig-out/bin/eth-zvm < "${INPUT_FILE_BINARY}"
execution time:  56.602µs

对更大输入进行基准测试

我的以太坊解释器目前只支持以太坊操作码的一个小子集。此刻，我的解释器能执行的最复杂的计算就是把数字相加。

例如，下面是一个以太坊应用，它通过把 1 压栈三次再把值相加，来数到三：

PUSH1 1    # Stack now contains [1]
PUSH1 1    # Stack now contains [1, 1]
PUSH1 1    # Stack now contains [1, 1, 1]
ADD        # Stack now contains [2, 1]
ADD        # Stack now contains [3]

我在基准测试中测试的最大应用，是一段通过不断累加 1 来数到 1,000 的以太坊字节码。

在 Andrew Kelly 的建议帮我减少了系统调用之后，我的“数到 1,000”应用的运行时间从 2,024 微秒降到了 58 微秒，提速 35 倍。我现在几乎以两倍的优势击败了官方以太坊实现。

用“作弊”手段冲击极限性能

看到我的 Zig 实现终于超越了官方 Go 版本，我很兴奋，但我想看看究竟能借助 Zig 把性能提升到什么程度。

软件中一个常见的瓶颈是内存分配，因为程序必须向操作系统请求内存，并在操作系统满足请求期间等待。

Zig 提供了一种叫做固定缓冲分配器（fixed buffer allocator）的内存分配器。这种分配器不向操作系统请求内存，而是由你提供一块固定大小的字节缓冲区，它只用这些字节来分配内存。

我可以通过编译一个限制在从栈上分配的 2 KB 内存内的以太坊解释器版本来给基准测试“作弊”：

diff --git a/src/main.zig b/src/main.zig
index a46f8fa..9e462fe 100644
--- a/src/main.zig
+++ b/src/main.zig
@@ -3,9 +3,9 @@ const stack = @import("stack.zig");
 const vm = @import("vm.zig");

 pub fn main() !void {
-    var gpa = std.heap.GeneralPurposeAllocator(.{}){};
-    const allocator = gpa.allocator();
-    defer _ = gpa.deinit();
+    var buffer: [2000]u8 = undefined;
+    var fba = std.heap.FixedBufferAllocator.init(&buffer);
+    const allocator = fba.allocator();

     const in = std.io.getStdIn();
     var buf = std.io.bufferedReader(in.reader());

我称之为“作弊”，因为我是针对我特定的基准测试进行优化的。当然存在需要超过 2 KB 内存的合法以太坊程序，但我只是好奇，借助这个优化我能跑多快。

我们来看看，如果我在编译期就知道最大内存需求，性能会是什么样：

$ ./zig-out/bin/eth-zvm < "${COUNT_TO_1000_INPUT_BYTECODE_FILE}"
execution time:  34.4578µs

很酷！使用固定内存缓冲后，我的以太坊实现运行“数到 1,000”的字节码只需 34 微秒，比官方 Go 实现快了近 3 倍。

结论

我从这次经历中得到的教训是：尽早且频繁地进行性能基准测试。

通过把基准测试脚本加入我的持续集成并归档结果，我很容易就能发现测量结果何时发生了变化。如果我把基准测试当作一项手动的、周期性的任务，那我就很难准确找出造成测量差异的原因了。

这次经历也凸显了理解你的指标的重要性。在遇到这个 bug 之前，我从没想过我的基准测试中包含了等待其他进程填充 stdin 的时间。

源代码

• eth-zvm：我用 Zig 实现的业余以太坊虚拟机