✅ MySQL 로그 파일
MySQL 서버의 상태를 진단하는 도구는 정말 많다.
이러한 도구는 높은 지식을 요구하는 경우가 많은데, 로그 파일을 이용한 방법은 높은 지식 없이도 MySQL의 상태나 부하의 원인을 쉽게 찾을 수 있다.
‼️ MySQL 서버에 문제가 발생하면 아래 로그 파일을 우선 확인하는 습관을 키우는 게 좋다.
📌 에러 로그 파일 (Error log)
에러 로그 파일은 MySQL 서버 실행 중 발생하는 에러나 경고 메시지를 기록하는 로그다.
▶︎ 에러 로그 파일 위치
에러 로그 파일의 위치는 MySQL 설정 파일(my.cnf)에서 log-error라는 이름의 파라미터로 정의된 경로에 생성된다.
linux> cat /etc/my.cnf [mysqld] datadir=/var/lib/mysql socket=/var/lib/mysql/mysql.sock # 에러 로그 저장 경로 log-error=/var/log/mysqld.log pid-file=/var/run/mysqld/mysqld.pid
log-error가 지정되지 않으면 datadir 경로에 .err 확장자의 파일로 생성된다설정 파일을 확인한 결과
/var/log/mysqld.log에 에러가 기록되는 것을 확인할 수 있다.
에러 로그는 파일을 직접 확인하는 방법과 쿼리문을 사용하여 확인하는 방법이 있다.
▶︎ 에러 파일로 확인
linux> cat /var/log/mysqld.log ... 2025-08-02T08:07:00.628029Z 0 [Warning] [MY-010075] [Server] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: aad3bceb-6f77-11f0-819a-0800276f12df. mysqld: File '/var/lib/mysql/auto.cnf' not found (OS errno 13 - Permission denied) 2025-08-02T08:07:00.628085Z 0 [ERROR] [MY-010183] [Server] Failed to create file(file: '/var/lib/mysql/auto.cnf', errno 13) 2025-08-02T08:07:00.628089Z 0 [ERROR] [MY-010076] [Server] Initialization of the server's UUID failed because it could not be read from the auto.cnf file. If this is a new server, the initialization failed because it was not possible to generate a new UUID. 2025-08-02T08:07:00.628138Z 0 [ERROR] [MY-010119] [Server] Aborting 2025-08-02T08:07:00.628884Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.4.6) MySQL Community Server - GPL. ...에러 로그 파일의 메시지 형식은 아래와 같다.
[날짜/시간] [스레드ID] [에러 심각도] [에러 코드] [서브시스템] 메시지
▶︎ 쿼리문으로 확인
performance_schema.error_log테이블을 조회해 에러 로그를 확인할 수 있다.mysql> SELECT * FROM performance_schema.error_log\G ... *************************** 9. row *************************** LOGGED: 2025-08-02 17:07:00.628029 THREAD_ID: 0 PRIO: Warning ERROR_CODE: MY-010075 SUBSYSTEM: Server DATA: No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: aad3bceb-6f77-11f0-819a-0800276f12df. *************************** 10. row *************************** LOGGED: 2025-08-02 17:07:00.628085 THREAD_ID: 0 PRIO: Error ERROR_CODE: MY-010183 SUBSYSTEM: Server DATA: Failed to create file(file: '/var/lib/mysql/auto.cnf', errno 13) *************************** 11. row *************************** LOGGED: 2025-08-02 17:07:00.628089 THREAD_ID: 0 PRIO: Error ERROR_CODE: MY-010076 SUBSYSTEM: Server DATA: Initialization of the server's UUID failed because it could not be read from the auto.cnf file. If this is a new server, the initialization failed because it was not possible to generate a new UUID. *************************** 12. row *************************** LOGGED: 2025-08-02 17:07:00.628138 THREAD_ID: 0 PRIO: Error ERROR_CODE: MY-010119 SUBSYSTEM: Server DATA: Aborting *************************** 13. row *************************** LOGGED: 2025-08-02 17:07:00.628884 THREAD_ID: 0 PRIO: System ERROR_CODE: MY-010910 SUBSYSTEM: Server DATA: /usr/sbin/mysqld: Shutdown complete (mysqld 8.4.6) MySQL Community Server - GPL. ...
📌 제너럴 쿼리 로그 파일 (General log)
제너럴 쿼리 로그는 MySQL 서버에서 실행된 모든 SQL 쿼리를 기록하는 로그다.
주로 디버깅이나 쿼리 실행 추적에 활용되며, 모든 쿼리를 기록하기 때문에 스토리지 사용량이 빠르게 증가할 수 있다.
※ 장기간 활성화는 권장되지 않으며, 필요한 경우 일정 시간만 켜고 로그를 백업하는 방식이 좋다.
▶︎ 제너럴 쿼리 로그 활성화
제너럴 쿼리 로그 기록은 기본적으로 OFF로 되어 있다. 만약 제너럴 쿼리 로그 기록을 희망한다면 이를 ON으로 설정해야 한다.
제너럴 쿼리 로그는 기본값이 OFF다. 기록을 활성화하려면 ON으로 설정해야 한다.
[제너럴 쿼리 로그 활성화 확인]
mysql> show global variables like 'general_log'; +---------------+-------+ | Variable_name | Value | +---------------+-------+ | general_log | OFF | +---------------+-------+ 1 row in set (0.00 sec)[제너럴 쿼리 로그 활성화]
mysql> SET GLOBAL general_log = 'ON';
▶︎ 제너럴 로그 파일 위치
제너럴 로그 파일의 위치 정보는 general_log_file 시스템 변수에 설정되어 있다.
mysql> show global variables like 'general_log_file'; +------------------+------------------------------+ | Variable_name | Value | +------------------+------------------------------+ | general_log_file | /var/lib/mysql/localhost.log | +------------------+------------------------------+ 1 row in set (0.00 sec)제너럴 로그 파일 위치 :
/var/lib/mysql/localhost.log
▶︎ 제너럴 로그 파일 확인
linux> cat localhost.log /usr/libexec/mysqld, Version: 8.0.41 (Source distribution). started with: Tcp port: 3306 Unix socket: /var/lib/mysql/mysql.sock Time Id Command Argument 2025-07-19T13:22:18.076585Z 31 Connect admin@localhost on using Socket 2025-07-19T13:22:18.077079Z 31 Query select @@version_comment limit 1 2025-07-19T13:23:22.111796Z 31 Query set default role NONE TO 'dev1_user009' 2025-07-19T13:23:33.647180Z 31 Query set default role ALL TO 'dev2_user009'
📌 슬로우 쿼리 로그 파일 (Slow log) ⭐️
슬로우 쿼리 로그는 설정된 기준 시간보다 오래 걸린 SQL 쿼리를 기록하는 로그다.
주로 성능 튜닝 대상 쿼리를 식별하는 데 활용된다.
▶︎ 슬로우 쿼리 기준 설정
슬로우 쿼리 기준은 long_query_time 시스템 변수로 설정한다.
쿼리문이 5초 이상을 넘어가면 슬로우 쿼리로 지정
mysql> set global long_query_time = 5;
▶︎ 슬로우 쿼리 로그 활성화
슬로우 쿼리 로그는 기본값이 OFF다. 기록을 활성화하려면 ON으로 설정해야 한다.
[슬로우 쿼리 로그 활성화 확인]
mysql> show global variables like 'slow_query_log'; +----------------+-------+ | Variable_name | Value | +----------------+-------+ | slow_query_log | OFF | +----------------+-------+ 1 row in set (0.00 sec)[슬로우 쿼리 로그 활성화]
mysql> SET GLOBAL slow_query_log = 'ON';
▶︎ 슬로우 쿼리 로그 파일 위치
슬로우 쿼리 로그 파일의 위치 정보는 slow_query_log_file 시스템 변수에 설정되어 있다.
mysql> show global variables like 'slow_query_log_file'; +---------------------+-----------------------------------+ | Variable_name | Value | +---------------------+-----------------------------------+ | slow_query_log_file | /var/lib/mysql/localhost-slow.log | +---------------------+-----------------------------------+ 1 row in set (0.00 sec)슬로우 로그 파일 위치 :
/var/lib/mysql/localhost-slow.log
▶︎ 슬로우 쿼리 로그 파일 확인
# Time: 2025-08-12T00:09:04.753866+09:00 # User@Host: root[root] @ localhost [] Id: 13 # Query_time: 8.964597 Lock_time: 0.000011 Rows_sent: 300024 Rows_examined: 36478428 SET timestamp=1754924935; select A.emp_no, max(A.salary) from salaries A left join salaries B on A.emp_no = B.emp_no group by emp_no;
- Time : 쿼리 종료 시점
- User@Host : 쿼리 실행 계정
- Query_time : 쿼리 실행 시간
- Lock_time : 테이블 잠금 대기(잠금 체크 포함) 시간 (MySQL 엔진 레벨)
- Rows_sent : 출력 행(row) 수
- Rows_examined : 쿼리문 처리를 위해 접근된 레코드 수
📌 쿼리 로그 통계(Percona Toolkit) ⭐️
슬로우 쿼리 로그나 제너럴 로그는 쿼리 실행 내역이 방대해 하나씩 검토하기 어렵다.
이때 Percona에서 개발한 Percona Toolkit의 pt-query-digest를 활용하면 쿼리 빈도, 실행 시간, 순위 등을 한눈에 확인할 수 있다.
▶︎ Percona Toolkit 설치
※ Apple Silicon 기반의 macOS에서 VirtualBox로 구동되는 CentOS 9 VM이며, CPU 아키텍처는 x86_64가 아닌 ARM64(aarch64)를 사용하고 있습니다.
이러한 이유로 x86_64 기반이 아닌 ARM64(aarch64)로 진행되었습니다.
[Toolkit 패키지 다운로드]
linux> wget https://downloads.percona.com/downloads/percona-toolkit/3.7.0-2/binary/redhat/9/aarch64/percona-toolkit-3.7.0-2.el9.aarch64.rpm
[Toolkit 패키지 설치]
linux> dnf install percona-toolkit-3.7.0-2.el9.aarch64.rpm
▶︎ Log 통계 파일 생성(With Toolkit)
[Genera Log 파일 분석]
linux> pt-query-digest --type='genlog' /var/lib/mysql/localhost.log > parsed_general.log[Slow Log 파일 분석]
linux> pt-query-digest --type='slowlog' /var/lib/mysql/localhost-slow.log > parsed_slow.log
통계 파일을 생성할 때 아래 옵션을 추가하여 상황에 맞는 통계 파일을 만들 수 있다. (옵션 공식 문서)
--limit=10 : 상위 10개 쿼리만 표시 --order-by=Query_time:sum : 총 실행 시간이 긴 쿼리 순 --filter '($event->{Query_time} > 1)' : 1초 이상 실행된 쿼리만 분석
▶︎ Slow Log 파일 분석 확인
Slow Log 파일 기준으로 살펴보면 아래와 같은 통계자료를 확인할 수 있다.(Genera Log 통계 자료도 Slow Log 통계와 비슷함)
linux> cat parsed_slow.log
# 60ms user time, 20ms system time, 36.60M rss, 256.07M vsz
# Current date: Tue Aug 12 02:24:22 2025
# Hostname: localhost.localdomain
# Files: /var/lib/mysql/localhost-slow.log
# Overall: 7 total, 2 unique, 0.00 QPS, 0.00x concurrency ________________
# Time range: 2025-08-11T14:54:42 to 2025-08-12T02:22:36
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 66s 8s 12s 9s 11s 1s 9s
# Lock time 148us 3us 63us 21us 60us 22us 10us
# Rows sent 1.72M 146.48k 292.99k 251.13k 283.86k 63.47k 283.86k
# Rows examine 180.57M 3.31M 34.79M 25.80M 34.72M 14.25M 34.72M
# Query size 2.14k 106 832 313.43 793.42 312.25 102.22
# Profile
# Rank Query ID Response time Calls R/Call V/M
# ==== =================================== ============= ===== ======= ===
# 1 0x572D37876B7D41AC706E4682C09D17E3 43.0714 65.1% 5 8.6143 0.02 SELECT salaries
# 2 0x190AB0B13E319A2297BAAD68D06FAD5A 23.0921 34.9% 2 11.5460 0.00 SELECT salaries titles dept_emp salaries employees d t
# Query 1: 0.00 QPS, 0.00x concurrency, ID 0x572D37876B7D41AC706E4682C09D17E3 at byte 1115
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.02
# Time range: 2025-08-11T14:54:42 to 2025-08-12T00:09:04
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 71 5
# Exec time 65 43s 8s 9s 9s 9s 406ms 8s
# Lock time 89 132us 3us 63us 26us 60us 24us 10us
# Rows sent 83 1.43M 292.99k 292.99k 292.99k 292.99k 0 292.99k
# Rows examine 96 173.94M 34.79M 34.79M 34.79M 34.79M 0 34.79M
# Query size 24 530 106 106 106 106 0 106
# String:
# Databases employees
# Hosts localhost
# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s ################################################################
# 10s+
# Tables
# SHOW TABLE STATUS FROM `employees` LIKE 'salaries'\G
# SHOW CREATE TABLE `employees`.`salaries`\G
# EXPLAIN /*!50100 PARTITIONS*/
select A.emp_no, max(A.salary) from salaries A left join salaries B on A.emp_no = B.emp_no group by emp_no\G
# Query 2: 0.07 QPS, 0.86x concurrency, ID 0x190AB0B13E319A2297BAAD68D06FAD5A at byte 2970
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.00
# Time range: 2025-08-12T02:22:09 to 2025-08-12T02:22:36
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 28 2
# Exec time 34 23s 11s 12s 12s 12s 99ms 12s
# Lock time 10 16us 5us 11us 8us 11us 4us 8us
# Rows sent 16 292.97k 146.48k 146.48k 146.48k 146.48k 0 146.48k
# Rows examine 3 6.63M 3.31M 3.31M 3.31M 3.31M 0 3.31M
# Query size 75 1.62k 832 832 832 832 0 832
...[1. 쿼리 통계 요약]
전체 쿼리 수, 실행 시간 평균·최대·최소, 잠금 대기 시간 등.# 60ms user time, 20ms system time, 36.60M rss, 256.07M vsz # Current date: Tue Aug 12 02:24:22 2025 # Hostname: localhost.localdomain # Files: /var/lib/mysql/localhost-slow.log # Overall: 7 total, 2 unique, 0.00 QPS, 0.00x concurrency ________________ # Time range: 2025-08-11T14:54:42 to 2025-08-12T02:22:36 # Attribute total min max avg 95% stddev median # ============ ======= ======= ======= ======= ======= ======= ======= # Exec time 66s 8s 12s 9s 11s 1s 9s # Lock time 148us 3us 63us 21us 60us 22us 10us # Rows sent 1.72M 146.48k 292.99k 251.13k 283.86k 63.47k 283.86k # Rows examine 180.57M 3.31M 34.79M 25.80M 34.72M 14.25M 34.72M # Query size 2.14k 106 832 313.43 793.42 312.25 102.22
[2. 쿼리 순위]
응답 시간 비중이 높은 순서대로 정렬.# Profile # Rank Query ID Response time Calls R/Call V/M # ==== =================================== ============= ===== ======= === # 1 0x572D37876B7D41AC706E4682C09D17E3 43.0714 65.1% 5 8.6143 0.02 SELECT salaries # 2 0x190AB0B13E319A2297BAAD68D06FAD5A 23.0921 34.9% 2 11.5460 0.00 SELECT salaries titles dept_emp salaries employees d t
[3. 쿼리 상세 정보]
실행 횟수, 평균 실행 시간, 접근 행 수, 실제 쿼리문.# Query 1: 0.00 QPS, 0.00x concurrency, ID 0x572D37876B7D41AC706E4682C09D17E3 at byte 1115 # This item is included in the report because it matches --limit. # Scores: V/M = 0.02 # Time range: 2025-08-11T14:54:42 to 2025-08-12T00:09:04 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 71 5 # Exec time 65 43s 8s 9s 9s 9s 406ms 8s # Lock time 89 132us 3us 63us 26us 60us 24us 10us # Rows sent 83 1.43M 292.99k 292.99k 292.99k 292.99k 0 292.99k # Rows examine 96 173.94M 34.79M 34.79M 34.79M 34.79M 0 34.79M # Query size 24 530 106 106 106 106 0 106 # String: # Databases employees # Hosts localhost # Users root # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ # Tables # SHOW TABLE STATUS FROM `employees` LIKE 'salaries'\G # SHOW CREATE TABLE `employees`.`salaries`\G # EXPLAIN /*!50100 PARTITIONS*/ select A.emp_no, max(A.salary) from salaries A left join salaries B on A.emp_no = B.emp_no group by emp_no\G ########## 쿼리 빈도/누적 실행 순위에 따른 쿼리 상세 정보 2 ########## # Query 2: 0.07 QPS, 0.86x concurrency, ID 0x190AB0B13E319A2297BAAD68D06FAD5A at byte 2970 # This item is included in the report because it matches --limit. # Scores: V/M = 0.00 # Time range: 2025-08-12T02:22:09 to 2025-08-12T02:22:36 # Attribute pct total min max avg 95% stddev median # ============ === ======= ======= ======= ======= ======= ======= ======= # Count 28 2 # Exec time 34 23s 11s 12s 12s 12s 99ms 12s # Lock time 10 16us 5us 11us 8us 11us 4us 8us # Rows sent 16 292.97k 146.48k 146.48k 146.48k 146.48k 0 146.48k # Rows examine 3 6.63M 3.31M 3.31M 3.31M 3.31M 0 3.31M # Query size 75 1.62k 832 832 832 832 0 832 ...
