본문으로 건너뛰기
글 목록으로 돌아가기
이 글 목차
~/posts/devops

언어가 다른 CLI의 시작 시간, 정직하게 재보기

Rust로 다시 쓰면 Node script보다 5~10배는 빠를 줄 알았어요. 막상 재보니 1.3배 정도였는데 그 차이에서 배운 게 더 많았어요. 기준점을 되살리고, 입력을 고정하고, 차이가 어디서 났는지 따져본 이야기예요.

codex-hud에서 status line을 그리는 부분을 Node script에서 Rust binary로 다시 썼어요. 그때 머릿속엔 이미 숫자가 하나 있었어요. 5~10배요. Rust는 compile되고 Node는 V8부터 띄워야 하니까 굳이 확인할 필요도 없어 보이는 결론이었죠. 그런데 실제로 재보니 처음부터 끝까지 걸린 시간은 1.3배 정도 차이였어요.

재미있는 건 제가 짐작한 값과 측정한 값 사이의 거리예요. 다시 쓴 쪽이 더 나은 건 맞지만 제가 자랑하려던 이유 때문은 아니었어요. README에 “5배 빠름”이라고 적어 내보냈다면 누군가 직접 돌려보고 금방 알아챘을 거예요. 그래서 재현 명령어와 나란히 적어도 부끄럽지 않을 숫자를 만들기까지 뭘 했는지 정리해 봤어요.

다시 쓴 코드의 측정이 조용히 거짓말하는 세 가지 방식

세 가지 모두 스스로는 꽤 엄밀하다고 느끼면서 빠지기 쉬워요.

기준점이 없어요. 예전 구현은 다시 쓰는 시점에 지워졌어요. 작업 tree에 A/B로 견줄 대상이 남아 있지 않으니, “새 쪽이 빠르겠지” 하고 넘어가는 게 제일 편한 길이 돼요. 하지만 짐작에 측정의 옷만 입히면 근거는 하나도 없이 숫자가 주는 권위만 챙기게 돼요.

입력이 공평하지 않아요. config와 환경 변수를 다르게 읽는 두 binary는 같은 측정 loop 안에서도 서로 다른 양의 일을 아무렇지 않게 해내요. 초시계는 그런 걸 신경 쓰지 않죠. 그래서 정밀해 보이는 배수가 하나 나오는데 실은 사과와 오렌지를 견주고 있어요.

차이의 원인을 잘못 짚어요. 짧게 떴다 사라지는 CLI는 전체 시간 중 상당 부분을 공통 I/O(git 실행, log 읽기)에 써요. 이 부분은 두 구현이 똑같이 해요. 그런데도 차이 전부를 “새 언어가 빠르니까”로 돌리면 읽는 사람이 직접 profiling해 보는 순간 제일 먼저 무너지는 주장이 돼요.

기준점 되살리기

예전 renderer는 tree에서는 사라졌지만 history에는 남아 있었어요. 그래서 비용이 꽤 다른 선택지가 세 개 생겼어요.

선택지얻는 것치르는 비용
새 쪽이 빠르다고 가정하기숫자 하나, 즉시가치가 없어요. 명령어 하나로 반박당할 수 있어요
예전 file을 repo에 되살리기진짜 A/B언젠가 지워야 할 낡은 두 번째 구현이 남아요
실행 시점에 history에서 꺼내기진짜 A/B, 치울 것 없음history가 있어야 해요(shallow clone에는 없어요)

세 번째를 골랐어요. 측정 script가 삭제 commit 직전 commit에서 예전 구현을 꺼내 임시 directory에 쓰기 때문에, repo에는 낡은 흔적이 전혀 남지 않아요.

// LEGACY_REF = "<removal-commit>^"  (parent of the "remove legacy X" commit)
const src = execFileSync("git", ["show", `${LEGACY_REF}:${LEGACY_PATH}`], {
  encoding: "utf8"
});
fs.writeFileSync(path.join(tmpDir, "legacy.js"), src);

맞는 ref를 찾는 게 유일하게 손이 가는 부분이에요. git log --diff-filter=D --oneline -- <path>로 해당 경로를 지운 commit들을 나열해요. 삭제 commit의 부모(^)가 그 file을 마지막으로 갖고 있던 commit이고 이게 바로 git show <ref>:<path>에 넣어야 할 값이에요. 복구를 best-effort로 만드는 것도 중요해요. history를 못 쓰는 상황이면 그냥 실패하는 대신 새 구현만 재는 쪽으로 물러나서, CI checkout에서도 계속 돌아가게 했어요.

여기서 남는 건 습관이에요. 예전 구현은 대개 git show 한 번 거리에 있으니까, “이전 버전은 이미 지웠는데요”는 비교를 건너뛸 이유가 되기 어려워요.

입력을 고정해야 비교가 성립해요

기준점을 확보했으면 다음 질문은 두 binary가 정말 같은 일을 하고 있느냐예요. 이번엔 그렇지 않았어요. 그것도 꽤 자주요.

renderer는 config를 네 겹으로 쌓아서 찾아요. 환경 변수, 현재 directory에서 위로 올라가며 찾는 project 단위 file, home directory의 file, 그리고 내장 기본값 순서예요. 어디서 실행하든 잘 동작해야 하는 도구에는 합리적인 설계지만 측정에는 그대로 독이 돼요. 어디서 돌렸느냐에 따라 출력이 달라지니까요. 우선순위가 가장 높은 곳을 고정하면 이 모호함이 사라져요.

const env = { ...process.env, CODEX_HUD_CONFIG: pinnedConfigPath };

그다음 script는 출력이 같다고 가정하는 대신 직접 확인해요. 둘 다 돌려서 stdout을 비교하고 고정한 입력에서 byte 단위로 똑같을 때만 공정한 비교라고 인정해요.

이건 이론적인 대비가 아니었어요. 어떤 shell에서는 출력이 완전히 같았는데 다른 shell에서는 달랐거든요. 같은 binary 둘, 다른 작업 directory, 그래서 다르게 잡힌 codex-hud.toml, 그리고 한 field가 한쪽에서는 xh로 다른 쪽에서는 xhigh로 찍혔어요. 딱 봐서는 renderer의 표시 문제 같지만 아니었어요. config를 어디서 읽었느냐가 만든 차이였고 config를 고정하자 10번 중 10번 같은 출력이 나오면서 사라졌어요.

출력이 일치하느냐는 binary 못지않게 재는 환경에 달려 있어요. 원할 때마다 같은 출력을 만들어내지 못한다면 그 측정이 뭘 재고 있는지 아직 모르는 거예요.

차이를 뭉뚱그리지 말고 어디서 났는지 따지기

마지막 함정이 이야기를 바꿔놨어요. script는 명령 하나만 재서 배수를 내는 대신, binary마다 두 가지 경로를 재요.

  • 일을 안 하는 경로(--help--version): process 생성과 언어 runtime 시작 시간만 떼어내요.
  • 실제로 일하는 경로: 시작 시간에 더해, 두 구현이 똑같이 하는 공통 I/O까지 포함해요.

제 machine에서 나온 대략적인 결과예요.

경로NodeRust차이
--help(시작 시간만)~22 ms~1.5 ms~20 ms
전체 출력(시작 + git + log 파싱)해당 없음해당 없음~20 ms
전체 출력 안의 공통 작업~54 ms~54 ms~0

확인할 건 (node_help - rust_help)(node_full - rust_full)과 비슷하냐예요. 두 차이가 맞아떨어지면 호출 한 번당 이득은 runtime 시작 시간에서 나온 거예요. 공통 작업은 두 구현이 똑같이 치르는 상수니까요. 처음부터 끝까지 잰 수치가 1.34배에 그친 이유도 여기 있어요. git 실행과 log 파싱에 드는 54 ms 정도가 양쪽에 나란히 얹히면서 실제로 벌어둔 20 ms를 희석해 버려요.

이렇게 쪼개고 나면 “Rust가 1.3배 빠르다”와 “Rust는 그릴 때마다 Node의 20 ms 남짓한 cold start를 건너뛴다”는 같은 측정을 가리켜요. 다만 방어할 수 있는 쪽은 두 번째고 읽는 사람 환경에서 무슨 일이 벌어질지 알려주는 쪽도 두 번째예요.

측정 코드 자체도 배수를 왜곡하고 있었어요

왜곡이 하나 더 있는데 이번엔 측정 대상이 아니라 재는 쪽에서 나와요. 부모 Node process에서 spawnSync로 각 binary를 재면 거의 일정한 부담 C가 양쪽에 함께 얹혀요. 그래서 보고되는 값은 (node + C) / (rust + C)가 되고 배수는 1.0 쪽으로 끌려가요. 실제보다 부풀려지는 게 아니라 줄어드는 방향이라 마음은 편하지만, 틀린 건 틀린 거예요.

차이는 측정 코드를 통과해도 살아남지만 배수는 그렇지 않아요. 배수보다 차이를 보고하는 게 낫다는 근거이고 한발 더 나가면 exec로 binary를 직접 재거나 hyperfine 같은 전용 도구에 맡기는 게 낫다는 근거예요. hyperfine은 warmup 실행과 이상치 판별을 알아서 해주니까 숫자 몇 개를 눈대중으로 볼 일이 줄어요.

배수가 불안정한 이유는 또 있었어요. 한자리에 앉아 있는 동안 session log가 쌓이자 전체 출력 수치가 1.34배에서 1.49배로 움직였어요. 같은 binary, 같은 machine인데 파싱할 데이터만 늘어난 거예요. 시작 시간 차이는 전혀 움직이지 않았고요. 작업 directory 상태에 따라 흔들리는 숫자는 README에 박아둘 숫자가 아니에요.

배수 대신 공개한 것

이 과정을 다 거치고 살아남은 결론은 처음 하려던 자랑보다 훨씬 좁아요.

저는 보수적인 쪽 수치를 재현 방법과 함께 적었어요. “참고용, 단일 machine, N회 실행의 중앙값, <cmd>로 재현” 정도의 문구예요. 그래야 직접 돌려본 사람이 같거나 더 나은 결과를 보지, 더 나쁜 결과를 보지 않아요. 하한선을 내세우면 놀랄 일이 생겨도 기분 좋게 놀라게 되죠.

측정 자체도 한 번 쓰고 버리는 session이 아니라 다시 돌릴 수 있는 script로 넣었어요. 코드가 바뀌어도 공개한 숫자가 계속 정직하게 남고 미심쩍은 사람이 제 말을 믿지 않고도 직접 확인할 수 있으니까요.

내세우는 문장도 바뀌었어요. 속도 배수 대신, 측정이 실제로 뒷받침하는 내용으로요. native binary는 그릴 때마다 Node의 20 ms 남짓한 cold start를 건너뛰고, runtime 의존성 없이 574 KB 남짓한 binary 하나로 배포돼요. 사실 구조에 관한 이야기가 처음부터 더 강한 주장이었는데 부풀린 숫자가 그걸 가리고 있었어요.

이만큼 공들일 만한 경우

이 정도 절차가 어울리는 상황은 좁아요. 다시 쓴 코드의 성능을 공개적으로 내세워야 하고 그 주장이 검증을 견뎌야 할 때, “새 버전이 정말 더 빠른가?”에 답해야 하는데 예전 버전이 아직 git history에 남아 있을 때, 그리고 process 시작 시간이 전체 시간에서 무시 못 할 비중을 차지하는 짧은 CLI나 hook, status line 같은 경우예요.

반대로 어울리지 않는 곳도 분명해요. 오래 떠 있는 service라면 시작 시간은 잡음이고 정상 상태의 처리량과 p99 지연이 의미 있는 숫자예요. 입력을 고정할 수 없는 진짜 비결정적 작업이라면 공정성을 확보할 방법 자체가 없으니, 배수 하나 대신 분포를 보여주는 게 맞아요. 그리고 정직하게 잰 차이가 내세우기엔 너무 작다면 속도를 앞세우는 걸 그만두는 게 나아요. 구조 이야기(native binary 하나, runtime 의존성 없음)를 먼저 하고 성능은 뒤를 받치는 자리에 두면 돼요.

정리하면

믿을 만한 주장 하나를 만든 방법은 세 단계였고 특별할 건 하나도 없어요. 짐작하지 말고 진짜 기준점을 되살리기, 출력이 byte 단위로 같아질 때까지 입력을 고정하기, 그리고 시작 시간과 공통 작업을 갈라놓아서 언어가 실제로 기여한 몫만 언어에게 돌리기. 제가 틀렸던 지점은 원하는 숫자를 먼저 정해두고 그걸 뒷받침할 측정을 찾은 거예요. 먼저 재고 나니 숫자는 작아졌지만 이야기는 더 좋아졌어요.

참고 자료

  • hyperfine: warmup 실행과 통계적 이상치 판별을 지원하는 command line 측정 도구. 직접 만든 측정 코드보다 이쪽이 나아요
  • git log: --diff-filter=D로 특정 경로를 지운 commit을 골라내요. 사라진 기준점을 찾는 첫 단계예요
  • git show: 특정 revision의 blob을 출력해요. 작업 tree를 건드리지 않고 예전 구현을 되살리는 방법이에요
  • child_process: execFileSyncspawnSync 문서예요. Node로 만든 측정 코드에 일정한 부담을 더하는 동기 spawn 동작도 여기 나와요

댓글

글 목록으로 돌아가기
enko