[AWS] ALB Access Log 활성화 및 분석하기

ALB Access Log 란

ALB Access Log는 말 그대로 단순 트래픽 로그다. 이것을 통해 ELB-respose, Target-response, Client, 접근 경로 등을 알 수 있으며 클라우드 환경에서 서비스를 올리면 자주 접해야 하는 것 중 하나며 기본 중의 기본이다.

 

Access Log를 통해 대략적인 추측은 가능하나 (Client의 요청이 어디까지 도달했는지, 무슨 에러를 뱉었는지, 어떤 요청을 했을 때 어떤 반응을 보였는지 etc...) 정확한 점검을 위해선 어플리케이션 점검이 필수적이다. 기능 활성화에 추가 과금은 없으며 로그 저장을 위한 버킷 과금만 발생하니 운영하는 서비스라면 웬만해선 설정해주자.

 

 

 

사전 준비

- 트래픽을 받고 뱉을 EC2 등의 서비스

- 로그 저장을 위한 S3

- 트래픽 테스팅을 위한 ALB

- ABL Access Log 활성화

 

본 포스팅은 필자가 사전에 구축한 간단한 3Tier architecture를 기반으로 테스트했다. 간단히 설명하자면 WEB/WAS가 분리되었고 'External ALB 호출 -> WEB -> Internal ALB 호출 -> WAS'까지 요청이 도달하는지 확인하고 그 로그를 확인해보려 한다.

 

 

 

ALB Access Log 활성화 및 S3 버킷 정책 수정

우선 EC2, ALB, S3는 사전에 구축되어 있다는 전제하에 진행하겠다. 먼저 EC2 서비스 콘솔 화면에 사이드바에 있는 '로드밸런싱'의 '로드밸런서'를 선택하고 해당되는 ALB를 선택한 후, 속성을 확인해보면 Default 값으로 다음과 같이 보일 것이다.

 

 

여기서 우리는 '속성 편집'을 클랙해 액세스 로그를 활성화하고 입력해주면 된다. 로그용 버킷과 각각의 ALB를 위해 로그가 분리 저장되도록 구성해주는 것이 좋다. 

 

 

하지만 아마도 권한 문제로 바로 적용은 안될 것이다. 필자는 S3 버킷을 Public으로 OPEN하지 않았다. 대신 버킷의 권한을 편집해 ALB Access Log가 쌓일 수 있게 설정하려 한다. 먼저 다음 표를 참조해보자.

 

https://docs.aws.amazon.com/elasticloadbalancing/latest/application/load-balancer-access-logs.html

 

액세스 로깅을 활성화할 때 액세스 로그에 대해 S3 버킷을 지정해야 하는데 다음 요구 사항을 충족해야 한다.

- 버킷은 로드 밸런서와 동일한 리전에 있어야 한다.

- Amazon S3 관리형 암호화 키(SSE-S3)가 필요하다.

 

각자의 Region에 해당되는 'Elastic Load Balancing account ID'를 참고해 버킷 정책을 수정해준다. 버킷 정책을 통해 ELB 및 사용자 접근 권한 등의 정책을 생성할 수 있다. 필자가 이용하는 Region은 도쿄이니 다음과 같이 수정해주었다.

 

https://docs.aws.amazon.com/elasticloadbalancing/latest/classic/enable-access-logs.html

 

 

ALB Access Log 분석하기

여기까지 성공적으로 진행했다면 S3 버킷에 로그가 쌓였을 것이다. 밑에도 언급했다시피 5분 주기로 로그가 쌓이니 바로는 쌓이지 않는다. 조금 기다리면 보일 것이다.

 

bucket[/prefix]/AWSLogs/aws-account-id/elasticloadbalancing/region/yyyy/mm/dd/aws-account-id_elasticloadbalancing_region_net.load-balancer-id_end-time_random-string.log.gz

출처: https://docs.aws.amazon.com/ko_kr/elasticloadbalancing/latest/network/load-balancer-access-logs.html

 

 

ALB Access Log 특징

ALB Access Log의 규칙은 일반적으로 위와 같으며 서비스나 호출에 따라 약간의 변동은 있을 수 있다. 여기에 Access Log에 대한 추가 설명을 곁들이자면 다음과 같다.

 

- Timstamp는 UTC 기준으로이다.

     (KST 기준이 아니므로 특정 시간대의 트래픽 로그를 찾을 때,

     그 로그는 그 전날 혹은 그다음 날 이름의 로그 데이터에 쌓여있을 수 있다. 이 부분은 자주 헷갈린다..)

- ALB Access Log는 5분 단위로 저장된다. 

     (예를 들어 08:03에 발생한 트래픽은 08:00~08:05 사이로 08:05 기준 트래픽에 저장된다.)

- Network Interface 마다 나눠져서 정장된다.

     (내부적으로 ALB가 Scale-Out 되면 그 수만큼 나눠져서 저장된다.

     특정 시간대에 트래픽을 분석하려 한다면 모든 Network Interface를 분석해야 한다.

     ALB도 결국 서버라는 것을 잊지 말자)

- 한 번에 하나의 객체만 다운로드할 수 있다. 

     (하지만 AWS CLI를 사용하면 한 번에 받을 수 있다.)

- ALB Access Log에 이상 로그가 없다고 맹신하지 말자.

     (모든 트래픽을 전부 저장하는 것은 아닌 듯하다. 이 부분은 나도 추가 공부가 필요하다.)

 

 

ALB Access Log Format

[type] [time] [elb] [client:port] [target:port] [request_processing_time] [target_processing_time] [response_processing_time] [elb_status_code] [target_status_code] [received_bytes] [sent_bytes] ["request"] ["user_agent"] [ssl_cipher] [ssl_protocol] [target_group_arn] ["trace_id"] ["domain_name"] ["chosen_cert_arn"] [matched_rule_priority] [request_creation_time] ["actions_executed"] ["redirect_url"] ["error_reason"] ["target:port_list"] ["target_status_code_list"] ["classification"] ["classification_reason"]

 

참고: https://docs.aws.amazon.com/elasticloadbalancing/latest/application/load-balancer-access-logs.html

 

 

각 항목의 자세한 설명은 AWS 공식 도큐먼트를 참조하도록 하자. 그럼 이제 실제로 내가 구성한 환경에서 발생한 Access Log를 분석해보도록 하자. 통신 환경은 대략 다음과 같다.

 

임의로 웹브라우저를 통해 Client(나)가 WAS까지 요청을 보내봤으며 해당 로그 내용은 다음과 같다.

 

http 2022-03-01T04:51:55.312163Z app/my-internal-alb/920ec0f816a4179b 10.0.2.89:40756 10.0.4.197:8080 0.000 0.002 0.000 200 200 870 393 "GET http://my-external-alb:8080//wastest.jsp HTTP/1.1" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/98.0.4758.102 Safari/537.36" - - arn:aws:elasticloadbalancing:ap-northeast-1:962262620804:targetgroup/was-tg/e5c5715bb1e2748c "Self=1-621da66b-0469da242e5245106ef54d3f;Root=1-621da66b-4941468f5a7a24c12e0bf018" "-" "-" 0 2022-03-01T04:51:55.307000Z "forward" "-" "-" "10.0.4.197:8080" "200" "-" "-"

 

이 로그 내용을 해석하자면 다음과 같이 정리할 수 있다. Source/Destination 서버와 통신 프로토콜 및 사용한 포트가 제대로 쌓인 것을 볼 수 있다. 

 

- http 프로토콜 통신.
- 2022년 03월 01일 04:51:55 발생. (UTC기준)
- http://my-external-alb:8080//wastest.jsp의 클라이언트 요청 (LB이름은 공개되기 꺼려 수정했다.)
- 'my-internal-alb'로부터 10.0.2.89:40756의 요청이 destination까지 도달함
- destination은 10.04.197:8080
- Mozilla/5.0 웹브라우저를 이용.
- 요청 처리까지 2미리 세컨드 소요됨.
- elb status code는 200으로 성공적으로 요청 반환

 

중요하지 않은 것은 없겠다만 여기서 주목해야 할 것은 elb와 target의 status code 값이 되겠다. 만약 Target 서버로부터 에러코드가 기록됐다면 해당 서버에 운영 중인 어플리케이션 점검이 우선이다. 

 

 

- 400, 404 : Client가 잘못된 요청을 보냈을 때

- 460 : Client로부터 요청을 중간에 끊었을 경우

- 502 : Client의 요청을 로드밸런서가 읽지 못했거나 Target 서버가 TCP RST/FIN을 수신할 경우

- 503 : 사용량 폭증으로 로드밸런서에 과부하게 생겼을 경우 (Scale-Out 되기도 전부터 사용량 급증)

- 504 : Client의 요청이 너무 오래 걸리는 경우, 어떠한 Target 서버가 강제적으로 Client의 요청을 끊을 경우

 

 

만약 Client에서 WAS로 요청을 보냈는데 에러가 발생했다면 각 ELB 로그를 뒤져 보면 된다. External ELB 쪽에서 에러를 반환하고 Internal ELB에서 에러 로그가 발견되지 않는다면 WEB 서버를 의심해 볼 수 있다. Internal ELB에 에러 로그가 발견되다면 이는 WEB에서 WAS까지는 정상적으로 요청을 보냈다는 뜻이고 어떤 이유로 인하여 WAS 서버가 에러를 반환했다는 의미다. 

 

 

만약 사용하는 인프라 환경이 복잡하고 로그도 많이 쌓였다면 Internal ELB에서 보낸 요청을 External ELB 로그에서 찾기 힘들 수도 있다. 시간대를 보면 알 수 있지만 수많은 요청 중 어느 요청이 어느 요청과 이어져 로그가 쌓였는지는 알 수 없다. 이것을 알고 싶다면 위에 내 예제 로그 내용 중 Root 값을 확인하면 알 수 있다. 위의 예시의 경우 그 값이 Root=1-621 da66b...이었다. 그리고 이 로그는 Internal ELB의 로그다. 그렇다면 External ELB도 동일한 Root 값의 로그를 찾으면 된다. 이렇게 수만은 로그를 특정 지어 짝을 찾을 수 있다.

 

 

그리고 이 글을 읽어주는 개발자가 있다면 이 말을 전하고 싶다.

 

 

클라우드 환경에 서비스가 올라갔다고 문제가 생기면 클라우드만 바라볼게 아니라 자신이 구현한 어플리케이션의 로직을 제발 확인했으면 좋겠다. '장애 발생 -> 인프라 점검 -> 이상 무 -> Global Support 문의 후 AWS 서비스 자체 이상 없음 확인 -> 그제야 어플리케이션 로직 확인'이라는 일처리를 너무도 많이 해왔다. 인프라에 변경사항이 없었는데 문제가 발생했다면 어플리케이션 문제일 수도 있겠다는 생각을 했으면 좋겠다.

 

 

 

 

잘못된 부분에 대한 지적은 언제든지 대환영입니다 ;)