GET이 빠른데 서버는 느리다: KVS의 fsync와 Raft 대기열 측정

이전 글에서는 KVS의 append log와 Raft가 응답한 쓰기를 어떻게 보존하는지 다뤘다. 이번에는 그 약속을 지키는 데 드는 비용을 살펴보려 한다. 다만 성능을 비교하기 전에 메모리에서 값 하나를 읽는 비용을 잴 것인지, 200개 연결이 쓰기 응답을 기다리는 서버의 처리량을 잴 것인지부터 정할 필요가 있다.

KVS의 성능 문서에서 메모리 모드는 초당 약 21만 명령을 처리하지만 3노드 클러스터는 초당 435~437개에 그친다. 그런데 GET의 중앙값은 클러스터 쪽이 더 짧아 전체 처리량만 보면 느린 서버가 개별 읽기에서는 가장 빠른 셈이다.

참고로 이 글의 숫자는 모두 KVS 성능 문서에 정리해 둔 측정값이다. 측정은 벤치마크를 추가한 f57bc5b 다음, 사전 채우기를 고친 24cccb1에서 했고 본문의 소스 링크는 그 뒤 리비전 번호를 붙인 main의 b470020을 기준으로 한다.

측정 장비는 Apple M4 10코어, 메모리 16GB, 내장 SSD였고 macOS 26.6.2에서 Go 1.26.7과 memtier_benchmark 2.5.1을 사용했다. 다른 부하 없이 AC 전원을 연결한 상태에서 클러스터의 세 노드도 모두 이 기계에서 실행했으므로, 다음 수치에는 서로 다른 호스트 사이의 네트워크나 운영 환경의 디스크 경합이 포함되지 않는다.

함수 호출과 RESP 왕복을 나눠 보기

make bench에서는 스토어 함수, RESP 서버, 클러스터 쓰기를 각각 측정하며 문서에 실린 값은 BENCH_COUNT=6으로 실행한 여섯 번의 중앙값이다. 다만 RESP 패키지는 첫 실행에 다른 작업의 부하가 겹쳐 해당 패키지만 다시 실행한 결과를 사용했다.

메모리 GET의 62ns는 Go에서 스토어를 직접 호출한 비용이다. RESP GET의 약 14.5μs에는 클라이언트 라이브러리, TCP 왕복, RESP 파싱, 명령 실행, 응답 처리가 들어가므로 두 값은 측정 범위부터 다르다. loopback에서는 외부 네트워크 지연이 작아도 프로토콜을 통과하는 비용까지 사라지지는 않는다.

스토어 벤치마크는 키 1,000개를 반복해서 덮어쓰되, 읽기 전에 모든 키를 넣어 두고 키 이름도 미리 만들어 문자열 변환 비용을 반복 측정하지 않게 했다. 값도 작은 "value"를 사용해 큰 값을 복사하는 대역폭보다 명령 경로의 비용을 보는 조건으로 맞췄다.

RESP 벤치마크도 키 1,000개와 작은 값을 사용한다. 반면 클러스터 벤치마크는 루프 안에서 키 문자열도 만든다. 세 경로를 비교할 수는 있지만 바이트 단위까지 같은 일을 하는 측정으로 취급해서는 안 된다.

메모리 스토어의 병렬 결과에는 공유 잠금의 경합 비용도 들어가므로 값이 더 크다. 병렬 벤치마크의 ns/op는 전체 실행 시간을 처리한 연산 수로 나눈 값이라서, 클라이언트 한 요청의 응답 시간이나 p99로 읽을 수는 없다.

200개 연결을 붙였을 때

make memtier는 스토어 함수 대신 실행 중인 서버에 부하를 보내며 4개 스레드가 각각 50개 연결을 사용해 SET 하나에 GET 열 개를 보낸다. 값은 32바이트로 맞추고 미리 채운 키 공간에서 무작위 키를 골라 60초 동안 실행한다.

아래 시간의 단위는 밀리초다. p50은 중앙값, p99는 99백분위수이며 모두 클라이언트가 본 대기 시간을 포함한다. Ops/sec에는 SET과 GET이 함께 들어가므로 내구성 모드의 2,754 ops/sec를 초당 2,754번의 디스크 동기화로 해석하면 안 된다.

memory는 데이터 디렉토리가 없는 kvs serve, durable은 --data-dir을 더한 단일 노드이고 cluster에서는 같은 호스트의 세 노드를 Raft로 묶어 리더에 부하를 보낸다. 표에는 같은 조건에서도 결과가 얼마나 움직이는지 보려고 두 실행을 실었지만 두 번만으로 변동의 전체 범위를 알 수는 없다.

fsync를 포함한 쓰기 3.75ms가 응답 시간 758ms가 되는 이유

durable 모드에서는 스토어의 쓰기 잠금을 잡은 상태에서 변경을 append log에 기록하고 디스크에 동기화한 다음 응답한다. WriteRevision은 잠금을 잡은 채 쓰기를 수행하고 로그 기록 함수는 버퍼를 flush한 뒤 file.Sync()를 호출한다.

순차 벤치마크에서 이 경로에 걸린 약 3.75ms의 역수를 취하면 초당 약 267번이다. 문서는 쓰기 상한을 약 270번으로 설명한다. 3.75ms는 fsync 호출만 따로 잰 값이 아니라 로그 기록과 동기화를 포함한 Put 전체 시간이다. 연결을 더 붙이더라도 한 번에 잠금을 잡고 동기화하는 쓰기는 하나뿐이다.

200개 연결이 모두 쓰기 차례를 기다린다고 생각하면 200 × 3.75ms = 750ms이므로 실제 SET 중앙값인 754~758ms와 비슷한 규모가 된다. 잠금 스케줄을 정확히 재현한 공식은 아니지만 한 번의 작업 비용이 대기열에서 어떻게 커지는지 보는 근사 계산이다.

GET은 디스크에 가지 않더라도 읽기 잠금이 필요하므로 현재 fsync 중인 쓰기가 스토어를 잡고 있으면 읽기도 기다린다. GET 중앙값 약 4ms도 메모리 조회 자체의 비용보다 잠금 대기가 더 큰 조건에서 나온 값으로 읽을 수 있다.

쓰기 하나를 빨리 처리하더라도 기다리는 쓰기가 많으면 요청 지연은 커진다. 이 표에 나온 200개 연결의 요청 지연을 설명하려면 순차 벤치마크의 3.75ms에 대기 시간까지 고려해야 한다. 반대로 758ms를 쓰기 하나의 fsync 시간이라고 부르면 디스크 비용을 약 200배 크게 잡게 된다.

Raft를 기다리는 동안 GET은 빨라진다

클러스터의 순차 쓰기는 약 22.2ms이고 부하를 붙인 SET 중앙값은 약 4.9초다. 이 역시 순차 작업 비용과 많은 연결의 대기 시간을 나눠 봐야 한다. SET:GET 1:10 비율을 적용하면 표의 전체 처리량은 초당 약 40번의 SET에 해당한다. durable 모드와 같은 방식으로 계산하면 200 × 22.2ms ≈ 4.4초이므로, 실제 SET 중앙값 4.85~4.88초도 쓰기 차례를 기다린 시간으로 대부분 설명된다.

코드에서도 직렬화되는 위치가 다르다. Node.Write는 applyMu를 잡고 변경을 계산한 뒤 Raft에 넘기며 적용 결과를 기다릴 때까지 이를 유지한다. 스토어의 잠금은 변경을 계산할 때와 합의한 변경을 적용할 때 잡으며 합의를 기다리는 동안에는 유지하지 않는다. 디스크 동기화 내내 잠금을 유지하는 durable 모드와 다른 부분이다.

이때 클라이언트 연결은 자기 SET이 끝나야 다음 GET을 보내므로 여러 연결이 쓰기 차례를 기다리는 동안 서버에 들어오는 읽기 부하도 줄어든다. 문서는 클러스터 GET의 0.055ms를 노드가 쓰기를 기다리며 대부분의 시간을 보내고 읽기 앞에는 쌓인 일이 적기 때문이라고 설명한다.

KVS의 읽기는 각 노드의 로컬 상태를 사용하며 합의를 거치지 않지만 메모리 단일 노드도 읽기마다 합의를 하지 않으므로, 이 사실만으로 메모리 단일 노드보다 읽기가 빠른 이유를 설명할 수는 없다. 같은 200개 연결이라도 실제로 흘러 들어오는 읽기 요청의 양과 대기 조건이 다르다.

다만 GET만 계속 보내는 별도 부하를 측정하지 않았으므로 클러스터의 읽기 처리 용량이 더 큰지는 이 표로 알 수 없다. 로컬 읽기는 뒤처질 수 있으므로 읽기 시간이 짧아도 최신 값인지 확인하는 일은 별도로 필요하다.

먼저 채우지 않은 키 공간을 고치다

처음 벤치마크를 추가한 f57bc5b의 스크립트는 빈 스토어에 무작위 SET과 GET을 보냈는데, GET이 고를 수 있는 키를 먼저 넣지 않아 읽기 대부분이 값이 없는 경로를 통과했다. 사전 채우기를 고친 변경의 설명에 따르면 이전 durable 실행이 끝날 때 존재한 키는 약 12%, 클러스터는 약 2.5%뿐이었다.

이는 실행 전체의 GET 적중률을 직접 측정한 값이 아니라 실행 종료 시점의 키 공간 점유 비율이다. 쓰기 속도가 느릴수록 키 공간이 덜 채워졌다는 점에서 모드별 읽기를 같은 적중 조건으로 비교하지 못했음을 알 수 있다. 명령 비율은 같았어도 읽기 경로까지 같지는 않았던 셈이다.

수정한 스크립트는 memtier-0부터 memtier-100000까지 100,001개를 모두 넣는다. 끝값도 포함하므로 이름에 100,000이 들어가더라도 키 수는 100,001개다. 이후에는 만료나 삭제 없이 같은 키에 쓰고 읽으므로 GET이 채워진 키를 대상으로 동작한다.

사전 채우기는 키 1,000개씩 MSET으로 묶고 마지막 키 하나를 따로 보내므로 정확히는 101개의 MSET 명령이 된다. 주석의 “약 100번 쓰기”는 이 규모를 가리킨다. 키마다 SET을 보낼 때 필요한 100,001번의 fsync나 합의를 줄일 수 있는 것은 한 MSET이 같은 트랜잭션의 변경을 묶기 때문이다.

이 채우기는 memtier의 60초 측정 전에 끝내고 파이프 응답에 에러가 없는지도 확인한다. 수정 뒤의 성능 문서는 AC 전원 조건에서 다시 측정했으므로 이전 표와 새 표의 차이를 사전 채우기 하나의 효과로만 분리할 수는 없다. 이 글은 수정 후 표를 사용한다.

INFO의 숫자는 무엇을 세는가

벤치마크를 추가하면서 RESP의 INFO에도 연결 수, 명령 수, 메모리를 더했다. 부하를 관찰할 때 쓸 수 있는 값이지만 먼저 각 필드가 무엇을 세는지 확인할 필요가 있다. 구현은 연결과 dispatch 코드와 INFO 응답 코드에 있다.

명령 수는 핸들러를 부르기 전에 증가해 그 안에서 실패한 명령도 포함되므로, 성공한 쓰기 수나 Raft 커밋 수로 읽으면 안 된다. 알 수 없는 명령이나 잘못된 인자 수처럼 핸들러 이전에 거부한 요청은 포함하지 않는다. INFO 자체도 명령 하나다. MULTI에 넣은 명령은 큐에 넣을 때가 아니라 EXEC에서 실행할 때 세며 Lua 내부의 명령 호출도 포함한다.

명령 수의 차이로 처리율을 계산하면 사전 채우기, 준비 확인, INFO 조회까지 섞여 들어갈 수 있다. HTTP와 gRPC 요청까지 합친 전역 카운터도 아니다. used_memory는 살아 있는 객체와 아직 회수되지 않은 죽은 객체가 차지한 Go 힙이며 RSS나 키·값만의 크기가 아니다.

같은 질문으로 다시 실행하기

재현 명령은 성능 문서와 Makefile에 있다. 다음 명령은 KVS 저장소를 체크아웃한 디렉토리에서 실행한다.

1
2
3
4
5

brew install memtier_benchmark redis
make memtier BENCH_MODE=memory
make memtier BENCH_MODE=durable
make memtier BENCH_MODE=cluster
make bench BENCH_COUNT=10

make memtier는 dist/kvs를 빌드해 기본 RESP 포트 16379에 서버를 띄우되, 해당 포트에 이미 응답하는 서버가 있으면 중단한다. 다른 포트는 KVS_BENCH_PORT로 지정할 수 있고 클러스터에서는 주변 포트도 사용한다. 클러스터는 나머지 두 노드의 합류를 기다린 뒤 키를 채우고 부하를 시작한다.

실행 시간의 기본값은 BENCH_TIME=60이며 전체 결과는 dist/memtier-<mode>.json에 남긴다. 끝날 때는 시작한 프로세스와 임시 데이터 디렉토리를 정리하므로 데이터 디렉토리를 재사용하는 장기 실행 조건과는 다르다. 코드가 바뀐 두 빌드를 비교할 때는 같은 조건에서 Go 벤치마크를 반복하고 benchstat으로 비교할 수 있다.

이 측정은 작은 값, 정해진 키 공간, SET:GET 1:10, loopback을 사용한 조건이므로 큰 값, 트랜잭션, 실제 네트워크, 여러 디스크, 장애 중의 응답 시간을 대표하지 않는다. 샤딩이나 group commit, Raft 쓰기 파이프라이닝을 적용한 결과도 아니다.

정리

이번 측정으로 이후 변경을 비교할 기준이 생겼다. GET의 짧은 시간과 전체 처리량의 낮은 수치가 함께 나온 조건에서는 함수 자체의 비용뿐 아니라 어떤 작업이 직렬화되고 클라이언트가 언제 다음 요청을 보내는지도 확인해야 한다. KVS에서는 fsync와 Raft를 기다리는 연결이 많아지면서 사용자에게 보이는 쓰기 시간이 훨씬 길어졌다. 성능을 비교할 때도 연결 수와 명령 비율을 함께 맞추는 편이 좋겠다.

전체 소스 코드는 github.com/skyoo2003/kvs에서 확인할 수 있다.