"내 프로그램이 2.5배나 털렸다고?" 충격받고 성능 뜯어고친 개발자 썰

요약 초고속 코드 라인 수 측정 도구로 널리 알려진 오픈소스 프로그램 'scc(Sloc Cloc and Code)'의 개발자가 경쟁 도구의 등장에 자극받아 성능을 대대적으로 뜯어고친 일화를 공개했습니다. 발단은 scc의 깃허브(GitHub)에 올라온 한 이슈 제기였습니다. 새롭게 등장한 코드 카운터 'mezura'가 엄청난 속도를 자랑한다는 제보를 접한 개발자는 직접 리눅스 커널 소스코드를 대상으로 벤치마크 테스트를 돌려보았습니다. 그 결과 scc는 약 512ms가 걸린 반면, mezura는 200ms 만에 작업을 끝마쳐 약 2.5배나 빨랐습니다. 개발자는 영화 '카우보이의 노래' 속 총잡이 버스터 스크러그스처럼 순식간에 한 수 위의 총잡이에게 당한 기분(Buster Scrugged)을 느꼈다고 밝혔습니다. 그는 자존심을 상해하기보다 '나보다 빠른 도구는 모욕이 아니라 프로파일러(분석 기회)로 삼아야 한다'며 다음 날 아침 본격적인 원인 분석에 나섰습니다. 복잡도 계산 옵션을 끄고 실행 시간을 비교해도 scc(445ms)가 mezura(203ms)보다 여전히 두 배 이상 느렸기 때문입니다. 개발자는 mezura의 소스코드를 훔쳐보는 대신 리눅스 시스템 콜 추적 도구인 strace를 사용해 두 프로그램의 시스템 호출 패턴을 비교했습니다. 분석 결과 mezura가 약 51만 번의 시스템 콜을 호출하는 동안 scc는 무려 134만 번(약 2.6배)이나 호출하고 있었습니다. 특히 스레드 대기/동기화와 관련된 futex 호출이 13만 번 이상 발생했고, epoll_ctl 호출은 9만 5천 번 넘게 실패하고 있었으며, fcntl과 newfstatat 호출도 과도하게 발생하고 있었습니다. 가장 먼저 병목이 확인된 곳은 내부 파이프라인 구조였습니다. 파일 탐색 고루틴은 8개나 돌고 있었지만 파일 정보를 검사하는 고루틴이 단 하나뿐이어서 큐가 꽉 막히고 스레드 경합(futex)이 극심했던 것입니다. 검사 고루틴을 병렬화하자마자 futex 호출이 5,500회 수준으로 급감하고 실행 시간이 160ms나 단축되는 극적인 성과를 거두었습니다. 이어서 Go 런타임이 리눅스 일반 파일에 대해 os.Open 시 불필요한 시스템 콜을 유발하는 문제 등 세부적인 시스템 콜 최적화 작업으로 이어졌습니다.