ALB 액세스 로그가 꺼져 있으면 야간 트래픽 9.5배도 못 읽는다

야간 요청이 주간의 9.5배인데 이유를 몰랐다. 크롤러인지 배치인지 공격인지 알아야 하는데, ALB 액세스 로그가 전부 꺼져 있어서 발신 IP도 User-Agent도 남지 않았다. 켜지 않은 로그는 나중에 소급해서 볼 수 없다. 꺼져 있다는 사실 자체가 리스크다. 그리고 이 편의 대부분은 켠 다음에 잘못 읽은 이야기다. 관측은 켜는 것보다 읽는 게 더 자주 틀린다.

출발점 — 이유를 모르는 야간 피크

지표를 보다 이상한 걸 발견했다. 야간 요청이 주간의 9.5배였고, 특정 서비스 하나는 111배 흔들렸다.

크롤러인지, 배치인지, 공격인지 알아야 하는데 알 방법이 없었다. ALB 액세스 로그가 전부 꺼져 있었기 때문이다. 발신 IP도 User-Agent도 남지 않았다.

여기서부터 한 달 가까이 "안 보이던 것을 켜는" 작업을 했다. 액세스 로그, 느린 쿼리 로그, 향상된 모니터링, APM, 감사 로그.

액세스 로그를 켜다 ALB 두 대를 죽였다

Terraform으로 ALB 액세스 로그를 켰는데 이걸로 실패했다.

Access Denied for bucket

정책이 틀렸나 싶어 한참 정책만 봤다. 정책은 맞았다.

원인은 의존성이다. ALB의 access_logs.bucket에 버킷을 직접 참조하면, 버킷 정책과 ALB 사이에 의존 관계가 없어서 둘이 병렬로 돈다. ELB가 쓰기 권한을 검증할 때 정책이 아직 안 만들어져 있으면 거부된다.

# 이렇게 두면 정책 → ALB 순서가 강제된다
access_logs {
  bucket = aws_s3_bucket_policy.logs.bucket
}

이름은 버킷을 가리키지만, 참조 대상이 정책 리소스라는 게 핵심이다. depends_on 없이 순서를 만드는 흔한 방법인데, 모르면 원인을 정책에서 찾게 된다.

다른 리전 코드에는 이 이유가 주석으로 남아 있었다. 코드를 옮겨 오면서 놓쳤다. 주석을 지우고 옮기면 그 지식도 같이 사라진다.

04시 배치의 정체 — 두 쿼리가 45분을 채웠다

느린 쿼리 로그(long_query_time=1)를 켜고 나서 04시대를 봤다.

04:00~04:45 구간 느린 쿼리 97건, 합계 2,726초

45분짜리 벽시계를 두 쿼리가 거의 전부 채우고 있었다. 원인은 보조 인덱스가 없어서 조인 안쪽이 매번 점포 전체를 훑는 것이었다.

인덱스를 넣자 지연이 사라졌다. 문제 자체는 평범한데, 찾는 과정이 계속 틀렸다.

로그 파일명은 내용 시각이 아니다

RDS 느린 쿼리 로그의 파일명 접미사는 회전 시각이다.

mysql-slowquery.log.2026-08-12.20   ← 안에 든 건 19:35~19:45 UTC 항목

한 시간 밀려 보인다. 게다가 내용의 # Time:은 UTC라 04시 KST 배치는 전날 19시대에서 찾아야 한다.

두 번 어긋나니 "그 시간대에 느린 쿼리가 없다"는 결론이 쉽게 나온다.

로그 조회 API는 기본이 "최신 부분"이다

aws rds download-db-log-file-portion ...

marker 없이 부르면 최신 부분만 준다. 앞이 잘린 걸 모르면 배치 시작 시각을 잘못 읽는다. --starting-token 0으로 처음부터 페이지네이션해야 한다.

상대 시각으로 조회하면 시간대를 잘못 읽는다

CloudWatch를 now-12h 같은 상대 시각으로 조회하면 버킷 경계가 어긋난다. 04:00에 시작하는 이벤트가 03:48로 보였다.

시각을 따지는 조회에서는 시작 시각을 정각으로 고정한다.

압축 로그를 0줄로 읽을 뻔했다

macOS의 zcat은 파일명에 .Z를 붙여 찾는다.

$ zcat access.log.gz
zcat: access.log.gz.Z: No such file

결과가 조용히 0줄이 된다. 모아 둔 ALB 로그를 통째로 "아무것도 없음"으로 읽을 뻔했다. gunzip -c를 쓴다.

숫자처럼 생겼는데 문자열인 것

ALB 규칙의 Priority는 문자열이다. JMESPath에서

Priority==`4`     → 항상 0건
Priority=='4'     → 맞음

틀렸다는 신호가 없다. 그냥 "그런 규칙이 없다"로 읽힌다.

그리고 EXPLAIN을 믿지 않는다

MySQL 옵티마이저 통계가 크게 어긋나 있을 수 있다.

EXPLAIN 추정   280 행
실측        363,719 행     ← 1,300배

이 오판이 조인 순서를 뒤집어 놓는다. rows는 사실이 아니라 추정이다.

APM — 프로세스가 살아 있어도 수집은 죽을 수 있다

APM(Scouter)을 양쪽 계정에 깔면서 겪은 것들이다.

이름 공간이 전역이라 객체가 사라졌다

호스트 에이전트의 obj_name은 전역 이름 공간이다. 클라이언트가 여러 collector를 볼 때 서버 구분은 화면 그룹일 뿐이고, 객체는 이름으로 식별된다.

양쪽 계정이 둘 다 admin을 쓰자 한쪽 객체가 화면에서 사라졌다. 서버는 멀쩡했고 클라이언트에서만 합쳐진 것이라 원인을 찾기 어려웠다.

계정 접두어를 붙여 a-prod-admin / b-prod-admin으로 갈랐다.

-javaagent는 -jar 앞에 와야 한다

뒤에 두면 JVM 옵션이 아니라 애플리케이션 인자로 넘어간다. Spring Boot가 모르는 인자라 에러도 안 나고 에이전트만 안 붙는다.

반대로 없는 jar를 가리키면 JVM이 아예 안 뜬다(Error opening zip file). 조용히 실패하거나 요란하게 실패하거나 둘 중 하나라, 중간이 없다.

설정 파일 로딩 규칙이 컴포넌트마다 다르다

• collector·host agent → CWD 기준 ./conf/scouter.conf (systemd WorkingDirectory 필수)
• java agent → 에이전트 jar 디렉터리 기준 (-Dscouter.config=)

같은 제품인데 다르다. 이걸 모르면 "설정을 넣었는데 안 먹는다"가 된다.

프로세스 생존 ≠ 수집 정상

collector가 떠 있고 알림도 나가는데 디스크 쓰기만 실패하는 상태가 실재한다. systemd로는 못 잡는다.

날짜 디렉터리와 최근 쓰기 시각을 주기적으로 확인하는 수밖에 없다. "떠 있으니 되겠지"가 가장 위험한 가정이다.

웹 UI는 껐다

배포본 기본값이 HTTP 서버(6180)를 자동으로 켠다. 그런데 인증이 없다. 터널을 열 수 있는 사람이면 누구나 전 구간 데이터를 본다.

껐는데 안 꺼졌다. scouter.conf에 net_http_server_enabled=false를 넣어도 별도 XML 설정이 다시 켠다. 두 군데를 다 꺼야 했다.

에이전트 디렉터리는 root 소유로 뒀다. 앱은 읽기만 하면 되고, 앱 계정 소유면 앱이 침해됐을 때 에이전트 jar를 바꿔칠 수 있다.

정리

• 켜지 않은 로그는 나중에 소급해서 볼 수 없다. 꺼져 있다는 사실 자체가 리스크다.
• ALB 액세스 로그는 access_logs.bucket에 정책 리소스를 참조해 순서를 만든다.
• RDS 로그 파일명은 회전 시각, 내용은 UTC. 두 번 어긋난다.
• zcat, JMESPath 백틱, 상대 시각 — 틀리면 0건으로 조용히 나온다.
• EXPLAIN의 rows는 추정이다. 1,300배 틀릴 수 있다.
• 프로세스가 살아 있는 것과 수집이 되는 건 다른 얘기다.

다음 편은 DB다. 리더를 붙이고 메이저 업그레이드를 했는데, 되돌릴 수 없는 작업 앞에서 자동 스냅샷을 믿으면 안 된다는 걸 알았다.