IL-0041 PrometheusKube · 2020-11-11 (게시일)kubernetesobservability
PrometheusKube 는 3년 넘게 fluent-bit 으로 로그를 보냈고, 여러 번 업그레이드하는 동안 문제가 없었다. 그런데 운영 환경에서 노드 한 대의 애플리케이션 로그가 완전히 끊겼다. fluent-bit 은 오류를 하나도 남기지 않은 채 로그를 보내지 않았다. 디버그 로그를 보면 해당 인스턴스는 처음 동기화 뒤 아무 일도 하지 않았다. 원문은 코드 안의 교착 상태나 무시된 오류를 원인으로 추정한다. GitHub 이슈 #2416 에 같은 상황이 올라와 있었지만 해결책은 없었다.
팀은 fluent-bit 버그를 당장 고칠 수 없다고 보고 Fluentd 로 바꾸기로 했다. 노드 어피니티로 문제의 노드에만 Fluentd 를 먼저 띄우고 안티 어피니티로 그 노드에서 fluent-bit 을 뺀 다음, 노드 하나씩 넓혀 가는 방식이었다. 몇 시간 뒤 Fluentd 가 `BufferOverflowError error="buffer space has too many data"` 를 내며 로그 전송이 완전히 멈췄다. Fluentd 이슈 #2411 의 조언대로 flush_thread_count 를 늘리고 flush_interval 을 조정하고 버퍼 크기도 키웠지만 같은 오류가 났다. Elasticsearch 도 다시 일부 요청을 거부했다.
Fluentd 는 로그를 처음부터 다시 읽으면서 그 노드에 쌓인 오래된 로그를 전부 다시 보내고 있었다. 팀은 오히려 속도를 늦췄다. flush_thread_count 를 1로 줄이고 flush_interval 을 5초로 늘렸고, 이미 보낸 데이터를 건너뛰게 해 주는 Position DB 기능을 켰다. 그러자 로그가 느리지만 오류 없이 전송되었고, 팀은 노드 하나씩 Fluentd 배포를 마쳤다.
화요일 아침 개발자가 운영 환경 로그 일부가 빠져 있다고 알려 왔다. 이상하게도 빠진 로그는 노드 한 대에서 나온 것뿐이었다.
fluent-bit 로그를 보니 Elasticsearch 가 일부 요청을 받지 않고 있었다. 오류는 `rejected execution of processing of` 로 시작했고, `BulkShardRequest [[index-2020.11.11][0]] containing [2434] requests`, `queue capacity = 200`, `queued tasks = 206` 이 찍혀 있었다. Elasticsearch 에 요청을 처리할 스레드가 모자란다는 뜻이었다.
큐 용량은 설정으로 바꿀 수 없어서 팀은 Elasticsearch 를 돌리는 가상 머신에 CPU 를 늘렸다. Elasticsearch 를 다시 띄우자 이 오류는 사라졌지만, 로그가 빠지는 원인은 따로 있었다. 해당 노드의 fluent-bit 지표를 보니 문제는 계속되고 있었다. 그 노드에서 로그를 많이 남기는 파드 하나의 로그를 Elasticsearch 와 대조해 보니 대부분이 빠져 있었다.
마이너 버전 롤백, 최신 버전 업그레이드, 여러 설정 변경을 해 봤지만 아무것도 듣지 않았다. fluent-bit 의 Prometheus 지표에도 오류는 없었다. 지표는 있었지만 값이 늘지 않았을 뿐이다. 디버그 로그를 켜고 나서야, 문제의 fluent-bit 인스턴스가 처음 동기화를 마친 뒤 아무 동작도 기록하지 않는다는 것을 알았다. 다른 노드의 인스턴스는 로그를 많이 남기고 있었다.
증상 ? 모니터링 중단
원인 ? 소프트웨어 결함
운영 환경 로그 일부가 빠져 있다는 개발자의 메시지로 알았다. fluent-bit 의 Prometheus 지표는 오류를 보이지 않고 값만 멈춰 있어서 모니터링은 이 상황을 잡지 못했다. 지표가 늘지 않는 것도 이슈 #1935 로 보고된 다른 버그였다.
오픈소스 소프트웨어가 어떻게 망가질지는 미리 알 수 없고, 때로는 다른 도구로 빨리 갈아탈 수 있어야 한다. 로그 전송 에이전트는 오류 지표만으로 감시할 수 없다. 이번처럼 지표가 오류 없이 멈추면 아무것도 잡히지 않는다. fluentbit_output_proc_bytes_total 의 5분 비율처럼 전송량에 알림을 걸 수 있다. 트래픽은 밤에 줄고 낮에 늘어 기준값 하나로는 맞지 않으므로, 낮과 밤 기준을 따로 둔다. 테스트 로그를 계속 남기고 Elasticsearch 에 들어왔는지 확인하는 블랙박스 점검도 방법이다. 다만 이런 알림이 울려도 그 자리에서 할 수 있는 조치가 마땅치 않다.
같은 원인 · 공통 텔레메트리 에이전트
같은 원인 · 공통 텔레메트리 에이전트