kafka-consumer-groups.sh NullPointerException 트러블 슈팅

Kafka 에서는 쉘스크립트를 통해 다양한 Kafka 리소스들을 CLI 를 통해 제어할 수 있게 도와준다.

 

kafka-consumer-groups.sh 는, Kafka CLI 중 group 관련된 리소스 제어를 제공해주는 쉘 스크립트 인데, --describe 옵션을 통해  group-id, topic, partition, offset, lag 과 같은 정보들을 제공해주며, Kafka 의 운영 및 모니터링에 있어서 정말 많이 사용하는 스크립트 이고, 필자도 Kafka 관련 이슈가 발생하면 제일 먼저 해당 스크립트를 찾았었다

 

// 실행 예시
// ./kafka-consumer-groups.sh --bootstrap-server {BOOTSTRAP_SERVER} --describe --group {GROUP_ID}

GROUP		TOPIC		PARTITION	CURRENT-OFFSET	LOG-END-OFFSET	LAG		CONSUMER-ID		HOST		CLIENT-ID
group:example	TEST_TOPIC	0		-		77		-		ci-b1f19adc-134a-...	/172.18.0.1	ci

 

 

그러던 어느날 해당 스크립트를 실행하면 정상적으로 결과값이 리턴되지 않았고,

Kafka 를 운영하며 경험했던 여러 이슈 중 단연 최고였던, 나를 3개월 넘게 괴롭혔던 이 녀석을 한번 리뷰해 보고자 한다.

 

 

---

증상

테스트중인 신규 기능에 사용되던 데이터라 기존의 topic partition 의 개수가 2개 밖에 되지 않았었고,

기능 출시를 앞두고 마지막 테스트를 위해 produce 하는 데이터의 양을 확 늘리자 기존 consumer 들의 스루풋이 produce 되는 데이터의 양을 감당하지 못해 lag 이 발생했고, 이를 해결하기 위해 topic 의 partition 과 consumer 를 늘리는 scale-out 을 수행했다

 

그러자 총 3개의 consumer 중 지속적으로 한 consumer 가 group coordinator 에 의해 group 에서 제외되는 현상이 발생했고

이에 대한 원인 파악을 위해 배스천 호스트에서 kafka-consumer-groups.sh 을 실행하면

 

java.lang.NullPointerException
	at kafka.admin.ConsumerGroupCommand...

 

와 같이 NPE 가 발생하며 스크립트가 비정상 종료 되었다

 

 

---

스크립트 실행 시 NPE 가 발생하는 이유

 

Kafka CLI 는 Kafka 내부의 여러 리소스들의 수정도 가능하지만, 이들의 상태를 알려주는 일종의 지표 역할도 수행한다

헌데, 그러한 스크립트가 NPE 를 내며 종료되었다. 참으로 당황스러운 일이 아닐 수 없다

 

너가 에러나면 난 어떡하라고...

 

관련 이슈를 구글링한 결과, Kafka Jira 에서 올라온 예전 ticket ( https://issues.apache.org/jira/browse/KAFKA-7044 ) 을 통해 해당 이슈의 원인을 찾을 수 있었다.

 

Consumer 는 message 를 consume 한 후 다음 consume 에서 중복된 데이터를 가져오지 않기 위해, 할당 받은 partition 에서 현재까지 consume 한 데이터에 대한 위치값인 offset 을 업데이트 하는데, 이 과정을 commit 이라고 한다.

 

ticket 의 내용에 따르면, group 에서 하나 이상의 partition 에 대해 최소 한번이상의 commit 도 발생하지 않았을 때, group 의 상태를 가져오는데 있어서 NPE 가 발생할 수 있다고 한다

 

따라서 group 의 최소 한개 이상의 partition 에서 offset 이 commit 되지 않았음이 현재 이슈의 원인으로 밝혀졌다

 

---

Commit 이 발생하지 않는 경우

Consumer 에서 commit 은 크게 수동 commit 과 자동 commit 으로 나뉘어진다

 

필자의 경우 Typescript + Node.js 환경에서 Kafka Client 를 활용한 프로젝트를 진행중이었고

싱글스레드인 Node.js 의 경우 Java 같은 언어와 달리 heartbeat 를 포함한 commit 의 반복적인 interval 작업의 수행시간이 보장되지 않기에 ( 왜 Node.js 는 반복작업의 시점이 보장되지 않는지 궁금하다면 이 글을 참고하자 )

commit 작업을 매뉴얼하게 하드코딩 해 놓았고, 따라서 코드상에서의 문제는 없었다

 

이는 Kafka 문제 일리는 절대 없으니 이제 다른 증상이었던

지속적으로 한 consumer 가 group coordinator 에 의해 group 에서 제외
되던 이유를 같이 살펴보자

 

private async handleBatch({ batch, resolveOffset, heartbeat }: EachBatchPayload, topic: string) {

    resolveOffset(batch.lastOffset());	// 이렇게 매번 커밋을 날려준다. 그것도 동기적으로
    
    // batch record 처리
    
    await heartbeat();
    return;
}

 

 

위 코드는 Consumer 의 코드 중 batch 로 Kafka message 를 consume 하는 함수 일부를 가져온 것 인데,

보다싶이 데이터를 처리하기도 전에 맨 먼저 하는게 offset 의 commit 이다.

 

consumer 가 group coordinator 에 의해 group 에서 제외되는 경우에는 크게 2가지가 있는데

 

1. heartbeat 주기가 Consumer의 session.timeout.ms 설정보다 길어질 경우
2. Consumer 가 이전에 consume 한 데이터를 처리하는데 시간이 길어지면서, 다음 offset 에 대한 message consume 까지의 시간이 max.poll.interval.ms 보다 길어진 경우

 

1번이 2번 경우보다 더 짧은 주기를 가져가기 때문에, commit 이 발생하기 이전에 1번 조건에 의해 consumer 가 group coordinator 에 의해 group 에서 제외 됐다는게 가능한 상황이지만,

 

heartbeat 는 수동으로 handleBatch 함수 맨 마지막에서 호출되고 있으므로, 나머지 consumer 들이 정상적으로 돌아가는 상황에서 heartbeat 은 문제가 되지 않는 상황이었다.

 

따라서, 이는 현재 이슈가 commit 을 수행하는 resolveOffset 메소드의 실행 여부와 상관없이

consumer 가 message 를 아예 consume 하지 못하는, 즉 handleBatch 메소드가 실행되지도 않는 상황으로 귀결되므로, 이는 몇몇 consumer 로의 파티셔닝이 이루어지지 않았다는 뜻이 된다

 

( 필자의 경우 offset 의 commit 이 message consume 의 과정에서 최우선적으로 발생하는것이 보장된 상황이었으므로 session.timeout.ms 이나 max.poll.interval.ms 가 문제가 되지 않았던 것이지, 다른 사람들의 경우는 두 옵션을 수정함으로써 NPE 문제를 해결한 경우도 보았었다 )

 

---

허무한 결말

Kafka 의 default partition assign 전략은 round-robin 이다

즉, 파티션이 n 개가 있는데 의도적으로 한 파티션에 파티셔닝이 안된다면 이는 절대 Kafka 의 문제가 아니다

 

깃허브에서 코드의 과거 커밋 기록을 살펴보았고, 이슈 발생시점에서 머지않은 과거에 문제가 되었던 Consumer 에서 subscribe 하는 topic의 Producer 코드에서 message 를 produce 할 때 key 값이 설정된 것을 확인했다

 

출처: https://kafka.js.org/docs/producing#message-key

 

위의 설명과 같이, Kafka message 의 key 값은 파티셔닝에 사용된다

분류되는 key 값도 딱 2 가지였고, topic 의 partition 값도 2 여서 내가 partition 값을 늘리기 전까지 문제가 발생하지 않았던 것이다.

 

producer 에서 key 값을 설정하지 않도록 코드를 수정했고, 이후 파티셔닝이 정상적으로 수행되면서 문제가 해결되었다.

 

피상적으로 드러났던 문제점과 그 원인이 너무 동떨어져있어 3개월동안 고생했던 이슈였던만큼 앞으로의 트러블 슈팅에 있어서 좀 더 넓은 시야로 문제를 바라봐야 겠다는 다짐을 했던 계기가 되었다