본문 바로가기

프로젝트

[AWS, 기록] lambda: killed Runtime.ExitError

요약

killed Runtime.ExitError은 lambda 함수에 대한 메모리 할당량 부족으로 인해 발생했을 확률이 높다. 현재 에러가 발생했을 때 로그 상에서 Memory Size 관련 내용을 발견할 수 있다면, lambda 함수에 대한 메모리 할당량을 1.5 ~ 2배 늘려 현재 문제를 해결할 수 있다.


문제 상황

나는 현재 진행 중인  졸업 팀 프로젝트에서 뉴스 기사 데이터 수집 기능과 백엔드 파트를 맡아 개발을 진행하고 있다.

뉴스 기사 데이터 수집 기능의 경우 AWS SQS를 이용하여 작업 범위를 적절한 크기로 쪼개 lambda 함수에서 실행하도록 구현하였고, 여태까지는 잘 동작했다. 그런데, 최근 lambda 함수가 지나치게 여러번 실행되는 현상이 Cloud Watch 로그 상에 나타났다. 

Cloud Watch 로그에 나타난 lambda 함수 실행 기록

 대략 9월 말부터 SQS + lambda + S3 기반 파이프라인을 구축하고 운영했지만, 이런 현상은 이전까지 발생하지 않았었던 터라 이게 대체 무슨 일인가 싶었다. lambda가 동작하지 않는 것까지는 좋은데, 대체 왜 여러번 반복되는지도 아리송했다.

 나는 일단 현재 lambda에 의해 파일이 정상적으로 생성되었는지 알아보기 위해 S3 버킷에 저장된 json 목록을 살펴보았다. 일단 결과만 말하자면, 상당히 많은 json 파일이 생성되어 있었다.

에러가 발생한 날 생성되어 있던 수많은 json 파일들

 내가 설계한 시스템은 키워드 1개마다 하나의 json 파일을 만들도록 설계되어 있기 때문에, 지금처럼 많은 파일이 생성되는 것은 절대적으로 비정상이다. 현재 테스트 중인 키워드가 2개뿐이라는 점을 고려하면, 현재 에러는 동일한 키워드에 대한 뉴스 기사를 반복적으로 수집하므로, AI 서버 상에서 동일한 뉴스 및 댓글 목록을 여러번 분석하게 만들 수 있다.

 혹시 몰라 각 json 파일 내부의 내용도 살펴보았는데, 모두 같은 키워드에 대해 생성된 파일에 해당했다.

동일한 키워드에 대해 생성된 파일들

 위 정보를 종합했을 때, 현재 문제는 모종의 이유로 동일 키워드에 대해 lambda 함수가 여러번 실행되는 현상으로 판단했다. 여기서 "모종의 이유"의 원인을 파악하기 위해 각 로그를 살펴보았다.

에러 로그 사항

 에러 로그를 살펴보니, 공통적으로 killed Runtime.ExitError 에러로 인해 프로그램이 종료되었다는 사실을 알게 되었다. 이게 정확히 어떤 의미인지 알아보기 위해 구글링 해보니 다음과 같은 내용이 나왔다. 

 요점은 lambda에 할당된 메모리가 작다는 내용이었다. 위 에러 로그에도 Memory Size 관련 내용이 포함되어 있으며, 메모리 크기가 128MB이지만 최대 129MB의 메모리를 사용했다는 내용이 포함되어 있다. 개인적으로 128MB라는 수치를 상당히 크다고 생각했는데, 예상과는 달리 lambda 함수를 쥐어 짜듯이 사용한 상황이었다...

 아무튼 위 문제가 메모리 때문이라는 것을 알게 되었으므로, 128MB에서 256MB로 기본 크기를 키운 후 경과를 지켜보기로 했다. 만약 256MB의 메모리 중 상당수를 사용하지 않는다면 다시 적절하게 메모리 크기를 변경하여 비용을 줄일 수 있기 때문이다.

 며칠 동안 로그를 살펴본 결과, 기존 128MB에서 코드가 동작한 것이 신기할 정도로 메모리 사용량이 늘었음을 알게 되어 메모리를 줄일 필요는 없게 되었다. 이 정도면 기존 코드가 어떻게 동작했나 싶다. 

200MB에 가까운 메모리 사용량으로 인해 메모리 크기를 줄이기에는 적절하지 않다고 판단했다.


여기서 아직 풀리지 않은 의문이 있는데, 그렇다면 대체 왜 현재 람다 함수가 이렇게 많이 실행되었는가에 대한 부분이다.

 SQS에는 "표시 제한 시간" 이라는 개념이 존재하여 한 소비자가 수신한 메시지를 다른 소비자가 해당 시간만큼 볼 수 없도록 숨긴다. 만약 메시지를 소비하던 함수가 이를 제대로 처리하지 못한 상태에서(소비 / 삭제하지 못한 경우) "표시 제한 시간"을 초과하면 해당 메시지는 다른 소비자에게 보이는 상태가 된다.

AWS SQS 표시 제한 시간 설명

killed Runtime.ExitError은 메모리 부족으로 인해 lambda 함수가 종료되어, 메시지를 제대로 소비하지 못한 상황에 해당한다. 따라서 SQS 메시지는 lambda 함수에 다시 노출되고, 아직 문제가 해결된 상태가 아니기 때문에 다시 에러가 발생하는 문제가 반복된 것이다. 시간 간격을 잘 보면 15분에 가깝게 구성되어 있는데, 이는 SQS 메시지의 표시 제한 시간을 15분으로 지정했기 때문이다. 반대로 시간 간격과 잘 맞지 않는 경우는, 에러가 발생했을 때 lambda 함수를 1회 다시 실행하도록 설정했기 때문이다. 또한 06시쯤부터 문제가 발생하지 않는 이유는 메시지 보존 기간을 6시간으로 지정했기 때문이다.

  • killed Runtime.ExitError로 인해 lambda에서 메시지를 소비하지 못함
  • SQS 메시지 표시 제한시간인 15분 초과
  • lambda 함수가 메시지를 읽고, 다시 killed Runtime.ExitError 발생
  • SQS 메시지 보존 기간인 06시까지 위 과정 반복

Cloud Watch 로그에 나타난 lambda 함수 실행 기록

실제로는 위와 같은 이유가 아닐 수도 있지만, 현재 시점에서 가장 가능성 있는 원인이라고 생각된다.


에러 원인 탐색 과정에서 알게된 내용을 작성한다.

https://stackoverflow.com/questions/51495745/lambda-instance-ram-allocation

람다 함수에서 "동시성"은  동일한 시간대에 동작할 수 있는 인스턴스의 개수를 의미한다. 나는 초반에 혹시 동시에 실행되는 람다 함수들에 대해 메모리가 공유되기 때문에, 메모리 사용량 관련 문제가 생기는 것은 아닐까 생각했다. 그러나 실제로는 람다 함수의 각 인스턴스에 대해 각각 메모리가 할당된다고 한다. 따라서 동시성을 늘린다고 메모리 크기도 늘릴 필요는 없다.


 클라우드 기술은 알면 알수록 단순히 사용할 줄 아는 영역에서 끝나서는 안된다는 것을 느낀다. 최근 여유로울 때 K-MOOC 수업을 수강하면서 클라우드 기술에 대해 이해하기 위해 노력하고 있지만 아직까지는 조금 어려운 것 같다.