벤치마크가 거짓말하는 세 가지 방식 — Rust CLI를 실제로 재보고 진 이야기

들어가며

앞의 네 편에서 kgrep을 만들었습니다. CJK 텍스트에서 컬럼 번호를 바이트가 아니라 문자로 세는 검색 도구입니다. 이제 남은 일은 배포하고, 얼마나 쓸 만한지 재보는 것입니다.

결론부터 적습니다. ripgrep이 제 도구보다 약 10배 빨랐습니다. 제 도구는 macOS 기본 grep과 비슷한 수준입니다.

그리고 이 문장에 도달하기까지, 틀린 벤치마크를 세 번 통과했습니다. 세 번 다 숫자가 나왔고, 세 번 다 그럴듯했고, 세 번 다 틀렸습니다. 이 글의 절반은 그 이야기입니다. 벤치마크를 돌려본 사람보다 벤치마크에 속아본 사람의 기록이 더 쓸모 있다고 생각하기 때문입니다.

1. 릴리스 빌드와 바이너리

먼저 배포용 빌드입니다.

cargo build --release

Finished `release` profile [optimized] target(s) in 7.56s

바이너리 크기는 이렇게 갈립니다.

디버그 빌드가 4배입니다. 디버그 정보와 최적화 미적용이 그만큼을 차지합니다. 2.4M도 C로 짠 같은 기능의 도구보다는 큰데, Rust 표준 라이브러리를 정적으로 링크하기 때문입니다. 이건 트레이드오프지 결함이 아닙니다 — 대신 대상 머신에 런타임을 깔지 않아도 됩니다.

2. 비교하기 전에 확인해야 하는 것

벤치마크에서 시간을 재기 전에 해야 할 일이 하나 있습니다. 세 도구가 같은 일을 했는지 확인하는 것입니다.

이걸 건너뛰면 "우리 도구가 10배 빠릅니다"가 "우리 도구는 절반만 검색했습니다"의 다른 표현일 수 있습니다. 실제로 제 첫 측정이 그랬습니다.

그래서 세 도구를 모두 파일 목록 모드로 맞췄습니다. kgrep -l, rg -l, grep -rl 은 전부 "패턴이 들어 있는 파일 이름만 출력"입니다. 출력 줄 수가 곧 매칭된 파일 수이므로, 세 값이 같으면 같은 일을 한 것입니다.

처음엔 이렇게 맞추지 않았습니다. kgrep은 매치마다 한 줄, grep -rn은 매칭된 줄마다 한 줄을 출력합니다. 한 줄에 패턴이 두 번 나오면 숫자가 달라집니다. 그래서 3464 대 2972라는 무의미한 비교가 나왔습니다. 두 도구가 서로 다른 것을 세고 있었을 뿐입니다.

3. 조건

측정 조건을 먼저 적습니다. 조건 없는 벤치마크는 숫자가 아니라 주장입니다.

• 데이터: 이 블로그의 data/blog — MDX 11,483개, 302MB. 대부분 한국어이고 일본어·중국어·영어가 섞여 있습니다.
• 머신: Apple Silicon Mac, macOS.
• 캐시: 측정 전에 전체 파일을 한 번 읽어 페이지 캐시를 데웠습니다. 콜드 캐시 측정이 아닙니다.
• 횟수: 각 3회, 최저값 채택.
• 도구 버전: ripgrep 15.2.0, /usr/bin/grep (BSD grep 2.6.0-FreeBSD), kgrep 0.1.0 릴리스 빌드.

4. 실제 숫자

한국어 패턴 커널:

ASCII 패턴 kubernetes:

세 도구의 파일 수가 각각 504와 1191로 일치합니다. 같은 일을 했다는 뜻이고, 그래서 시간 비교가 성립합니다.

ripgrep이 9~10배 빠릅니다. 제 도구는 BSD grep과 비슷하고, 한국어 패턴에서 약간 앞섭니다.

5. 왜 졌는지, 그리고 그게 왜 정상인지

이 결과를 좋게 포장할 방법이 몇 가지 있습니다. "동등한 조건에서는", "특정 패턴에서는" 같은 말을 붙이면 됩니다. 그러지 않겠습니다. 진 이유가 분명하고, 그 이유를 아는 것이 이 시리즈에서 얻을 수 있는 실제 지식이기 때문입니다.

ripgrep이 빠른 이유는 Rust로 짜여서가 아닙니다. 제 도구도 Rust입니다. 차이는 구현에 들어간 공학입니다.

• 리터럴 검색에 SIMD를 씁니다. 제 구현은 str::find를 부릅니다. 표준 라이브러리 구현도 나쁘지 않지만, ripgrep은 패턴 특성에 따라 전용 경로를 고릅니다.
• 디렉터리 순회가 병렬입니다. 제 구현은 단일 스레드로 걸어가며 한 파일씩 읽습니다. 11,483개 파일에서 이 차이는 그대로 벽시계 시간이 됩니다.
• 파일을 메모리 맵으로 읽습니다. 제 구현은 std::fs::read로 통째로 읽어 String으로 변환합니다. UTF-8 검증 비용이 파일마다 붙습니다.

즉 제가 진 것은 언어 때문이 아니라 10년 다듬은 도구와 하루 만에 만든 도구의 차이입니다. 이건 예상된 결과고, 예상된 결과를 예상대로 보고하는 것이 벤치마크의 목적입니다.

6. 벤치마크가 거짓말한 세 가지 방식

이제 본론입니다. 위 표에 도달하기 전에 세 번 틀린 숫자를 얻었습니다.

6-1. 측정 대상이 그 도구가 아니었다

첫 측정에서 ripgrep이 이렇게 나왔습니다.

rg  best-of-3: 0.025s  files: 0

0.025초에 0개 파일. 압도적으로 빠른 것처럼 보이지만, 실은 검색을 하지 않은 것입니다.

원인을 찾다가 이걸 발견했습니다.

which rg

경로가 나올 자리에 셸 함수 본문이 출력됐습니다. 이 셸에서 rg와 grep은 실제 바이너리가 아니라 다른 프로그램으로 넘기는 셸 함수였습니다. 그리고 그 함수는 하위 셸(bash -c) 안에서는 정의되지 않으므로, 제 벤치마크 스크립트 안에서는 command not found로 조용히 실패하고 있었습니다. 종료 코드는 127이었지만 저는 2>/dev/null로 그걸 버리고 있었습니다.

더 나쁜 건 이겁니다. 그 shim은 --version에 ripgrep 14.1.1이라고 답했습니다. 나중에 진짜 ripgrep을 설치해보니 15.2.0이었습니다. 버전 문자열조차 확인용으로 쓸 수 없었던 겁니다.

교훈: 벤치마크에서는 도구를 이름이 아니라 절대 경로로 부릅니다. /opt/homebrew/bin/rg, /usr/bin/grep. 이름은 alias, 함수, PATH 순서에 따라 다른 것을 가리킬 수 있습니다.

6-2. 타이머가 프로세스 기준이었다

두 번째 하니스에서는 이런 값이 나왔습니다.

kgrep  best-of-3: -0.007s
rg     best-of-3: -0.000s

음수입니다. 시간이 거꾸로 흐르지 않았으니 측정이 틀린 것입니다.

원인은 이 코드였습니다.

s=$(python3 -c 'import time;print(time.perf_counter())')
"$@" > out.txt
e=$(python3 -c 'import time;print(time.perf_counter())')

perf_counter()는 임의의 기준점에서 잰 값이고, 그 기준점은 프로세스마다 다릅니다. python3를 두 번 따로 띄웠으니 서로 다른 기준의 두 값을 뺀 셈입니다. 차이가 음수로 나온 건 오히려 다행이었습니다 — 양수가 나왔다면 그럴듯해서 그냥 썼을 겁니다.

교훈: 말이 안 되는 값이 나오면 그 값만 고치지 말고 측정 방법을 의심합니다. 음수 시간은 눈에 띄지만, 같은 버그가 0.3초라는 그럴듯한 값을 낼 수도 있었습니다.

6-3. 타이밍 출력을 스스로 버렸다

세 번째는 이랬습니다.

kgrep  runs:      best s   files 504

파일 수는 맞는데 시간이 전부 비었습니다. 문제의 코드입니다.

t=$( { /usr/bin/time -p "$@" > out.txt 2>/dev/null ; } 2>&1 | awk '/^real/{print $2}' )

/usr/bin/time은 측정 결과를 자기 stderr로 출력합니다. 그런데 중괄호 안의 2>/dev/null이 명령의 stderr와 time의 stderr를 함께 버렸습니다. 바깥의 2>&1이 붙잡을 것이 남아 있지 않았습니다.

고친 형태는 이렇습니다. 명령의 출력과 타이밍을 다른 파일로 분리합니다.

/usr/bin/time -p "$@" > /tmp/out.txt 2> /tmp/timing.txt
awk '/^real/{print $2}' /tmp/timing.txt

교훈: 2>/dev/null은 벤치마크에서 특히 위험합니다. 잡음을 지우려다 신호를 지웁니다. 이 세션에서 저는 같은 실수를 다른 곳에서도 했습니다 — 파일 목록을 검사하는 명령에 2>/dev/null을 붙여둔 탓에, 파일 경로가 잘못 전달되어 아무것도 검사하지 못한 상태가 "이상 없음"으로 보고됐습니다.

7. 세 버그의 공통점

세 버그는 원인이 다르지만 증상이 같습니다. 모두 숫자를 출력했고, 모두 그럴듯했습니다.

• 0.025초 / 0개 파일 → "엄청 빠르네"로 읽힐 수 있었습니다
• 음수 → 이번엔 눈에 띄었지만, 부호가 반대였다면 그냥 썼을 겁니다
• 빈 값 → 파일 수가 맞아서 "대체로 잘 돌았다"로 보였습니다

그래서 저는 벤치마크의 첫 번째 검사를 시간이 아니라 결과의 일치로 잡습니다. 세 도구가 같은 504라는 숫자를 낼 때까지는 시간을 보지 않습니다. 결과가 다르면 시간은 의미가 없고, 결과가 같으면 최소한 같은 일을 놓고 비교하는 것이 됩니다.

그리고 두 번째 검사는 결과가 너무 좋으면 의심하는 것입니다. 자기 도구가 성숙한 도구를 큰 차이로 이겼다면, 축하하기 전에 하니스를 먼저 봐야 합니다. 제 경우 그 "승리"는 상대가 실행되지 않았다는 뜻이었습니다.

8. 설치와 배포

마지막으로 실제 배포입니다.

cargo install --path .

~/.cargo/bin에 설치되고, 그 경로가 PATH에 있으면 바로 쓸 수 있습니다. 크로스 컴파일은 rustup target add로 대상을 추가한 뒤 --target을 주는 방식인데, 이 글에서는 실제로 해보지 않았으므로 자세히 쓰지 않겠습니다. 해보지 않은 것은 해본 것처럼 쓰지 않는 것이 이 시리즈의 규칙입니다.

막혔던 곳

가장 오래 막힌 건 코드가 아니라 측정이었습니다. 도구 자체는 하루 만에 돌았고, 믿을 수 있는 숫자를 얻는 데 그보다 오래 걸렸습니다.

돌아보면 순서가 잘못됐습니다. 저는 벤치마크를 먼저 돌리고 나중에 검증했습니다. 반대로 했어야 합니다 — 하니스가 알려진 답을 내는지부터 확인하는 것입니다. 예를 들어 파일 하나에 패턴 하나를 넣고 세 도구가 모두 1을 반환하는지 봤다면, 셸 함수 문제를 첫 5분 안에 잡았을 겁니다.

마치며

이 시리즈의 목표는 Rust를 잘한다고 주장하는 것이 아니라, 만들어보고 무슨 일이 있었는지 적는 것이었습니다. 그래서 결론도 그대로 적습니다.

제 도구는 ripgrep보다 10배 느립니다. 그리고 그 사실을 알아내는 과정에서 벤치마크 하니스에 세 번 속았습니다.

둘 중에 더 오래 남을 지식은 후자라고 생각합니다. 10배라는 숫자는 제 구현이 나아지면 바뀌지만, 숫자를 출력한 벤치마크와 무언가를 측정한 벤치마크는 다르다는 사실은 바뀌지 않습니다. 그리고 그 차이를 알아채는 첫 신호는 대개, 결과가 너무 좋다는 것입니다.

이어서 읽기

• 이전 — 에러 처리, 테스트, 그리고 쓸 만한 CLI
• 리눅스 성능 도구 완전 가이드 — 같은 종류의 "숫자를 어떻게 읽을 것인가" 문제를 시스템 도구 쪽에서 다룹니다.