MySQL강좌17편: MYSQL 로그를 통한 MYSQL튜닝 실무

MySQL강좌17편: MYSQL 로그를 통한 MYSQL튜닝 실무

 

 

 

오랜시간 동안 리눅스서버와 함께해온 필자는 다음과 같은 사실을 알게되었다. 필자 주변에 있는 많은 리눅스 서버관리자들을 보면 APACHE나 FTP등과 같은 로그관리는 아주 적극적으로 하면서 MYSQL의 로그에 대해서는 너무 무관심한 경우를 흔하게 볼 수 있다.  MYSQL의 로그를 잘 활용하면 MYSQL의 문제해결뿐아니라 튜닝까지도 할 수 있다는 것을 아는 분은 그다지 많지 않다는 것을 알게되었다. 이에 필자는 MYSQL의 로그를 튜닝이라는 관점에서 설명하고자 한다. 즉 MYSQL뿐아니라 다른 모든 어플리케션의 경우도 그렇지만 로그파일의 활용가치는 에러원인의 결정적인 단서를 제공할 수 있으며 이를 이용하면 MYSQL의 성능과 안정성을 위한 튜닝까지도 쉽게 할 수 있다.

 

MYSQL에는 용도별도 다양한 로그파일을 활용할 수 있다. 필자의 경우 “mysqld_safe &”를 실행하였으나 실행되지 않았을 경우 그 원인을 파악하기 위하여 가장 먼저 확인하는 것이 MYSQL의 메인로그파일(에러로그파일)이다.  필자의 경험으로 보아 에러로그파일에서 에러원인의 90%는 거의 찾을 수 있었다. 이와같이 로그파일의 분석만 잘 해도 장애나 에러원인 분석시간을 굉장히 단축할 수 있다.

 

이번 절에서는 MYSQL의 주된 로그파일에 대해서 설명하도록 하겠다. 이어서 설명하는 BINARY로그, QUERY로그, SLOW로그도 모두 읽어보기 바란다.

 

 

1.MYSQL 주로그(에러로그)파일 관리하기

 

먼저, MYSQL을 다음과 같이 실행하면 MYSQL의 주로그가 데이터디렉토리에 호스트이름으로 생성되어 MYSQL의 시작과 종료등에 대한 로그기록과 장애원인등에 대해서 기록하게 된다.  MYSQL의 주로그는 특별한 옵션없이 그냥 기본으로 생성되어 기록되므로 로그기록을 위한 옵션이 존재하지 않는다.  다음은 /usr/local/mysql/bin/디렉토리에 있는 “mysqld_safe &”명령으로 MYSQL을 실행하였다.

 

[root@sulinux bin]#/usr/local/mysql/bin/mysqld_safe & [1] 3908 [root@sulinux bin]#090429 02:17:19 mysqld_safe Logging to '/usr/local/mysql/data/sulinux.net.err'. 090429 02:17:20 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data   [root@sulinux bin]#

 

위와같이 실행하면 MYSQL의 데이터가 저장되는 디렉토리, 즉 필자의 경우 /usr/local/mysql/data/에는 “호스트명.err”으로된 MYSQL 메인로그(에러로그)가 생성되어 MYSQL의 시작/종료/장애등에 대한 로그와 에러원인등을 기록한다.

 

다음은 현재 필자가 사용하고 있는 리눅스 서버의 호스트명을 확인하기 위하여 hostname을 실행한 것이다.  아래 확인해보는 바와같이 현재 서버의 호스트명은 “sulinux.net”이다.

 

[root@sulinux bin]#hostname sulinux.net [root@sulinux bin]#

 

따라서 /usr/local/mysql/data/디렉토리에는 “sulinux.net.err”이라는 MYSQL 주로그(에러로그)가 생성되어 기록될 것이다. 다음은 /usr/local/mysql/data/디렉토리의 에러로그파일을 확인한 것이다.

 

[root@sulinux data]#pwd /usr/local/mysql/data [root@sulinux data]# [root@sulinux data]#ls -l *.err -rw-rw---- 1 mysql mysql 5914  4월 29 02:17 sulinux.net.err [root@sulinux data]#

 

실무적인 예를들어본다면 필자의 경우 어떤 문제에 대한 원인분석을 위하여 “tail -f /usr/local/mysql/data/sulinux.net.err”이라는 실시간 로그감시 터미널을 실행한 후에 MYSQL을 실행하거나 종료하면서 문제원인을 손쉽게 확인하곤 한다.

 

 

2.MYSQL의 쿼리로그를 남기려면

 

앞의 예에서 보았던 MYSQL의 주로그(에러로그)에는 웹프로그램이나 MYSQL접속후에 사용되는 SQL쿼리(Query)에 대한 로그는 기록되지 않는다.  만약 쿼리로그를 기록하게 된다면 로그의 크기가 순식간에 커질 수 있으며, 어느 순간에 파일시스템이 꽉 차버리는 시스템장애가 발생할지도 모르기 때문에 MYSQL에서 SQL쿼리로그는 필요할 경우에만 지정된 로그파일에 기록할 수 있도록 선택적으로 사용할 수 있다.

 

MYSQL데이터베이스를 사용하는 프로그래머의 입장에서 본다면 SQL쿼리로그가 종종 필요할 경우가 있을 것이다. 이때 서버관리자에게 SQL쿼리로그를 기록하게 해달라고 요청할 것이며 이런 경우에 서버관리자의 입장에서 “네, 알겠습니다.’라고 준비된 대답을 할 수 있어야 할 것이다.  아래 설명을 참고하여 그 답을 준비하도록 하자.

 

MYSQL 쿼리로그를 기록하려면 “mysqld_safe”으로 MYSQL을 실행하실 때에 다음과 같은 옵션을 추가로 사용하면 된다.

 

쿼리로그옵션형식 : --log=쿼리로그파일명

 

위와같이 쿼리로그의 형식을 사용하면 MYSQL의 데이터디렉토리 (예 : /usr/local/mysql/data/)에 “쿼리로그파일명”으로 지정된 로그파일이 생성되며 SQL쿼리로그를 기록하게 된다.  만약 위의 형식에서 “쿼리로그파일명”을 생략하고 “--log”라고만 한다면 “호스트명.log”라는 파일명으로 쿼리로그가 기록될 것이다.

 

아래의 예는 /usr/local/mysql/data/디렉토리에서 쿼리로그를 기록하기위하여 아래와 같이 실행한 것이다.

 

[root@sulinux data]#/usr/local/mysql/bin/mysqld_safe --log=MYSQL_QUERY_LOG & [1] 4006 [root@sulinux data]#090429 02:19:33 mysqld_safe Logging to '/usr/local/mysql/data/sulinux.net.err'. 090429 02:19:34 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data   [root@sulinux data]#

 

즉 위의 예에서 쿼리로그파일명으로 MYSQL_QUERY_LOG라고 지정하였기 때문에 /usr/local/mysql/data/디렉토리에는 MYSQL_QUERY_LOG라는 파일명이 생성되어 쿼리로그를 기록할 것이다.

 

다음은 /usr/local/mysql/data/디렉토리에서 위의 예에서 지정한 쿼리로그파일을 확인한 것이다. 그 내용을 보면 사용한 쿼리들이 기록되어있다는 것을 알 수 있다.

 

[root@sulinux data]#ls -l /usr/local/mysql/data/MYSQL_QUERY_LOG -rw-rw---- 1 mysql mysql 179  4월 29 02:19 /usr/local/mysql/data/MYSQL_QUERY_LOG [root@sulinux data]# [root@sulinux data]#cat /usr/local/mysql/data/MYSQL_QUERY_LOG /usr/local/mysql/libexec/mysqld, Version: 5.1.32-log (Source distribution). started with: Tcp port: 3306  Unix socket: /tmp/mysql.sock Time                 Id Command    Argument 090429  2:20:28    1 Connect    tempuser@localhost on temp_db2                     1 Query     xit exit 090429  2:20:29    1 Quit 090429  2:20:37    2 Connect    root@localhost on mysql                     2 Query     select @@version_comment limit 1 090429  2:20:42    2 Query      show databases 090429  2:20:50    2 Query      select * from user 090429  2:20:52    2 Query      select * from db 090429  2:20:59    2 Query      select * from db where user='root' [root@sulinux data]#

 

참고로 MYSQL의 로그파일을 특별한 위치에 저장하고자 한다면 다음과 같이 디렉토리경로와 함께 MYSQL을 시작하면 된다.

 

[root@sulinux bin]# ./mysqld_safe --log=/디렉토리경로/MYSQL_QUERY_LOG &

 

위와같이하면 지정된 “/디렉토리경로/에 “MYSQL_QUERY_LOG”파일이라는 쿼리로그파일을 저장하게될 것이다.

 

 

3.MYSQL 바이너리(BINARY)로그 파일 활용

 

다음은 MYSQL의 데이터가 변경될 때에 그 내역을 기록하는 바이너리로그에 대한 설명이다. 예전에는 MYSQL의 insert, update, delete쿼리에 의해 변경된 데이터를 UPDATE로그라고 하여 텍스트형태로 기록하였다. 하지만 현재는 MYSQL자체 보안과 실행속도 향상을 위하여 바이너리(BINARY)형태로 기록을 하며 로그파일명 또한 BINARY로그라고 부르고있다. 사실 바이너리로그는 DB서버의 부하분산을 위하여 Master DB서버를 Slave DB서버와 Replication하기 위한것이 주목적이다. 그래서 이 로그를 바이너리로그 또는 업데이트로그라고도 하지만 Replication로그라고도 한다. 참고로 알아두기 바란다. 즉 Masterr DB서버에서 insert, update, delete쿼리에 의해 변경된 데이터들을 Slave DB서버에서 이를 가져가서 적용하기 위한 목적으로 사용된 것이다.

 

즉 MYSQL의 바이너리(BINARY) 로그파일은 MYSQL의 변경된 데이터내역을 기록하기 위한 목적으로 사용되며 다른 로그파일과는 달리 텍스트형태가 아닌 BINARY로 기록하는 이유는 로그를 기록하는 속도를 향상시켜 실행속도를 빠르게하기 위한 것과 데이터의 변경기록을 아무나 볼 수 없도록하여 자체보안을 위한 것이 그 목적이라고 할 수 있다.

 

. 바이너리로그 옵션형식  : --log-bin=바이너리로그파일명

. 바이너리로그 보는 방법 : /usr/local/mysql/bin/mysqlbinlog 명령어 사용

 

위와같이 바이너리로그의 형식을 사용하면 MYSQL의 데이터디렉토리 (예 : /usr/local/mysql/data/)에 “바이너리로그파일명”으로 지정된 바이너리로그파일이 생성되며 MYSQL데이터의 변경내역을 기록한다. 그리고 설명한 바와같이 바이너리로그는 vi나 cat등으로 확인할 수 없기 때문에 /usr/local/mysql/bin/mysqlbinlog라는 명령어를 이용하여 확인할 수 있다.

 

다음은 /usr/local/mysql/bin/디렉토리에서 바이너리로그를 기록하기위하여 아래와 같이 실행한 것이다.

 

[root@sulinux data]#/usr/local/mysql/bin/mysqld_safe --log-bin=MYSQL_BINARY_LOG & [1] 4117 [root@sulinux data]#090429 02:22:42 mysqld_safe Logging to '/usr/local/mysql/data/sulinux.net.err'. 090429 02:22:42 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data   [root@sulinux data]#

 

즉 위의 예에서 바이너리로그파일명으로 MYSQL_BINARY_LOG라고 지정하였기 때문에 /usr/local/mysql/data/디렉토리에는 MYSQL_BINARY_LOG라는 파일명이 생성되어 바이너리로그를 기록할 것이다.

 

다음은 /usr/local/mysql/data/디렉토리에서 위의 예에서 지정한 바이너리로그를 확인한 것이다.

 

[root@sulinux data]#ls -l /usr/local/mysql/data/MYSQL_BINARY_LOG.* -rw-rw---- 1 mysql mysql 106  4월 29 02:22 /usr/local/mysql/data/MYSQL_BINARY_LOG.000001 -rw-rw---- 1 mysql mysql  26  4월 29 02:22 /usr/local/mysql/data/MYSQL_BINARY_LOG.index [root@sulinux data]# [root@sulinux data]#file /usr/local/mysql/data/MYSQL_BINARY_LOG.* /usr/local/mysql/data/MYSQL_BINARY_LOG.000001: MySQL replication log /usr/local/mysql/data/MYSQL_BINARY_LOG.index:  ASCII text [root@sulinux data]#

 

참고로 MYSQL의 바이너리파일을 특별한 위치에 저장하고자 한다면 다음과 같이 디렉토리경로와 함께 MYSQL을 시작하면 된다.

 

[root@sulinux bin]# ./mysqld_safe --log-bin=/디렉토리경로/MYSQL_BINARY_LOG &

 

위와같이하면 지정된 “/디렉토리경로/에 “MYSQL_BINARY_LOG”파일이라는 바이너리로그파일이 저장될것이다.

 

거듭 말하거니와 이 로그파일을 확인하는 것은 mysqlbinlog라는 다음 유틸리티를 이용하면 그 내용을 확인할 수 있다.

 

[root@sulinux data]#ls -l /usr/local/mysql/bin/mysqlbinlog -rwxr-xr-x 1 root root 1395582  4월 15  2011 /usr/local/mysql/bin/mysqlbinlog [root@sulinux data]#

 

 

4.SLOW로그파일을 활용한 지정된 시간이상 질의를 계속하는 질의문 잡아내기

 

이번에 설명드릴 MYSQL의 로그파일은 MYSQL 질의속도에 대해 튜닝하기 위한 결정적인 단서를 잡을 수 있는 아주 훌륭한 방법이 될 수 있다. 즉  MYSQL의 질의에 대한 응답속도가 현저하게 떨어지거나 MYSQL 데이터베이스와 연동되는 특정 웹프로그램이 시스템자원을 현저하게 많이 차지하는 등의 문제가 발생하였다면 이번 예에서 설명드리는 SLOW로그에서 어떤 웹프로그램이 문제인가를 파악해보기 바란다.

 

즉 SLOW로그란 MYSQL의 환경변수인 “long_query_time”의 설정시간(초단위) 이상의 쿼리시간을 가지는 특정SQL 쿼리문에 대한 로그만을 기록하는 로그파일이다.

 

따라서 SLOW로그파일을 활용한다면 어떤 웹프로그램이 쿼리시간(실행시간)을 많이 차지하는가를 확인 할 수 있다.  즉  어느날 갑자기 MYSQL의 응답속도가 현저하게 떨어진다면 SLOW로그로 쿼리응답속도가 일정시간 이상 지속되는 쿼리문을 찾아서 조치하면 될 것이다.

 

SLOW쿼리옵션형식 :  --log-slow-queries=슬로우쿼리파일명

 

아래는 이와 같은 MYSQL의 SLOW로그파일의 활용에 대한 설명이다.

 

먼저, /usr/local/mysql/bin/디렉토리에서 “mysqld_safe”으로 MYSQL을 실행시킬 때에  “--log-slow-queries=”옵션을 사용하여 SLOW쿼리로그를 기록하도록 지정하였다.

 

[root@sulinux data]#/usr/local/mysql/bin/mysqld_safe --log-slow-queries=SLOW_QUERY_LOG & [1] 4228 [root@sulinux data]#090429 02:26:46 mysqld_safe Logging to '/usr/local/mysql/data/sulinux.net.err'. 090429 02:26:46 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data   [root@sulinux data]#

 

즉 위의 예에서 SLOW로그파일명으로 SLOW_QUERY_LOG라고 지정하였기 때문에 /usr/local/mysql/data/디렉토리에는 SLOW_QUERY_LOG라는 파일명이 생성되어 SLOW쿼리로그를 기록할 것이다.

 

다음은 /usr/local/mysql/data/디렉토리는 위의 예에서 지정한 SLOW쿼리로그를 확인한 것이다.

 

[root@sulinux data]#ls -l /usr/local/mysql/data/SLOW_QUERY_LOG -rw-rw---- 1 mysql mysql 179  4월 29 02:26 /usr/local/mysql/data/SLOW_QUERY_LOG [root@sulinux data]#

 

그리고 위의 “SLOW_QUERY_LOG”파일에는 MYSQL의 환경변수 “long_query_time”에 초단위로 지정된 시간보다 초과하는 쿼리문만을 기록한다. 아래는 MYSQL의 환경변수 “long_query_time”의 값을 확인하는 방법을 나타낸 것이다. 즉 mysqladmin이라는 MYSQL유틸리티를 이용하여 MYSQL의 환경변수들을 모두 출력하여 grep으로 “long_query_time”에 대한 부분만을 확인한 것이다.

 

[root@sulinux bin]#./mysqladmin -u root -p variables | grep long_query_time Enter password: ******** | long_query_time                 | 10.000000                              | [root@sulinux data]#

 

위의 결과를 보면 “long_query_time”의 변수값이 10(초)로 설정되어있기 때문에 MYSQL의 SQL쿼리문이 10초이상 지속될 때에는 그 쿼리문의 내역을 /usr/local/mysql/data/디렉토리에 있는 SLOW_QUERY_LOG파일에 기록할 것이다.  따라서 이 로그파일을 확인해본다면 MYSQL의 과부하를 일으키는 웹프로그램파일(SQL쿼리문)을 찾을 수 있을 것이다.

 

물론 long_query_time에서 지정한 10초라는 시간은 얼마든지 변경이 가능하다. MYSQL을 실행할 때에 -O옵션을 이용하는 방법이 있고 my.cnf를 이용하는 방법도 있다. 이 방법에 대해서는 이번장의 뒷부분에 자세히 설명하였다.  참고하기 바란다.

 

결론적으로 이 SLOW로그파일을 활용하면 어떤 쿼리문에서 MYSQL 과부하를 일으키는지 정확하게 알 수 있기 때문에 필자의 경우에 MYSQL 튜닝방법으로 굉장히 애용하는 방법이다.