DEVOCEAN

최근 신규 연동했던 서비스에서 502 에러응답이 온다는 클라이언트쪽 문의가 들어와서 이부분 트러블슈팅을 진행하였습니다.

API에서 502를 응답하는 케이스는 없었기에 502를 어디서 응답하는지부터 파악해보았는데요.

아키텍쳐를 고려했을때, AWS를 사용하고 있었고 NLB -> ALB -> ECS(API) 로 이어지는 구조였기때문에 502 응답이 올수 있는곳은 ALB 뿐이라고 판단했고,

실제로 이 ALB의 Cloudwatch Metric(HTTPCode_ELB_502_Count)을 확인했을때 해당 지표가 일부 시간대에서 0이상 값을 가지는 걸 확인했습니다.

AWS 가이드에 따르면 정확히 어떤 이유로 ALB가 502를 응답하는지 확인하기 위해서는 해당 로드밸런서의 Access Log를 수집해야합니다.

특별한 조치가 없을때는 디폴트로는 Access Log를 수집하지 않습니다. 수집을 위해서는 몇가지 절차가 필요합니다.

aws 문서 에 잘 나와있으니 참고하시면 됩니다. 이를 요약해보자면

1. 수집된 로그가 저장될 s3 버킷을 미리 만든다

2. 해당 버킷의 Bucket Policy에 적절한 권한(LB가 S3 object를 추가할수 있는 권한)을 추가한다.

3. ALB의 Access Log 옵션을 활성화하고 만들어둔 S3 버킷을 Destination 으로 추가한다.

위 절차가 모두 완료되어 Access Log 가 S3 버킷에 잘 남는 걸 확인한 후에는 이제 Access Log 분석이 필요합니다.

s3 에는 각 로그가 텍스트의 압축파일 형태로 저장되어 일일히 분석하기가 쉽지 않습니다.

이때 활용할 수 있는것이 athena 입니다. Athena 는 s3에 저장된 데이터를 source로 하여 쿼리할 수 있는 서비스입니다.

먼저 s3 에 저장된 데이터 기반으로 Athena 테이블을 만들어야하는데요. CREATE TABLE ~ 로 시작하고, 데이터 내 필드명등을 포함하는 Athena Query 를 작성하여야합니다.

친절하게도 AWS 는 ALB Log를 Athena에서 쿼리할수 있도록 사전에 ALB 테이블 생성 쿼리를 만들어두었습니다.

만들어진 Athena 테이블에 일반적인 SQL 쿼리를 사용할 수 있습니다.

예를 들어 저희는 502 응답한 요청들을 확인해야하기 때문에 아래와 같은 쿼리를 사용하였습니다.

SELECT * FROM alb_logs WHERE elb_status_code = 502

위 쿼리를 이용하여, 문제가 되었던 요청들을 자세히 살펴보겠습니다. 먼저 Count를 보겠습니다.

Access log 를 활성화했던 26일 저녁부터 27일 점심정도까지 30건입니다.

총 요청은 약 200만건정도로 502 응답의 비율은 0.0015%정도입니다. 매우 적은 수준이긴 했습니다.

위의 가이드에서 확인해보라고 조언하는 세가지 지표(request_processing_time, target_processing_time, and response_processing_time)를 확인해보겠습니다.

각 지표는 아래와 의미를 가집니다.

• request_processing_time은 Load Balancer(이하 LB) 가 요청을 받고 타겟으로 요청을 보내기까지의 시간

• target_processing_time은 타겟이 로드밸런서가 요청을 보내고 타겟이 응답 헤더를 보내기까지의 시간입니다.

• response_processing_time 은 로드밸런서가 타겟으로부터 응답헤더를 받고 클라이언트로 응답을 보내기시작할때까지의 시간

세 필드의 값을 확인해봤을때, 앞의 두 지표는 0이거나 매우 적은 값을 가지는 데 비해 response_processing_time는 -1값을 가지는 것이 확인되었습니다.

response_processing_time 값만 -1을 가지는 케이스에 대해서 위의 AWS 가이드에 따르면,

LB가 타겟에 요청을 보내는 중에 타겟이 TCP RST 나 TCP FIN으로 커넥션을 닫은 경우에 발생할 수 있다고 설명하고 있습니다.

또한 보통 타겟의 keep-alive timeout 이 LB의 idle timeout보다 낮은 경우에 발생하니 keep-alive timeout을 idle timeout값보다 높혀야한다고 추가적으로 예시까지 들어주고 있습니다.

ALB <-> Target group 간의 커넥션에서, LB는 Client, Target group은 Server 의 역할을 합니다.

Keep-alive timeout은 커넥션의 재사용 기능인 Keep-alive(HTTP/1.1 부터 디폴트로 적용)의 제한 시간을 의미하고 서버에서 적용합니다.

지금 우리 케이스의 경우에는 Target group인 API 서버에서 적용하는 내용입니다.

Idle timeout의 경우에는 클라이언트인 로드밸런서가 서버와의 커넥션을 관리할때 커넥션들 중 특정시간동안 사용하지 않았던 유휴(Idle) 커넥션을 삭제하기 위해 삭제주기를 관리하기 위한 설정입니다.

특별한 설정이 없으면 기본적으로 ALB는 Idle-timeout 이 60초입니다. 즉, 60초동안 요청이 없었던 커넥션은 삭제하기 위함이지요.

그렇다면 Target group의 keep-alive timeout은 어떻게 설정되어있을까요.

저희는 물리 서버 없이 ECS Fargate 로 서버를 운영중이고 웹서버로 Gunicorn 을 사용중에 있습니다.

특별한 keep-alive 설정없이 사용중이었고, 확인해보니 기본 셋팅으로 사용하면 keep-alive timeout 이 2초입니다.

즉, 위 이슈의 원인은 Gunicorn 과 LB 간의 Connection에 서버인 Gunicorn 은 요청이 없이 2초가 지났기 때문에 연결을 끊었고,

클라이언트인 LB는 Idle-timeut 이 60초이기 때문에 해당 커넥션이 끊긴지 모르고 닫힌 커넥션에 요청을 해서 응답을 받지 못해 502 응답을 하게 된것입니다.

따라서 이 부분은 Target Server의 Keep alive timeout 을 Idle-timeout인 60초보다 더 크게, 65초로 증가시켜서 신규 배포하여 대응하였습니다.

정확히 제가 AWS ALB의 동작방식을 알지는 못하지만, LB 와 Target Server 간에 통신시 적절한 크기의 Connection pool 을 두고 통신하고 있기 때문에

서버가 Keep-alive timeout 을 좀 더 길게 가져가도 괜찮고, Default인 2초는 이러한 통신방식에서는 확실히 너무 짧다고 판단됩니다.

Timeout 조정 작업 이후로는 502 응답은 더이상 발생하지 않는것으로 확인되었습니다.

한줄요약

• LB 와 Target group 간의 통신시 Target group server의 keep-alive timeout은 꼭 LB Connection Idle timeout 보다 길게 가져가도록 하세요~!