Kafka Broker가 느려졌지만 Kafka가 원인은 아니었다

Kafka 장애를 볼 때 가장 먼저 보이는 것은 보통 Kafka 지표입니다.

broker throughput이 줄고, under replicated partition이 늘고, ISR shrink가 보이고, 특정 broker가 다른 broker보다 유난히 느려 보입니다. 그러면 자연스럽게 Kafka 안에서 원인을 찾기 시작합니다. broker log, controller event, JVM, GC, network thread, request handler, replica fetcher, partition leadership 같은 것들을 차례대로 봅니다.

그런데 가끔 Kafka 지표는 원인이 아니라 증상입니다.

한 번은 12대 정도로 구성된 Kafka cluster에서 특정 broker의 throughput이 갑자기 줄어드는 일이 있었습니다. 그 broker가 follower replica를 들고 있던 partition들 중 일부가 leader를 따라가지 못했고, 결과적으로 ISR에서 빠지는 partition들이 생겼습니다. 일부 partition에서는 client 요청 처리량도 함께 흔들렸습니다.

처음에는 Kafka replication 문제처럼 보였습니다. 하지만 broker log와 JVM 지표에서는 결정적인 오류가 보이지 않았습니다. 추적을 계속하다 보니 Kafka가 아니라 그 아래 계층의 신호가 이상했습니다. 해당 broker VM에서 CPU iowait, /proc/meminfo의 Dirty와 Writeback, 그리고 block device write latency 계열 지표가 평소와 다르게 움직이고 있었습니다.

더 내려가 보니 broker VM들이 사용하는 block storage가 local disk가 아니라 network storage였고, storage backend 경합에서 밀린 broker가 Kafka 위에서는 느린 broker처럼 보였던 것이었습니다.

이 글은 그 경험을 바탕으로, Kafka 문제처럼 보이는 현상을 어떻게 storage path까지 따라가야 하는지 정리합니다. 핵심은 단순합니다.

운영 시스템은 한 계층의 지표로 설명되지 않는다.
요청은 애플리케이션에서 시작해 OS, block device, hypervisor, network, storage backend까지 이어진다.

처음에는 Kafka 문제처럼 보였다

현상만 놓고 보면 Kafka 내부 문제처럼 보였습니다.

• 특정 broker의 produce/fetch throughput이 줄었습니다.
• 그 broker와 관련된 partition에서 ISR shrink가 관찰되었습니다.
• replication lag가 특정 broker 주변으로 치우쳐 보였습니다.
• leader 이동이나 client request 지연처럼 보이는 현상이 함께 나타났습니다.
• 다른 broker들은 상대적으로 정상처럼 보였습니다.

이런 상황에서 가장 먼저 하는 일은 Kafka 안을 보는 것입니다.

• broker log에 disk error, request timeout, replica fetcher error가 있는가?
• GC pause가 길어졌는가?
• network processor나 request handler가 포화되었는가?
• controller event나 leader election이 비정상적으로 반복되는가?
• partition leadership이 한 broker에 과하게 몰렸는가?
• producer traffic이나 consumer fetch pattern이 갑자기 달라졌는가?

하지만 결정적인 단서는 나오지 않았습니다. Kafka log는 조용했고, JVM도 “이게 원인이다”라고 말할 만큼 이상하지 않았습니다. broker 지표는 느린 broker를 가리켰지만, 왜 그 broker가 느려졌는지는 설명하지 못했습니다.

이 시점에서 중요한 것은 보이는 증상이 어디까지 말해주고 어디부터 말해주지 못하는지 구분하는 일이었습니다. ISR shrink와 replication lag는 분명히 느린 broker를 가리켰습니다. 하지만 그것만으로는 왜 그 broker가 느려졌는지, Kafka process 안에서 생긴 문제인지, host 아래쪽 write path에서 생긴 문제인지까지는 알 수 없었습니다.

Kafka 지표가 말하지 못한 것

Kafka broker는 disk-backed log 시스템입니다. produce request는 memory와 page cache를 지나 log segment에 쓰이고, follower replica도 leader에서 fetch한 데이터를 자기 broker의 log에 써야 합니다. broker가 leader든 follower든, 결국 write path가 흔들리면 Kafka 위에서는 여러 모양의 증상으로 나타납니다.

그런데 broker metric만 보면 그 아래 경로가 잘 보이지 않습니다.

Kafka에서 보인 것	바로 알 수 없는 것
broker throughput 감소	application traffic 감소인지, write path 지연인지
ISR shrink	follower fetch 지연인지, follower write 지연인지, leader response 지연인지
request latency 증가	Kafka thread 포화인지, disk flush 지연인지
특정 broker만 느림	broker 설정 문제인지, VM host 문제인지, storage backend 문제인지

이때 분석 범위를 OS 계층으로 내렸습니다.

이상했던 신호는 OS write path에 있었다

Kafka 안에서는 결정적인 오류가 없었지만, host 지표는 다른 이야기를 하고 있었습니다.

특히 눈에 띈 것은 다음 신호였습니다.

• CPU iowait 비율이 평소보다 높아졌습니다.
• /proc/meminfo의 Dirty가 평소보다 오래 높게 남았습니다.
• /proc/meminfo의 Writeback 또는 WritebackTmp가 튀었습니다.
• block device write latency와 in-flight I/O가 broker별로 균일하지 않았습니다.
• Kafka traffic 감소와 dirty page writeback pressure가 시간상 맞물렸습니다.

여기서 중요한 점은 iowait 하나만 보고 “디스크가 원인이다”라고 단정하지 않는 것입니다. iowait는 CPU가 I/O completion을 기다리는 시간을 보여주는 신호일 뿐입니다. Dirty는 아직 storage에 기록되지 않은 dirty page의 양이고, Writeback은 지금 storage로 쓰이는 중인 page의 양입니다. block device latency와 in-flight I/O까지 같이 봐야 “write path가 밀린다”는 해석이 가능해집니다.

실제로는 이런 식으로 같이 봐야 합니다.

vmstat 1
iostat -xz 1
sar -d 1
cat /proc/meminfo | egrep 'Dirty|Writeback'

node_exporter를 쓴다면 이름을 더 정확히 붙일 수 있습니다.

보고 싶은 것	node_exporter metric / PromQL 예시	해석
CPU iowait 비율	node_cpu_seconds_total의 mode="iowait"	CPU time 중 I/O completion을 기다린 비율
dirty page bytes	node_memory_Dirty_bytes	page cache에 있으나 아직 storage에 writeback되지 않은 dirty page
writeback bytes	node_memory_Writeback_bytes	현재 writeback 중인 page
temporary writeback bytes	node_memory_WritebackTmp_bytes	FUSE 등 일부 경로에서 임시 writeback에 잡히는 값
dirty page 비율	node_memory_Dirty_bytes / node_memory_MemTotal_bytes	host memory 대비 dirty page 압력
write throughput	node_disk_written_bytes_total	block device에 기록된 bytes/sec
write latency	rate(node_disk_write_time_seconds_total[5m]) / rate(node_disk_writes_completed_total[5m])	완료된 write 1건당 평균 소요 시간. iostat await에 가까운 파생값
in-flight I/O	node_disk_io_now	현재 진행 중인 I/O 개수
device busy time	rate(node_disk_io_time_seconds_total[5m])	device가 I/O를 처리한 시간 비율에 가까운 신호
weighted I/O time	rate(node_disk_io_time_weighted_seconds_total[5m])	queueing과 in-flight I/O를 함께 반영하는 누적 시간
flush latency	rate(node_disk_flush_requests_time_seconds_total[5m]) / rate(node_disk_flush_requests_total[5m])	kernel/exporter가 flush metric을 제공할 때 flush 요청당 평균 시간

node_memory_Dirty_bytes와 node_memory_Writeback_bytes는 node_exporter의 meminfo collector가 /proc/meminfo를 bytes 단위로 노출한 값입니다. disk latency는 node_disk_write_time_seconds_total 같은 counter를 그대로 보는 것보다, 완료 count로 나눠 평균 write 시간으로 파생해 보는 편이 해석하기 쉽습니다. await는 iostat 용어이므로 Prometheus에서는 위처럼 직접 계산한다고 적는 것이 더 정확합니다.

/proc/vmstat에도 nr_dirty, nr_writeback 같은 page count가 있지만, node_exporter의 vmstat collector는 기본 field filter가 제한적일 수 있습니다. 기본 수집만 전제한다면 meminfo 기반의 node_memory_Dirty_bytes와 node_memory_Writeback_bytes를 먼저 보는 편이 안전합니다.

PromQL로는 이런 식으로 시작할 수 있습니다.

avg by (instance) (rate(node_cpu_seconds_total{mode="iowait"}[5m]))

rate(node_disk_written_bytes_total{device=~"nvme.*|vd.*|sd.*"}[5m])

rate(node_disk_write_time_seconds_total[5m])
/
rate(node_disk_writes_completed_total[5m])

그리고 Kafka 쪽에서는 같은 시간대의 지표를 맞춰 봅니다.

broker bytes in/out
produce/fetch request latency
under replicated partitions
ISR shrink / expand rate
replica fetcher lag
request handler idle ratio

이 둘을 시간축으로 겹쳐보면 단일 지표보다 더 많은 것이 보입니다. Kafka가 먼저 흔들렸는지, OS writeback이 먼저 흔들렸는지, 특정 broker의 block device latency가 먼저 튀었는지를 볼 수 있습니다.

원인은 local disk가 아니었다

추적을 더 내려가니 중요한 사실이 나왔습니다.

Kafka broker VM들이 쓰는 block storage는 VM 안에서는 disk처럼 보였지만, 실제로는 network storage였습니다. broker VM 입장에서는 /dev/... block device였지만, 아래에는 hypervisor, network path, shared storage backend가 있었습니다.

문제의 broker는 그 storage backend 경합에서 밀렸습니다. 그러자 이 broker의 write latency가 불안정해졌고, page cache의 Dirty/Writeback 흐름도 흔들렸습니다. Kafka는 그 위에서 다음과 같은 증상을 보였습니다.

• produce 처리량이 낮아짐
• follower replica의 local log write가 늦어짐
• leader를 따라가지 못하는 replica가 생김
• ISR shrink가 증가함
• client 입장에서는 특정 broker가 느린 것처럼 보임

이 구조에서는 broker process만 보아서는 답이 나오기 어렵습니다. Kafka는 자기 log에 쓰고 있었을 뿐이고, JVM은 JVM 안에서 크게 잘못한 것이 없었습니다. 느려진 곳은 broker 아래의 storage path였습니다.

네트워크 블록스토리지는 왜 조심해야 하나

이 글의 결론이 “Kafka에는 network storage를 절대 쓰면 안 된다”는 뜻은 아닙니다. 환경에 따라 provisioned IOPS, latency SLO, dedicated path, local SSD cache, single tenant storage, cloud provider의 보장 모델이 있을 수 있습니다.

하지만 Kafka broker는 storage latency에 민감합니다. 특히 throughput이 일정하게 들어오는 cluster에서 broker별 storage latency가 균일하지 않으면 replication과 leadership 분산이 흔들립니다.

network block storage에서 특히 조심할 부분은 다음입니다.

• VM 안에서는 local disk처럼 보이지만 실제 병목은 밖에 있을 수 있습니다.
• 같은 storage backend를 공유하는 다른 workload의 영향을 받을 수 있습니다.
• 평균 latency보다 tail latency가 더 중요할 수 있습니다.
• broker별로 같은 VM spec이어도 storage path는 같지 않을 수 있습니다.
• cloud나 virtualization 계층에서 보이는 지표와 guest OS 지표가 다를 수 있습니다.

Kafka는 broker 수만 늘린다고 자동으로 안정해지지 않습니다. broker마다 비슷한 CPU, memory, network를 줬더라도 storage path가 균일하지 않으면 느린 broker 하나가 replication health를 흔들 수 있습니다.

분석을 어떻게 이어가야 하나

이 경험 이후로 Kafka broker 이상을 볼 때는 다음 순서로 봅니다.

1. Kafka 증상을 확인합니다.
   • throughput, request latency, ISR shrink, under replicated partition, replica fetcher lag를 봅니다.
2. 증상이 특정 broker에 몰리는지 확인합니다.
   • leadership, replica lag, client request latency가 같은 broker 주변에 모이는지 봅니다.
3. JVM과 broker thread를 봅니다.
   • GC, network/request handler, request queue, page cache 관련 간접 신호를 봅니다.
4. OS write path로 내려갑니다.
   • node_cpu_seconds_total의 mode="iowait", node_memory_Dirty_bytes, node_memory_Writeback_bytes, node_disk_write_time_seconds_total, node_disk_writes_completed_total, node_disk_io_now를 봅니다.
5. VM 아래를 확인합니다.
   • hypervisor host, storage backend, network storage 경합, provider metric을 확인합니다.
6. 시간축을 맞춥니다.
   • 어떤 계층의 신호가 먼저 흔들렸는지 봅니다.

핵심은 “Kafka metric 다음에 OS metric을 본다”가 아닙니다. 각 지표를 경로로 연결하는 것입니다.

produce request
-> broker append path
-> page cache dirty pages
-> kernel writeback
-> block device queue
-> hypervisor / network
-> storage backend

어느 지점에서 지연이 생겨도 Kafka 위에서는 throughput 감소, request latency 증가, replication lag, ISR shrink 같은 형태로 보일 수 있습니다.

Konduo 관점에서 보면

이 글의 주제는 결국 운영 단계에서 상태와 근거를 어떻게 읽을 것인가로 이어집니다. Konduo는 여러 IT 인프라를 플러그인으로 연결하고, 리소스 상태와 메트릭·로그 근거, 알림 대응, 권한과 운영 이력을 하나의 화면 흐름에서 다루도록 설계된 통합 관리 운영 플랫폼입니다. Kafka broker 문제도 Kafka 지표만으로 끝나지 않고 host, storage, log evidence, alert history와 함께 읽을 때 원인에 더 가까워집니다.

다음 장애에서 쓸 체크리스트

비슷한 현상을 다시 본다면 다음 질문부터 확인합니다.

• Kafka 증상이 특정 broker 주변에 반복해서 모이는가?
• replication lag, ISR shrink, request latency가 같은 시간대에 같이 움직이는가?
• broker log/JVM/GC에 결정적인 단서가 없을 때 OS write path를 봤는가?
• node_memory_Dirty_bytes와 node_memory_Writeback_bytes가 평소 baseline에서 벗어났는가?
• node_disk_write_time_seconds_total / node_disk_writes_completed_total로 계산한 write latency가 broker별로 불균형한가?
• node_disk_io_now나 node_disk_io_time_weighted_seconds_total로 본 in-flight I/O 또는 queueing 신호가 같이 튀는가?
• VM의 block device가 실제로 local disk인지 network storage인지 확인했는가?
• 같은 storage backend를 공유하는 다른 workload나 tenant 영향을 볼 수 있는가?
• Kafka 지표와 OS/storage 지표를 같은 시간축으로 맞춰 봤는가?

마무리

Kafka broker는 혼자 느려지지 않습니다.

producer request, page cache dirty pages, writeback, block device, hypervisor, network storage backend가 하나의 경로로 이어져 있고, 그중 아래쪽 계층이 흔들리면 위에서는 ISR 이탈과 leader 이동처럼 보일 수 있습니다.

장애 분석에서 중요한 것은 더 많은 지표를 모으는 것만이 아닙니다. 지표가 놓인 경로를 이해하는 것입니다. Kafka의 ISR shrink는 Kafka metric으로 시작해도, 답은 OS writeback이나 storage backend에 있을 수 있습니다.

운영자는 한 화면의 빨간 숫자가 아니라 요청이 지나가는 전체 경로를 따라가야 합니다.

함께 읽기 좋은 글

이 글의 관점과 이어지는 주제를 더 보려면 아래 글도 함께 읽어볼 수 있습니다.

• Kafka는 메모리가 남아 있는데 왜 OOM이 났을까 - heap 밖 direct buffer까지 포함해 Kafka broker 메모리를 다시 봅니다.
• 겉보기엔 균형 잡힌 Kafka, Broker Metrics는 다르게 말한다 - leader 수보다 실제 broker 부하를 봐야 하는 이유를 다룹니다.
• JVM 메트릭만으로는 컨테이너를 설명할 수 없다 - JVM 밖의 cgroup, filesystem, fd, I/O 신호를 함께 봐야 하는 이유를 다룹니다.