우리 서버에 OOMKilled 장애가 발생했어요 - 회고편

이 글은 최근에 있었던 서버 OOMKilled 장애 과정을 기록 및 공유하며 회고하는 글입니다.
또한 이 글은 인프라 레벨(cpu, memory)에서의 장애 감지 및 대응 프로세스에 관한 내용을 기록하기 때문에 NPE(Null Point Exception) 같은 코드 레벨에서의 명확하고 단순한 문제는 크게 다루지 않습니다.

 

여러분들은 서버의 메모리가 부족해 OOMKilled 장애 발생 시 어떻게 대응하시나요?

저는 보통 다음과 같은 프로세스로 대응합니다.

1. 장애 감지
2. 예상되는 원인 범위를 합리적으로 찾고 가설을 세운다. (가설 수립)
3. 가설을 검증하기 위해 APM, log 등 단서들을 찾고 가설을 확인하고 원인 범위를 좁혀간다. (가설 검증 및 route finding)
4. 위 과정을 반복하여 원인을 명확히 찾았다면 이를 해결한다. (문제 해결)
5. 해결 이후에도 명확히 해결되었는지 확인하기 위한 가시성(Observability)를 확보하고 지켜본다 (모니터링)
6. 1~2주 경과 후 이슈를 마무리한다. (이슈 종료)

저는 이게 일반적인 프로세스라고 생각하고 조금은 냉철해보일 수 있지만 장애 순간에 절대 당황한 기색을 보이지 않고 이렇게 하고 있습니다. 실제로 장애 대응 시 저를 보시는 분들은 좀 기계같다고 생각하실 수도 있을 것 같습니다 ㅎㅎ..

아무래도 우리는 모두 인간이다보니 이 과정을 이해하고 있더라도 그 순간의 감정들로 명확한 판단을 하지 못할 수도 있다고 생각합니다.
하지만 회사에서는 프로답게 일해야하기 때문에 중요한 순간에는 감정을 컨트롤할 수 있어야 한다는 생각을 가지고 있습니다. 
이런 가치관 때문에 기계같을 수 있으니 오해는 안 하셨으면 좋겠습니다 :)

 

어쩌면 위에 장애 대응 프로세스 내용을 보시면서 이런 의문이 드시는 분도 있으실 것 같습니다.

장애 발생 시 빠르게 대응해야지 저럴 시간이 있나?

네, 좋은 포인트입니다. 경우에 따라 비즈니스에 치명적이고 빠른 처리가 필요한 경우 일반적으로 scaling을 통해 대응하는 경우가 많습니다. 하지만 이건 임시 방편인 경우가 많고 장애 발생 시 적절한 action item이 나오는 게 좋은 장애 대응이라고 다들 아실거라 생각됩니다. 

오늘 이야기는 임시 방편이 아니라 실제 장애 대응 시 어떻게 적절한 action item을 뽑는지. 어떤 사고 과정들이 중요했었는지 기록하는 이야기입니다.

 

장애는 어떻게 보통 어떻게 감지하시나요?

여러가지 방법을 통해 장애를 감지하고 계실 것 같습니다. 제가 경험했던 장애 감지 유형은 다음과 같습니다.

1. 사내 모니터링 alert에서 감지된다.
2. 서비스를 사용하시는 사내 구성원 분의 이슈 레이즈로 감지된다.
3. 유저의 이슈 레이즈로 감지된다.

감이 오셨겠지만 2번과 3번은 기술팀에서 의도하지 않았고 감지하고 있지 못했기 때문에 꽤 심각한 상황입니다.
그리고 이런 상황들은 Observability가 부족하다는 지표가 됩니다.

보통 Observability를 잘 확보해둔 팀은 장애 원인 파악이 쉽고 정확한 대응이 가능합니다.
하지만 실제 상황에서는 소프트웨어와 팀은 항상 진화하고 빠르게 달리는 와중에 모든 걸 챙기기는 어려운 것 같습니다.
그리고 실수가 발생할 수 있는 건 너무나 당연하고 그 실수를 인정하고 해결을 잘 하는 것이 인간적으로도 성숙하고 팀적으로도 성숙하다고 생각합니다.

장애 감지

이번 장애는 위의 2번에 해당하는 장애 감지였습니다. 
다행히 유저분들에게 직접적으로 장애가 노출되는 상황은 아니였지만 비즈니스에는 치명적이였습니다.
Observability가 부족했던 상황이었고 쉽게 찾기 어려웠습니다. 그래서 일시적으로 scailing해서 임시 대응 후 하루 정도 명확한 원인 찾기를 위해 Observability 보완을 진행했습니다.

 

가설 수립

장애 감지 후 가설을 수립합니다.
이번 장애는 OOMKilled로 pod들이 죽어버렸고 runtime에 동작하던 goroutine들이 유실되던 상황이었습니다.
일반적으로 큰 범위에 속하는 APM을 먼저 살펴보기 때문에 OOMKilled는 빠르게 확인할 수 있었고 log와 DB data로 goroutine안에서 뭔가 문제가 발생하고 있다는 걸 감지할 수 있었습니다.

이후에 세운 가설을 다음과 같습니다.

1) goroutine이 정상적으로 완료되지 못하고 메모리에 계속 쌓인다.
이 경우 메모리는 제한적이기 때문에 OOMKilled가 나기 충분한 상황이었습니다. 그래서 확인이 필요했습니다.

2) goroutine 안에서 뭔가 로딩이 긴 부분이 있다.
이 경우 아래 2가지를 확인해야한다고 판단했습니다.

1. data가 적재되지 않는 상황이 있었기 때문에 DB connection에 문제가 있었는지 확인이 필요
2. api call 등 timeout을 적절하게 확인

가설 검증 및 route finding

이제 세워둔 가설을 기반으로 검증을 시작합니다.

1) goroutine이 정상적으로 완료되지 못하고 메모리에 계속 쌓인다

먼저 일반적으로 DB에서 문제가 많이 발생하기 때문에 DB와 관련된 지표를 보면서 분석을 진행했습니다.
제가 DB에서 주로 보는 지표는 다음과 같습니다.

1. CPU
DB에서 CPU는 I/O 작업 시에 활용하게 되고 CPU가 99%를 치솟으면 모든 작업에서 timeout이 발생하는 현상이 주로 발생합니다. 그래서 CPU를 가장 먼저 살펴봅니다. (90% 정도도 위험한 수치라고 판단하고 alert를 설정해두고 있습니다.)

다행히 CPU는 50% 정도로 문제가 없어보였습니다.

2. connection 및 쿼리 속도

fyi) 제가 근무하고 있는 회사는 AWS Aurora MySQL을 사용하고 datadog을 통해서 중요 DB metric을 살펴볼 수 있는 환경입니다.

DB 쿼리 속도가 CPU와 상관없이 느리다고 뭔가 lock이 잡히는 부분이 있다는 가설도 있었기 때문에 쿼리 속도 관련을 살펴봤습니다.
RDS 사용 시 모니터링을 활성화해두면 AWS CloudWatch에서는 RDS 관련 메트릭이 꽤 상세하게 기록되는데 이를 활용해 가설을 쉽게 확인할 수 있었습니다.

당시 살펴본 지표는 다음과 같고 DB 문제는 아니였습니다.

Deadlocks: 초당 평균 교착 상태 수

-> 0.003으로 데드락은 영향 없어보임

DMLThroughput

-> 일시적으로 DML 처리량이 늘어났지만 1주일 추이를 보면 비슷한 추이
-> 그러나 지난주에는 OOMKilled가 발생하지 않았고 이상 수치로 보이진 않음 -> 영향 없어보임

InsertLatency

-> 최대 30 ms를 넘지 않음 DB에 저장 시 지연이 goroutine 로딩에 영향을 주진 않음

 

 

 

2) goroutine 안에서 뭔가 로딩이 긴 부분이 있다. 이게 뭔지 찾아야 한다

위 과정을 통해서 DB 문제는 아니라고 판단했고 코드 레벨에서 문제 확인이 필요했습니다.
그러나 이건 코드 레벨에서 문제를 찾는 건 모든 코드를 살펴보며 가설을 세우고 검증해야하기 때문에 여간 쉬운 일은 아닌데요.
이럴 때 메모리 사용량, CPU 점유 시간 등을 함수별, 패키지별로 볼 수 있는 기능을 포함한 profiler를 사용하면 가시성을 확보할 수 있습니다.

저희 회사는 golang을 사용하고 있고 혹시 golang을 사용하고 계신 분들은 pprof와 같은 오픈소스 profiler를 활용해볼 수도 있습니다.

저희는 datadog을 쓰고 있어서 빠른 적용을 위해 datadog profiler를 추가했습니다.
datadog에서 제공하는 오픈소스인 dd-trace-go를 사용하면 다음과 같은 코드 추가만으로 쉽게 profiler를 추가할 수 있습니다.

 

이렇게 Observability를 확보해두고 데이터가 쌓여야 명확한 가설 검증을 할 수 있기 때문에 조금 지켜보기로 했습니다.

 

문제 해결

profiler를 추가하고 데이터 추이를 살펴보니 gRPC client에서 goroutine을 과도하게 잡아먹고 있는 걸 확인했습니다.

 

원래 gRPC client는 goroutine을 과도하게 잡아먹지 않고 연결 실패 시 timeout이 발생하는 걸 의도했었지만 현재는 의도대로 동작하고 있지 않았기 때문에 문제라고 판단되었습니다.

그래서 context에 timeout을 추가하는 작업을 진행했고 goroutine 수는 정상 수치로 돌아오는 걸 확인했습니다.
fyi) golang에서는 context라는 개념이 존재하는데 context에 timeout이 없으면 gRPC client에서 timeout 처리를 하지 않습니다.

datadog profiler goroutine count metric

 

 

문제 해결 이후 모니터링 및 이슈 종료

문제 해결 이후 문제가 재발하지 않는지 모니터링하는 건 매우 중요합니다.
그리고 문제 해결 이후 트래픽 피크 시간에도 고루틴이 정상 수치로 유지되는지 확인하기 위해 profiler를 계속 켜두고 좀 더 지켜보기로 했습니다.

다행히도 트리팩이 몰리는 피크 시간에도 gRPC client가 점유하던 goroutine 수는 정상 수치로 확인되었고 이슈 해결로 처리하게 되었습니다.

gRPC client의 timeout과 관련된 부분은 따로 학습 후 글을 작성해보려고 합니다.

 

장애 회고

이슈 종료 후 이슈가 다시는 발생하지 않도록 지식 기록 및 공유의 목적으로 장애 회고를 하는 것도 중요합니다.
보통 명확한 원인 파악 및 공유를 위해 double check 차 시점 별로 기록해서 장애 회고를 하게 되는데 기존에 이슈 원인 파악 시에도 히스토리 기록과 함께 소통을 잘 진행했다면 이 때 자료들을 복붙하면 꽤 도움이 되는 것 같습니다.

 

Lesson learned

이번 이슈 해결을 하면서 느낀 점들은 다음과 같습니다.

1. 이슈 발생 시 감정적인 부분은 최대한 절제하고 이슈 해결과 핵심에 집중한다.

사람은 감정이 있는 동물이니 이슈 발생 시 당황할 수 있는 건 자연스럽습니다. 하지만 이런 감정 소모가 현실적으로 이슈 해결에 도움이 되진 않는다고 생각합니다. 그리고 여러명이서 이슈를 파악할 때는 각자의 가설이나 공유된 가설을 가지고 원인을 파악하기 때문에 무작정 현상을 공유하기보단 본인의 생각을 포함한 현상 + 가설의 검증 여부 + action item을 묶어서 공유하는 게 훨씬 좋습니다.
특히 현상만 공유되었을 때 다른 사람은 이미 확인한 사항이라면 현실적으로 큰 도움이 되진 않습니다.

당시 팀에서 같이 대응하고 있었는데 일부 팀원분은 생각보다 당황하셔서 그런지 이런 과정이 어려울 수도 있겠다는 생각이 들었고 누군가는 부담을 느끼시는 걸 간접적으로 느꼈던 것 같습니다. 그리고 제가 타인의 감정을 책임질 순 없으니 멀리서 응원을 했던 것 같습니다.

2. 팀원에게 이슈 해결을 위한 작업을 나눠주는 것이 좋다.

이슈 해결을 사실 최대한 빠르게 하는 것이 좋습니다. 그래서 원인과 해결 방법을 명확히 인지한 사람이 작업까지 해버리면 가장 빠른 해결이 됩니다. 그래서 팀에 서버 엔지니어 수가 2명일 때는 각자 빠르게 해결하는 게 너무나 당연했지만, 지금은 5명 정도 되었고 팀원 분들에게 작업을 나누어주는 게 개인의 자기효능감을 비롯한 팀의 사기를 올리는 데 도움이 될 것 같다는 걸 느꼈습니다. 그래서 이번에는 작업을 나눠서 진행했던 게 꽤 좋았다고 생각합니다.

긴 글 읽어주셔서 감사합니다 :)