Loki 인덱스가 무릎 꿇은 새벽 — 라벨 카디널리티 삽질 노트

어쩌다 라벨에 request_id를 박았나

지난주 새벽 2시 17분에 핸드폰이 울렸다. PagerDuty였다. "Loki ingester OOM, 로그 쿼리 응답 없음." 평소 같으면 "내일 보자" 하고 자야 하는데, 마침 다음날 오전에 장애 회고 미팅이 잡혀 있었다. 거기서 로그가 안 보이면 곤란해진다. 노트북을 켰다.

결론부터 말하면, 우리 팀에서 무심코 라벨에 박아놓은 request_id 하나 때문에 Loki 인덱스가 통째로 부풀어 올랐고, ingester가 메모리 한계에 부딪혀 차례로 죽었다. 그 후로 1주일 동안 카디널리티를 줄이느라 정신없이 보냈다. 그 기록이다.

이게 좀 부끄러운 이야기인데, 처음부터 그런 건 아니었다. 우리 팀이 Loki를 도입한 건 작년 봄이었고, 그때는 그냥 namespace, pod, container 정도만 라벨로 썼다. 멀쩡했다. 노드 24대 클러스터, 일 처리 로그가 약 1.2TB 정도였는데, ingester 3개로 충분히 감당이 됐다.

문제는 6개월 전쯤이었다. 서비스 팀에서 "특정 요청의 로그만 따라가고 싶다"는 요구가 들어왔다. 분산 트레이싱은 따로 있긴 한데 로그랑 연결이 매끄럽지 않아서, "그냥 로그에서 request_id로 grep 하면 되지 않나" 하는 의견이 나왔다. 맞는 말이긴 했다. 다만 request_id를 어떻게 노출시키느냐가 문제였다.

누군가가 — 사실 나였다 — Promtail pipeline에서 JSON 로그를 파싱해서 request_id를 라벨로 추출하도록 설정을 바꿨다. {namespace="payment", request_id="abc-123"} 이렇게 쿼리하면 깔끔하게 나오니까 모두가 좋아했다. 슬랙에 "와 이거 편하네" 같은 반응이 줄줄이 달렸다.

그 결정이 6개월 뒤 새벽에 나를 깨운 것이다.

새벽 2시 17분, 처음 본 화면

ingester pod 셋이 모두 OOMKilled 상태로 재시작 루프를 돌고 있었다. kubectl describe를 찍어보니 메모리 limit 12Gi에 도달해서 죽고, 다시 떠서 WAL replay 하다가 또 죽고, 그게 반복되고 있었다.

State:          Waiting
  Reason:       CrashLoopBackOff
Last State:     Terminated
  Reason:       OOMKilled
  Exit Code:    137

처음에는 단순히 트래픽이 튄 줄 알았다. Grafana에서 인입량을 보니 평소랑 비슷했다. 1.4TB/day 수준. 그럼 왜 죽지?

이상한 점은 ingester가 살아있는 짧은 순간(WAL replay 끝나고 죽기 직전 30초~1분)에 메모리 그래프를 보면 거의 수직으로 치솟고 있었다. 그래서 ingester limit을 24Gi로 임시 증액했다. 일단 살리고 보자는 마음이었다. 살았다. 다만 살아난 ingester가 메모리를 21Gi 정도 들고 있었다. 이건 정상이 아니다.

범인은 인덱스 사이즈

/metrics 엔드포인트에서 loki_ingester_memory_streams를 봤다. 평소 약 8만 개였던 활성 stream 수가 270만 개로 늘어 있었다. 35배.

stream이 뭐냐면, Loki는 라벨 조합 하나하나를 별도의 stream으로 본다. {namespace="payment", pod="payment-7d8f", container="app", request_id="abc-123"} 이게 stream 한 개고, request_id="abc-124"로 바뀌면 또 다른 stream이다. UUID 형태의 request_id가 라벨에 박혀 있으니, 들어오는 요청 수만큼 stream이 늘어난다.

stream 하나당 메모리 footprint가 있다. chunk 메타데이터, 인덱스 엔트리, 압축 버퍼 등등. 보통 stream 하나에 약 5~8KB 정도. 270만 × 7KB = 약 18.9GB. 어쩐지.

게다가 stream이 너무 잘게 쪼개지니까 chunk가 flushed 되기 전에 작은 상태로 누적되고, 각 chunk가 인덱스에 별도 엔트리를 만들어서 인덱스도 같이 부풀어 올랐다. 인덱스 store(우리는 TSDB shipper 쓴다) 쓰기 부하도 같이 늘어났다.

라벨 vs structured metadata, 6개월 전에 알았어야 했다

Loki 2.9부터 들어온 기능이 있다. structured metadata. 라벨이긴 한데 인덱스에는 들어가지 않는다. chunk 내부에 메타데이터로만 저장된다. request_id처럼 카디널리티는 높지만 필터링은 필요한 값에 딱 맞는 기능이다.

쿼리는 이렇게 한다:

{namespace="payment"} | request_id="abc-123"

라벨 셀렉터({}) 안이 아니라 파이프 뒤에서 필터링한다. 그러면 인덱스는 namespace="payment"로만 좁히고, chunk를 읽으면서 request_id 매치되는 라인만 뽑는다. 인덱스 폭발 없음. Loki 3.3부터는 structured metadata도 bloom filter로 가속이 된다고 한다. 우리는 아직 3.2라서 못 쓰지만.

문제는 우리가 6개월 전에 promtail에서 labels: 블록에 request_id를 박아놨다는 거였다. 그걸 그대로 두면 마이그레이션이 안 된다. structured metadata로 옮기려면 promtail이 아니라 Loki에 보낼 때 OTLP 또는 native push API를 써야 한다.

우리 환경에서는 Alloy로 옮기면서 처리하는 게 깔끔했다. Promtail은 점차 deprecation 되는 분위기이기도 했고.

일단 응급처치, 그다음 마이그레이션

새벽에 마이그레이션을 할 수는 없었다. 응급으로 한 것:

# loki-config.yaml
limits_config:
  max_streams_per_user: 100000   # 기존 1000000에서 강하게 제한
  max_global_streams_per_user: 500000
  per_stream_rate_limit: 5MB
  per_stream_rate_limit_burst: 20MB

이걸 적용하면 신규 stream 생성이 차단되면서 기존에 떠있던 270만 개 stream 일부가 idle timeout으로 정리되기 시작한다. 다만 이러면 일부 새 stream이 reject 되니까 로그가 손실된다는 단점이 있다. 새벽이라 트래픽도 적었고, 더 큰 장애를 막아야 했으니 받아들였다.

ingester는 안정화됐다. 메모리 12Gi로 돌아갔다.

다음날 아침, 회고 미팅에서 정작 로그가 필요했던 시점의 일부 stream이 reject 되어 있었다. 운이 좋게 핵심 로그는 들어와 있어서 회고는 진행할 수 있었지만, 진땀이 났다.

그 뒤로 한 일들

며칠에 걸쳐서:

1. promtail pipeline에서 request_id를 labels에서 빼고, JSON 로그 본문 안에 그대로 두기로 했다. 어차피 LogQL의 | json 파서로 추출이 가능하니까. {namespace="payment"} | json | request_id="abc-123". 인덱스에 들어가지 않으니 카디널리티 영향 없음.
2. Alloy POC 시작. 일부 노드에 Alloy 데몬셋을 배포해서 structured metadata를 제대로 보낼 수 있는지 확인 중이다. 잘 되면 점진 마이그레이션 예정.
3. 사내 위키에 "Loki 라벨로 박지 말아야 할 것들 체크리스트"를 적었다. UUID성 ID, IP 주소, 타임스탬프, user_id, trace_id 등등. 한 줄 요약: 라벨은 카테고리, 본문은 디테일.

라벨 카디널리티는 처음 도입할 때는 멀쩡해 보인다. 그런데 6개월 뒤에 청구서처럼 돌아온다. 새 라벨을 추가할 때마다 "이게 unbounded인가?"를 한 번씩 묻는 습관을 들이는 게 낫다.

혹시 비슷한 실수 해보신 분 있으면 댓글로 같이 욕 좀 해주세요. 위로가 필요합니다.