MySQL 슬로 쿼리 로그 읽는 법

무엇이 남나

다음을 모두 만족하는 문장이 남습니다.

1. 관리 문장(ALTER TABLE · ANALYZE TABLE · CREATE INDEX · OPTIMIZE TABLE 등)이 아니거나, log_slow_admin_statements 가 켜져 있습니다.
2. long_query_time 초 이상 걸렸거나, log_queries_not_using_indexes 가 켜져 있고 행을 찾는 데 인덱스를 쓰지 않았습니다.
3. min_examined_row_limit 줄 이상을 읽었습니다.
4. log_throttle_queries_not_using_indexes 로 걸러지지 않았습니다.

long_query_time 의 기본값은 10초, 최솟값은 0 이며 마이크로초 단위까지 줄 수 있습니다. 로그는 기본으로 꺼져 있습니다. 최소 설정은 다음과 같습니다.

[mysqld]
slow_query_log      = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time     = 1
log_output          = FILE

파일을 읽을 때 알아 둘 점입니다.

• 처음 잠금을 얻는 시간은 실행 시간에 들어가지 않습니다.
• 문장은 실행을 마치고 잠금을 다 푼 뒤에 쓰이므로, 파일 순서가 실행 순서와 다를 수 있습니다.
• 해석되지 않는 문장(문법 오류)은 남지 않습니다.
• 문장 안의 비밀번호는 평문으로 남지 않게 고쳐 씁니다.
• log_timestamps 가 파일 속 시각의 시간대를 정합니다.

항목 하나, 줄마다

# Time: 2026-10-18T10:41:02.551000Z
# User@Host: report[report] @  [10.0.3.5]  Id:  5102
# Query_time: 12.880415  Lock_time: 0.412003 Rows_sent: 1  Rows_examined: 9120400
SET timestamp=1792320062;
SELECT COUNT(*) FROM order_items WHERE created_at >= '2026-10-01';

위 항목은 한 줄을 돌려주려고 912만 줄을 읽었고, 잠금을 0.4초 기다렸고, 12.9초 걸렸습니다. 이 비율이 가장 먼저 볼 값입니다.

log_slow_extra 를 켜면 늘어나는 칸

log_slow_extra 를 켜면 # Query_time 줄에 문장별 계수가 붙습니다. Thread_id · Errno · Killed · Bytes_received · Bytes_sent, 핸들러 읽기(Read_first · Read_last · Read_key · Read_next · Read_prev · Read_rnd · Read_rnd_next), 정렬 계수(Sort_merge_passes · Sort_range_count · Sort_rows · Sort_scan_count), Created_tmp_disk_tables · Created_tmp_tables · Start · End 입니다. 한 파일에 붙은 줄과 안 붙은 줄이 섞일 수 있으며 칸 수로 구분합니다. 아래 명령은 앞 네 칸만 쓰므로 어느 쪽이든 동작합니다.

읽는 법

문장 모양으로 묶어 Query_time 을 더하는 것이 슬로 로그 요약 도구가 하는 일이며, MySQL 은 이를 위해 mysqldumpslow 를 함께 줍니다. 0.8초짜리라도 하루 5만 번 도는 쿼리가 30초짜리 보고서 한 번보다 중요합니다.

슬로 쿼리 로그용 한 줄 명령

# Query_time 줄은 $3 = Query_time, $5 = Lock_time, $7 = Rows_sent, $9 = Rows_examined 로 나뉩니다. 모두 항목 여러 개가 든 표본 파일로 실행해 확인했습니다.

• 파일에 문장이 몇 개인가

  grep -c '^# Query_time' slow.log

  복사

• 1초 넘게 걸린 문장은 몇 개인가

  awk '/^# Query_time/ && $3 > 1' slow.log | wc -l

  복사

• 문장 수와 실행 시간 합계

  awk '/^# Query_time/ {s += $3; n++} END {printf "%d statements, %.1f s total\n", n, s}' slow.log

  복사

• 가장 느린 문장과 SQL 첫 줄

  awk '/^# Query_time/ {qt = $3; next} /^(#|SET timestamp|use )/ {next} qt != "" {print qt, $0; qt = ""}' slow.log | sort -rn | head

  복사

• 보낸 한 줄당 읽은 줄 수, 나쁜 순

  awk '/^# Query_time/ && $7 > 0 {printf "%d %s/%s\n", $9/$7, $9, $7}' slow.log | sort -rn | head

  복사

• 잠금 대기가 0.1초를 넘는 문장

  awk '/^# Query_time/ && $5 > 0.1 {print $5, $3}' slow.log | sort -rn

  복사

• 느린 문장을 내는 계정

  awk '/^# User@Host/ {print $3}' slow.log | sort | uniq -c | sort -rn

  복사

• 느린 문장을 내는 클라이언트 주소

  grep '^# User@Host' slow.log | grep -oE '\[[0-9.]+\]' | sort | uniq -c | sort -rn

  복사

• 문장 첫 줄의 모양으로 묶기 — 리터럴을 ? 와 N 으로 바꿈

  awk '/^SET timestamp/ {getline; print}' slow.log | sed -E "s/'[^']*'/?/g; s/[0-9]+/N/g" | sort | uniq -c | sort -rn | head

  복사

• 시간당 항목 수(log_timestamps 가 다르게 정하지 않으면 UTC)

  grep '^# Time:' slow.log | cut -c9-21 | uniq -c

  복사