말썽꾸러기 Kafka

annakky 2024. 6. 26. 22:54

2024. 6. 26. 22:54

🤨 문제상황

Spring Boot 3.x 와 MSK t3.small 사용중
개발하던 모듈에서 일괄 등록 기능이 있었고, 최대 몇 건까지 가능하냐는 기획자분이 문의 주셨다
1만건, 2만건 씩 대량 생성 요청을 보내면서 테스트하고 있었다. 물론 개발서버에서!
1건당 최소 10개의 kafka 메세지를 발송하는 서비스였다. (entity 변경 내역도 쌓고, 로그도 쌓고 하느라 이것저것 많이 날림),
한번에 메세지를 발송하는 것은 아니고, 몇 초에서 몇 분 안에 총 10개 이상의 메세지를 발송함
요청 직후는 큰 문제는 없었지만, 30분에서 1시간 뒤 부터 TopicAuthorizationException 이 발생했다
kafka-ui 를 구축하여 kafka 상태를 모니터링 하고 있었고, 에러가 발생한 후 부터는 브로커에 상태를 보기 어려웠다.

실제 상황에서는 브로커 정보도 보이지 않았고, Topic을 비롯한 거의 모든 정보가 보이지 않았다. 간헐적으로 몇 개의 브로커의 정보가 보였다가 다시 안보이는 것을 반복했다.

kafka-ui 에서 확인한 장애 상황
가끔 연결되는 브로커 정보를 확인했을 때, Disk usage 가 51GB 까지 올라가는 것을 확인했다. msk 설정에서 브로커당 메모리를 100GB로 잡아놨는데... 가까워지는 게 실시간으로 보였다...

⛏️ 삽질 시작…

1. 인증 문제인가?

TopicAuthorization 이라는 exception 이름으로 유추해 봤을 때, IAM Role에 권한이 빠진건 아닌가 생각해봤다.
→ 보안팀에게 문의 결과 변경점 없다고 답변 받았다.

2. 모를땐 재부팅이지!

AWS MSK 콘솔에 들어가면 브로커 재부팅 버튼이 있다. 이 기능을 사용하여 존재하는 모든 브로커를 재부팅 해봤다.

→ 재부팅 직후에는 kafka-ui 연결도 잘 되는듯 싶다가 몇 분 지나면 동일한 증상을 보인다.

3. 브로커 로그를 켜보자

kafka-ui에서 브로커 상태를 볼 수 없는 것으로 보아, 브로커에 이슈가 있어서 연결이 안되는 것이라고 판단하였다.

그러나 connection 이슈 및 broker endpoint는 외부에서 접근이 어려웠다.

그래서 브로커 로그를 확인할 수 있도록 S3에 브로커 로그를 쌓는 설정을 추가하였다.

AWS 콘솔에서 MSK 설정을 확인해보면, 로그전송 설정이 있다. 여기서 원하는 S3 버킷을 골라 로그전송 설정을 ON하면 설정 끝이다.

그럼 다음과 같이 S3에서 로그를 확인할 수 있다.

4. 메세지 쏠림 현상인가?

문제 발생 시점이 대량 bulk 등록으로 인해 엄청나게 많은 메세지가 발행되고 난 후이다. 그럼 대량 메세지를 의심할 수 밖에 없다.

브로커가 현재 2개인데, 너무 적은 브로커에 부하가 많이 몰려서 죽는것인가?

예상 이유

브로커 디스크 사용량이 꾸준하게 증가하고 있었고, CPU 사용률과 네트워크 패킷수가 하나의 브로커만 튀고 급격하게 감소하는 모습을 보인다. 하나의 브로커에 요청이 몰려서 죽는것처럼 보인다.
Pod에서 BufferExhaustedException 이 발생했다

이를 해결하기 위해 브로커의 개수를 늘리고, 가장 많은 메모리를 차지하는 topic을 제거하였다.

브로커 개수는 가용영역당 브로커 1개로 총 2개 -> 가용영역당 브로커 2개로 총 4개로 2배 증가하였다.

위 지표처럼 네트워크와 CPU 사용률은 줄어들었지만, 브로커가 연결이 안되는 문제는 동일했다.

5. SASL 설정 문제인가?

정상 동작하는 팀의 MSK 인증방식은 SASL/SCRAM, IAM 을 사용하고 있었다.

우리팀의 인증방식은 IAM 으로 설정되어 있었다.

그리고 최근에 인증 방식을 SASL로 변경했기 때문에 의심하던 와중에 다음과 같은 로그가 발생했다.

그래서 보안설정을 변경해보았다

그러나 이 방법도 실패하였다.

💪🏻 드디어 해결!

AWS MSK 공식 페이지에 게시된 문의 내용 중, SaslAuthenticationException 관련 내용이 있었다. [바로가기]

별 생각 없이 문서를 보다가 해당 내용이 눈에 들어왔다. 음? 초당 하나의 TCP 연결? 냄새가 났다. 관련해서 더 찾아보니 다른 문의글도 있었다. [바로가기]

이 글에는 다음과 같은 내용이 있었다.

MSK Connect에서 IAM 인증을 사용하여 t3 인스턴스를 사용하지 않는 것이 좋습니다. 이는 현재 t3 인스턴스에 적용된 연결 제한 때문입니다.

우리는 MSK Connect를 사용하지 않고, IAM도 사용하고 있지 않지만 t3를 사용하고 있으니 connection 문제는 동일할 것으로 쉽게 유추할 수 있다.

그래서 MSK broker의 스펙을 t3.small -> m5.large 로 변경해보았다. (15분 걸린다고 했는데 1시간이나 걸렸다... 😡)

당연하겠지만, CPU 사용률이 급격하게 줄어들었다. connection 이슈로 인한 CPU 부하가 줄어든 것으로 예상된다.

그리고 같은 에러는 더이상 발생하지 않았다!

👼🏻 무엇이 문제인가

1. consumer/producer 는 왜 broker에 못 붙었을까?

요청하려는 broker에 connection을 얻지 못해 발생하는 이슈이다. t3.small은 초당 1개의 connection만 허용하기 때문에 동시에 많은 요청이 들어올 경우 처리가 connection을 얻지 못한다.

실제 pod의 에러 로그를 보면, DisconnectException 이 발생한다.

초당 1개는 가능하기 때문에 간헐적으로 메세지 produce는 성공했던 것이다.

2. kafka-ui 에서는 왜 broker 상태를 볼 수 없었을까?

kafka-ui는 AdminClient 에 요청해서 kafka 정보를 받아오는데, 이 때 브로커가 connection 문제로 응답을 늦게 전달한다. 그래서 kafka-ui pod의 에러로그에는 TimeOutException이 발생하는데, 도착까지 걸린 시간을 보면, timeout 시간인 30000ms 보다 늦은 30903ms 가 소요된다. 아슬아슬한 timeout이기 때문에 간헐적으로 kafka-ui가 정상동작한 것 처럼 보였던 것이다.

3. 카프카는 대용량 처리를 위한 서비스라면서 이정도로 뻗어도 되나?

이 이슈의 원인은 카프카라기 보다는 AWS MSK의 이슈이다.

AWS MSK에서는 TCP Connection 제한이 존재하고, 클러스터 유형에 따라 다르다.

AWS MSK serverless의 connection quota는 [여기서] 확인 가능하다.

참고로 t3.small 은 브로커마다 초당 1개의 TCP 연결이 가능하고, burst enable시 4개까지 가능하다.

4. 그럼 왜 여태까지 문제가 없었을까?

지금까지는 대량의 요청이 없었기 때문에, 브로커가 초당 1개의 TCP Connection으로도 처리가 가능했다. 많은 메세지가 발행되지도 않았고, 잠깐 요청이 몰리더라도 connection 획득을 기다리면 해결됐기 때문에 문제가 없었다.

브로커 로그를 보면, disconnected 혹은 closing connection 과 같은 connection 이슈들만 발생한다.

😱 또다른 문제...

문제를 해결했다고 판단하여 MSK의 broker 스펙을 t3.small로 낮추었다. 개발서버 비용을 아끼자는 의견이 있었기 때문에 m5.large는 필요할 때 다시 올리기로 하였다.

그래서 대용량 요청은 최대한 지양하고 있었는데 문제가 발생했다.

실제로 요청한 메세지 건수는 몇천건(대략 2000건)에 불과했지만, 새로만든 msk에서 1주일만에 offset이 227,148,710 건까지 늘어났다. 2000건의 메세지로 발생하는 다른 메세지가 있다고 생각하더라도 너무 많은 데이터가 들어오고 있었다.

브로커 디스크 사용량을 확인해보니 linear하게 증가하고 있었고, 중간에 튀는 것 없이 꾸준하게 증가하는 것이 매우 이상했다.

그래서 메세지가 재발행되고 있다고 판단하였고, 그에 따른 문제상황을 살펴보았다.

🔎 문제 파악

producer에서 발생하는 재발행 이슈면, pod의 리소스가 늘어나거나 kafka로의 요청 건수가 늘어나야 한다. 그러나 pod는 모두 정상상태였다.

msk 지표를 확인해보니, 네트워크 패킷수에는 증가가 없었다. 패킷 수가 피크칠 때는 2000건의 요청을 보낸 것이고, 그 이후에는 안정된 모습을 보인다.

지표를 확인하던 중 브로커별 CPU 크레딧 잔액 이라는 지표 눈에 띄었다. 뭔가 냄새가 난다.

CPU 크레딧 잔액은 1번 브로커(파란색) 만 남아있는데, 패킷수와 디스크 사용량을 확인해보면 1번 브로커가 제일 낮다. 1번 브로커가 제일 일을 안해서 잔액이 남는건가? 그럼 잔액이 없으면 어떻게 되는거지?

관련해서 찾아보니 T2/T3에서는 크레딧 잔액이 0에 가까우면 CPU 사용이 제한될 가능성이 있다고 한다. [관련 AWS 문의]

크레딧이 없어서 CPU에 문제가 발생하는거였구나! 관련해서 공식문서를 더 찾아보았다.

T 유형 인스턴스를 사용하고 있습니다.
참고로 T 유형 인스턴스에는 기준 성능과 함께 버스트 가능한 몇 가지 기능이 있습니다. 이 인스턴스는 기준 성능으로 CPU 사용률 20%를 사용할 수 있습니다. 이 값을 초과하면 인스턴스 유형이 CPU 크레딧을 사용하기 시작합니다. 사용률이 20% 미만이면 CPU 크레딧이 누적됩니다.
…
CPUCreditBalance 지표 에 표시된 CPU 크레딧은 인스턴스가 기준 CPU 사용률을 초과하여 버스트하는 데 사용할 수 있습니다.
…
T 유형 인스턴스에서 실행 중인 모든 클러스터의 기준 CPU 사용량과 크레딧 잔액을 모니터링해야 합니다. CPU 사용량이 기준보다 많고 더는 사용할 크레딧이 없으면 클러스터에 성능 문제가 발생합니다.
[AWS 공식문서]

한번에 많은 요청으로 CPU가 부하를 받게 되었고, 이로 인해 메세지 발송 및 처리가 제대로 이루어지지 않아서, 에러 메세지가 계속 쌓이는 것으로 보인다.