MariaDB: Slow Query Log 설정

MariaDB에서 Slow Query Log 설정을 할 경우 Mariadb 10.2 버전부터 etc/my.cnf.d/ 폴더안에 mysql-clients.cnf 및 server.cnf 파일로 나뉘게 되었습니다. mysql 이라도 폴더를 확인한 후에 설정 내역에 따라 확인하면 되겠습니다.

먼저 etc/my.cnf.d/server.cnf 파일에 적용하는 방법에 대해 알아 보겠습니다.

※ Slow Query
Slow Query는 수행하는 데 오랜 시간이 걸리는 쿼리입니다. 응답 시간이 길어질 경우 서비스의 품질이 저하되기 때문에 Slow Query Log를 설정해서 지속적인 모니터링을 통해 개선이 필요한 사항 중 하나입니다.

✅ Slow Query Log 설정하기

MariaDB Slow Query Log 참조하기

vi /etc/my.cnf.d/server.cnf

# This group is read by both MariaDB and MySQL servers
[mariadb]    ## [mariadb] 설정 아래가 아닐 경우 에러 발생이 됩니다.
[mysqld]  ## 설정 아래가 아닐 경우 에러 발생이 됩니다.
slow_query_log=1  ## 1은 ON 0은 OFF 
## 슬로우 쿼리 로그의 경로 설정 후 임의 IP 주소로 이름 설정되거나 파일명 같이 생성
slow_query_log_file=/var/lib/mysql/mariadb-slow.log
long_query_time=1  ## 1초를 초과하는 쿼리에 대해 기록 한다는 것 | 테스트를 위해 0.001 초 등으로 설정이 가능.
log_slow_rate_limit=5  ## 슬로우 쿼리 최대 실행 시간 설정
:wq

ll /var/lib/mysql/
-rw-rw----. 1 mysql mysql    425984 Feb 13 15:10 aria_log.00000001
-rw-rw----. 1 mysql mysql        52 Feb 13 15:10 aria_log_control
-rw-rw----  1 mysql mysql         9 Feb 13 15:10 ddl_recovery.log
-rw-rw----  1 mysql mysql       790 Feb 13 15:10 ib_buffer_pool
--- 생략 ---
-rw-rw----  1 mysql mysql       286 Feb 13 15:10 ip-172-31-11-71-slow.log
--- 생략 ---

vi ip-172-31-11-71-slow.log

ip-172-31-11-71-slow.log(서버 IP) 파일로 Slow Query Log를 열어서 확인할 수 있습니다.

✅쿼리 로그 만들기(테스트 위한)


MariaDB [(none)]> select sleep(60);
+-----------+
| sleep(60) |
+-----------+
|         0 |
+-----------+
1 row in set (1 min 0.000 sec)

설정 내역 확인

MariaDB [(none)]> show variables like 'slow_query_%';
+---------------------+-------------------------------+
| Variable_name       | Value                         |
+---------------------+-------------------------------+
| slow_query_log      | ON                            |
| slow_query_log_file | /var/lib/mysql/slow-query.log |
+---------------------+-------------------------------+
2 rows in set (0.001 sec)

✅ Slow Query Log 확인하기

use iamroot;
select max(wr_comment) as max_comment from g4_write_ja
                  where wr_parent = '92' and wr_is_comment = 1;
# Time: 120809 16:08:15
# User@Host: iamroot[iamroot] @  []
# Query_time: 253  Lock_time: 0  Rows_sent: 1  Rows_examined: 419562
select max(wr_comment) as max_comment from g4_write_ja
                  where wr_parent = '92' and wr_is_comment = 1;
# Time: 120809 16:08:17
# User@Host: iamroot[iamroot] @  []
# Query_time: 94  Lock_time: 0  Rows_sent: 0  Rows_examined: 640675
use iamroot;
SELECT count(*) from comment where boardcode=1045552594 and boardidx=274;
# Time: 120809 16:08:23
# User@Host: iamroot[iamroot] @  []
# Query_time: 183  Lock_time: 0  Rows_sent: 1  Rows_examined: 268576

-------------------------------------------------------------------------------------------------
로그 내용 중 각 항목에 대한 설명은 아래와 같습니다.

# Query_time: 2.906063  Lock_time: 0.000026  Rows_sent: 0  Rows_examined: 133323
Query_time : 쿼리 수행시간 
Lock_time : 테이블 LOCK 이 걸린시간
Row_sent : 쿼리 처리 결과 ROW 수
Rows_examined : 쿼리 처리 대상의 ROW 갯수

✅ Slow Query 빠르게 중단 시키기

슬로우 쿼리로 인해 Load Average가 올라갈 경우 먼저 ps -ef 명령어로 DB 관련 PID를 kill 시킨 후 슬로우 쿼리를 점검 해 보면 되겠습니다.

mysql> SHOW PROCESSLIST;
+----+--------+--------------+---------+---------+------+-------+-------------
| Id | User   | Host         | db      | Command | Time | State | Info        
+----+--------+--------------+---------+---------+------+-------+-------------
|  5 | root   | localhost    | STARPL3 | Query   | 2048 | init  | INSERT INTO
| 13 | root   | localhost    | NULL    | Query   |    0 | NULL  | show processlist
| 14 | lapoly | Canopus:3750 | STARPL3 | Sleep   |  160 |       | NULL        
| 15 | lapoly | Canopus:3751 | NULL    | Sleep   |  386 |       | NULL        
+----+--------+--------------+---------+---------+------+-------+-------------

mysql> KILL 5