Loki 라벨 하나로 인제스터가 죽었다

Loki 라벨 하나로 인제스터가 죽었다

지난주 금요일 오후, Slack 알람이 미친 듯이 울렸다. loki-ingester가 OOMKilled로 재시작 루프에 빠진 것이다. 그날 배포한 건 아무것도 없었다. 근데 왜 갑자기?

결론부터 말하면 개발팀 한 곳이 애플리케이션 로그에 trace_id를 라벨로 추가했다. 그거 하나 때문에 클러스터가 죽을 뻔했다. 이 삽질을 공유한다.

처음엔 그냥 트래픽 스파이크인 줄 알았다

인제스터 3대 중 2대가 메모리 12Gi 리밋을 찍고 OOMKilled. 남은 1대에 부하가 몰리면서 그것도 죽고. 클래식한 캐스케이딩 실패였다.

처음엔 그냥 로그가 늘어난 줄 알았다. 배포 이력을 봐도 로키 관련 변경은 2주 전이 마지막이었고, 그라파나 대시보드에서 로그 인입량(loki_distributor_bytes_received_total)을 봤을 땐 평소랑 큰 차이가 없었다. 아니 오히려 조금 줄어 있었다. 뭐지.

그때 팀 시니어가 지나가면서 "스트림 수 봐봤어?" 한마디 던졌다. 이걸 왜 생각 못했지.

sum(rate(loki_ingester_streams_created_total[5m])) by (tenant)

숫자를 보고 멘탈이 나갔다. 평소 초당 20개 정도 만들어지던 스트림이 초당 3,000개를 넘기고 있었다. 하나의 테넌트에서만.

trace_id를 라벨로 넣으면 벌어지는 일

Loki에 조금이라도 익숙한 분이라면 이 시점에 "아 뻔하지" 하실 거다. 그렇다. 누군가 고카디널리티 값을 라벨로 넣은 거다.

문제의 팀은 OpenTelemetry SDK를 새로 도입하면서 로그에 trace_id를 attribute로 붙였다. 그런데 로그를 Loki로 보내는 collector 파이프라인 설정에서 실수로 trace_id를 stream_labels에 포함시켰다. Promtail의 pipeline_stages로 치면 labels: 아래에 넣은 거다.

trace_id는 매 요청마다 다른 값이다. 하루 300만 요청이면 하루 300만 개의 새 스트림이 생긴다. Loki에서 각 스트림은 별도의 청크 파일로 관리된다. 인제스터는 최근 활성 스트림을 전부 메모리에 들고 있다.

12Gi가 아니라 120Gi를 줘도 부족했을 거다.

응급처치와 삽질

일단 급한 불부터 껐다. 라벨 기반으로 특정 스트림을 강제로 뻥튀기 방지하는 방법은 몇 가지가 있다.

첫 번째로 시도한 건 인제스터의 max_streams_per_user 리밋 강제. 기존에 100,000으로 되어 있었는데 이걸 30,000으로 낮췄다.

limits_config:
  max_streams_per_user: 30000
  max_global_streams_per_user: 30000

근데 이건 이미 문제가 터진 후엔 별 의미가 없었다. 이미 만들어진 스트림은 그대로 살아있고, 리밋에 걸린 신규 로그는 그냥 drop만 될 뿐이었다. 인제스터 메모리는 여전히 위험 수위.

두 번째로 인제스터 리플리카를 5대로 늘렸다. 이건 시간을 벌어줬지만 근본 해결은 아니었다. 청크 flush가 끝날 때까지 버티는 용도.

진짜 해결은 문제 팀에 연락해서 collector 설정에서 trace_id를 라벨에서 빼는 것이었다. 대신 structured metadata로 옮겼다. Loki 3.0부터 지원하는 기능인데, 인덱스에 부담을 안 주면서 검색은 가능한 필드다.

# Alloy/collector 설정
loki.process "default" {
  stage.structured_metadata {
    values = {
      "trace_id" = "trace_id",
      "span_id"  = "span_id",
    }
  }
  // labels 블록에서는 tenant, service, level 정도만
}

이렇게 바꾸고 30분 정도 지나니 스트림 생성률이 정상 수준으로 돌아왔다. 인제스터 메모리도 안정화.

왜 미리 못 잡았을까

사실 이건 방지할 수 있었던 사고다. 우리가 놓친 게 세 가지 있었다.

첫째, 스트림 수 모니터링이 없었다. 로그 인입량은 대시보드에 있었지만 스트림 카디널리티는 없었다. 최근 그라파나가 6월에 GA한 Historical Cardinality 기능이 있는데, 이걸로 시간대별 카디널리티 변화를 추적할 수 있다. 우리 팀은 아직 안 붙였는데 이번 사고 이후 도입 논의 중이다.

둘째, 사전 알림이 없었다. 스트림 수가 임계치를 넘으면 알람이 울렸어야 했는데 그런 룰이 없었다. 지금은 이런 룰을 넣어뒀다.

- alert: LokiHighStreamCardinality
  expr: |
    sum(rate(loki_ingester_streams_created_total[10m])) by (tenant) > 100
  for: 5m
  labels:
    severity: warning
  annotations:
    summary: "Tenant {{ $labels.tenant }} creating {{ $value }} streams/sec"

셋째, 개발팀이 새 라벨을 추가할 때 리뷰 프로세스가 없었다. Loki 라벨 추가는 스키마 변경만큼 신중하게 다뤄야 하는데 그냥 collector config PR 하나로 들어갔다. 지금은 collector 설정 변경 시 관측성 팀 승인을 받게 바꿨다.

배운 것

Loki 운영하시는 분들께 몇 가지 당부하고 싶다. 라벨은 최소한으로. 카디널리티가 100 이하인 것들만 라벨로 쓴다고 생각하는 게 좋다. service, namespace, level 정도가 안전한 후보다.

고카디널리티 필드는 structured metadata를 쓰거나, 아니면 그냥 로그 본문에 두고 LogQL의 json, logfmt 파서로 뽑아 쓰면 된다. 검색 속도는 좀 느리지만 인제스터가 죽는 것보다는 낫다.

그리고 스트림 생성률은 반드시 대시보드에 올려두시길. 인입 바이트만 보면 이런 사고를 놓친다. 우리가 그랬듯이.

혹시 비슷한 사고 겪으신 분 있으면 어떻게 대응하셨는지 댓글로 공유해주시면 좋겠다. 특히 Loki의 새로운 아키텍처(Kafka 백엔드) 도입하신 분 계시면 이야기 좀 나누고 싶다.