서비스가 갑자기 느려졌는데 어떤 쿼리가 범인인지 모를 때가 있습니다. 애플리케이션 로그에는 "DB가 느리다"는 정황만 보이고 정작 어떤 SQL이 문제인지는 안 나옵니다. 이럴 때 가장 먼저 켜야 할 것이 슬로우 쿼리 로그입니다. 설정한 시간보다 오래 걸린 쿼리를 MySQL이 직접 파일에 기록해 줍니다.
어떤 쿼리가 기록되는가
슬로우 쿼리 로그는 세 가지 기준으로 동작합니다.
| 변수 | 의미 | 권장 시작값 |
|---|---|---|
slow_query_log | 로그 기능 on/off | ON |
long_query_time | 이 초보다 오래 걸리면 기록 | 1 (초) |
log_queries_not_using_indexes | 인덱스 안 탄 쿼리도 기록 | ON (초기 진단 시) |
long_query_time을 1로 잡으면 1초 넘는 쿼리만 잡힙니다. 처음에는 넉넉히 잡았다가, 굵직한 것을 잡은 뒤 0.5, 0.1로 점점 내려가며 잔챙이를 훑는 방식이 좋습니다.
로그 켜기 (재시작 없이)
운영 중인 서버라면 재시작 없이 동적으로 켤 수 있습니다.
SQL
SET GLOBAL slow_query_log = 'ON';
SET GLOBAL long_query_time = 1;
SET GLOBAL log_queries_not_using_indexes = 'ON';
단, 이미 연결된 세션에는 long_query_time이 적용되지 않으니 새로 접속해서 확인합니다. 영구 적용하려면 my.cnf에 박아 둡니다.
TEXT
[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 1
log_queries_not_using_indexes = 1
현재 설정과 로그 위치는 이렇게 확인합니다.
SQL
SHOW VARIABLES LIKE 'slow_query%';
SHOW VARIABLES LIKE 'long_query_time';
로그를 분석하는 순서
- 로그가 쌓이는지 확인 — 부하 시간대에
slow.log파일 크기가 커지는지 봅니다. 안 커지면 설정이 새 세션에 안 먹은 것입니다. - 개별 항목 읽기 — 각 항목에는
Query_time,Rows_examined,Rows_sent가 붙습니다.Rows_examined가Rows_sent보다 압도적으로 크면 검사한 행은 많은데 실제 반환은 적다는 뜻이라 인덱스 누락 신호입니다. - 집계로 우선순위 매기기 — 로그를 사람이 한 줄씩 읽으면 끝이 없습니다.
pt-query-digest로 패턴별 집계를 냅니다.
로컬 터미널
pt-query-digest /var/log/mysql/slow.log | head -50
이 도구는 비슷한 쿼리를 묶어 총 소요 시간이 큰 순서로 정렬해 줍니다. 한 번에 10초 걸리는 쿼리보다, 0.5초짜리가 하루 10만 번 도는 쿼리가 더 큰 범인인 경우가 많은데 이런 누적 비용을 한눈에 보여 줍니다.
요점 정리
slow_query_log,long_query_time,log_queries_not_using_indexes세 변수로 시작한다.- 동적 설정은 새 세션부터 적용되니 재접속해서 확인한다.
Rows_examined가Rows_sent보다 크게 많으면 인덱스 누락 의심.- 로그를 직접 읽기보다
pt-query-digest로 누적 비용 큰 순서로 정렬해 본다.
슬로우 쿼리 로그를 켜고 실제 느린 쿼리를 잡아 EXPLAIN으로 원인을 파고드는 실습은 데이터베이스 트랙에서 회원가입 없이 무료로 할 수 있습니다.