지난 몇 달 동안 나는 두 가지 기술에 관심을 가져왔다. Zig 프로그래밍 언어와 이더리움 암호화폐가 그것이다. 두 기술을 더 깊이 배우기 위해 Zig로 이더리움 가상 머신용 바이트코드 인터프리터를 작성해 왔다.

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는 16진수로 인코딩된 10바이트 시퀀스(0x00, 0x01, …)를 출력한다.
2. xxd는 echo의 16진수 바이트를 바이너리 바이트로 변환한다.
3. zig build run은 내 바이트 카운터 프로그램을 컴파일하고 실행해 xxd가 출력한 바이너리 바이트 수를 센다.

zig build run과 ./zig-out/bin/count-bytes의 유일한 차이는 두 번째 명령어가 이미 컴파일된 앱을 실행하는 반면, 첫 번째 명령어는 앱을 다시 컴파일한다는 점이었다.

또다시 나는 어리둥절했다.

추가 컴파일 단계가 어떻게 프로그램을 더 빠르게 만들 수 있을까? Zig 앱은 갓 구워낸 직후에 더 빨리 실행되는 걸까?

Zig 커뮤니티에 도움 요청하기

이쯤 되니 완전히 막막했다. 소스 코드를 몇 번이고 다시 읽어봤지만, 애플리케이션을 컴파일해서 실행하는 것이 이미 컴파일된 바이너리를 실행하는 것보다 어떻게 더 빠를 수 있는지 이해할 수 없었다.

Zig는 아직 새로운 언어이니, 내가 뭔가 오해하고 있는 부분이 분명 있을 거라고 생각했다. 경험 많은 Zig 프로그래머들이 내 코드를 보면 즉시 실수를 찾아낼 것 같았다.

나는 Zig 토론 포럼인 Ziggit에 질문을 올렸다. 처음 몇 개의 답변은 내가 “입력 버퍼링”에 문제가 있다고 했지만, 해결하거나 더 조사할 구체적인 제안은 없었다.

Zig의 창시자이자 리드 개발자인 Andrew Kelly가 스레드에 깜짝 등장했다. 그는 내가 겪는 현상을 설명하진 못했지만, 내가 다른 성능 실수를 하고 있다고 지적했다:

마침내 내 친구 Andrew Ayer가 Mastodon에서 내 글을 보고 미스터리를 풀었다:

Andrew Ayer의 추측은 정확했고, 아래에서 자세히 풀어보겠다.

참고로 Andrew Ayer는 지난번 성능 미스터리를 해결한 핵심 통찰을 제시하기도 했다.

bash 파이프라인에 대한 내 머릿속 모델은 틀렸다

나는 bash 파이프라인에 대해 깊이 생각해 본 적이 없었는데, Andrew의 댓글 덕분에 내 머릿속 모델이 틀렸다는 걸 깨달았다.

다음과 같은 간단한 bash 파이프라인을 상상해 보자:

./jobA | ./jobB

내 머릿속 모델에서는 jobA가 시작해 끝까지 실행된 뒤, jobB가 jobA의 출력을 입력으로 받아 시작한다고 생각했다.

사실 bash 파이프라인의 모든 명령어는 동시에 시작된다.

bash 파이프라인에서의 병렬 실행을 보여주기 위해 두 개의 간단한 bash 스크립트로 개념 증명을 작성했다.

jobA는 시작해서 3초간 대기한 뒤 stdout에 출력하고, 다시 2초간 대기한 뒤 종료된다:

#!/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이 닫힐 때까지 읽을 수 있는 모든 내용을 출력한다:

#!/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가 echo와 xxd 명령어가 stdin으로 입력을 전달할 때까지 약 150마이크로초 동안 기다려야 한다는 점이다.

벤치마크 수정하기

벤치마크를 수정하는 건 간단했다. 애플리케이션을 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가 지적했듯이 나는 바이트 하나를 읽을 때마다 시스템 콜을 한 번씩 하고 있었다.

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

그래서 루프에서 내 애플리케이션이 readByte를 호출할 때마다 실행을 중단하고 OS에 입력 읽기를 요청한 뒤, OS가 한 바이트를 전달하면 다시 재개해야 했다.

수정 방법은 간단했다. 버퍼드 리더를 사용하면 됐다. OS에서 한 번에 한 바이트씩 읽는 대신, Zig에 내장된 std.io.bufferedReader를 사용해 OS에서 큰 덩어리 단위로 데이터를 읽도록 했다. 이렇게 하면 시스템 콜 횟수를 대폭 줄일 수 있다.

전체 변경 내용은 다음과 같다:

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을 세 번 푸시한 뒤 값을 더해 3까지 세는 이더리움 애플리케이션이다:

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를 활용해 성능을 얼마나 더 끌어올릴 수 있을지 궁금했다.

소프트웨어에서 흔한 병목 중 하나는 메모리 할당이다. 프로그램이 운영체제에 메모리를 요청하고 OS가 이를 충족할 때까지 기다려야 하기 때문이다.

Zig에는 고정 버퍼 할당자(fixed buffer allocator)라는 메모리 할당자가 있다. 메모리 할당자가 OS에 메모리를 요청하는 대신, 할당자에 고정된 바이트 버퍼를 제공하면 그 바이트만 사용해 메모리를 할당한다.

스택에서 할당된 2KB 메모리로 제한된 이더리움 인터프리터 버전을 컴파일해 벤치마크에서 꼼수를 쓸 수 있다:

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());

이는 내 특정 벤치마크에만 최적화한 것이므로 “꼼수”라고 부른다. 분명 2KB 이상의 메모리를 필요로 하는 유효한 이더리움 프로그램도 있지만, 이 최적화로 얼마나 빨라질 수 있는지 궁금할 뿐이다.

컴파일 시점에 최대 메모리 요구량을 안다면 성능이 어떻게 달라지는지 보자:

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

오! 고정 메모리 버퍼를 사용하자 내 이더리움 구현은 “1,000까지 세기” 바이트코드를 34마이크로초 만에 실행해 공식 Go 구현보다 거의 3배 빨라졌다.

결론

이번 경험에서 얻은 교훈은 성능 벤치마크를 일찍, 그리고 자주 해야 한다는 것이다.

벤치마킹 스크립트를 지속적 통합에 추가하고 결과를 보관해 두니 측정값이 언제 변했는지 쉽게 파악할 수 있었다. 만약 벤치마킹을 수동으로 주기적으로 수행하는 작업으로만 뒀더라면 측정값 차이의 원인을 정확히 파악하기 어려웠을 것이다.

이번 경험은 또한 자신의 지표를 이해하는 것이 얼마나 중요한지를 보여준다. 이 버그를 만나기 전까지는 내 벤치마크에 다른 프로세스가 stdin을 채울 때까지 기다리는 시간이 포함되어 있다는 사실을 생각하지 못했다.

소스 코드

• eth-zvm: Zig로 구현한 취미용 이더리움 가상 머신