MySQL 로그

에러 로그 파일

• MySQL이 실행되는 도중에 발생하는 에러나 경고 메시지가 출력되는 로그 파일이다.

• 위치는 my.cnf에서 log_error라는 이름에 정의된 경로로 생성된다.

• my.cnf에 별도로 정의되지 않은 경우에는 데이터 디렉토리에 .err이라는 확장자의 파일로 생성된다.

MySQL이 시작하는 과정과 관련된 정보, 에러 메시지

• MySQL의 설정 파일을 변경하거나 데이터베이스가 비정상적으로 종료된 이후 다시 시작하는 경우에는 반드시 MySQL 에러 로그 파일을 통해 설정된 변수의 이름이나 값이 명확하게 설정되고 의도한 대로 적용됐는지 확인해야 한다.

• MySQL 서버 정상 기동: 'mysqld: ready for connections'

• 위의 메시지가 뜨고, 새로 변경하거나 추가한 파라미터에 대한 특별한 에러나 경고성 메시지가 없다면 정상적으로 적용된 것으로 판단하면 된다.

• 특정 변수가 ignore된 경우, 변수명을 인식하지 못하거나 설정된 값의 내용을 인식하지 못하는 경우 MySQL서버가 에러 미시지를 출력하고 시작하지 못했다는 메시지를 출력한다.

마지막으로 종료할 때 비정상적으로 종료된 경우 나타나는 InnoDB의 트랜잭션 복구 메시지

• InnoDB의 경우 MySQL 서버가 비정상적, 강제적으로 종료되면 다시 시작되면서 완료되지 못한 트랜잭션을 정리하고 디스크에 기록되지 못한 데이터가 있다면 다시 기록하는 재처리 작업을 하게된다. 이 때 메시지가 출력되는데, 문제가 있어서 복구되지 못할 때는 에러 메시지를 출력하고 MySQL은 종료된다.

• 이 단계에서 발생하는 문제는 해결하기 어려운 문제일 때가 많다. 때로는 innodb_force_recovery를 0보다 큰 값으로 설정하고 재시작해야할 수도 있다.

쿼리 처리 도중에 발생하는 문제에 대한 에러 메시지

• 쿼리 도중 발생하는 문제점은 사전 예방이 어렵다.

• 주기적으로 에러 로그 파일을 검토해야 한다.

비정상적 종료된 커넥션 메시지(Aborted connection)

• 클라이언트 애플리케이션에서 정상적으로 종료 하지 못하고 프로그램이 종료된 경우 에러 메시지에 기록된다.

• 네트워크 문제일 경우에도 기록 된다.

-많이 기록된다면 애플리케이션 커넥션 종료 로직을 검토해보아야 한다.

• max_connect_erros시스템 변수에 설정한 값을 넘게되면 "Host 'host_name' is blocked"라는 에러가 발생한다. 이럴 땐 max_connect_erros의 값을 올린 후 문제를 해결하자.

모니터링, 상태 조회(show engine innodb status) 명령의 결과 메시지

• InnoDB의 테이블 모니터링, 락 모니터링, InnoDB의 엔진 상태를 조회하는 명령은 상대적으로 큰 메시지를 기록한다.

• 모니터링을 사용한 이후에는 다시 비활성화해서 에러 로그 파일이 커지지 않게 해야한다.

MySQL의 종료 메시지

• 'Received SHUTDOWN from user ...'이라는 메시지는 누군가가 MySQL 서버를 종료시킨 것이다.

• 아무런 종료 관련 메시지가 없거나 스택 트레이스와 같은 내용이 출력되는 경우에는 MySQL 서버가 비정상적(세그멘테이션 폴트)으로 종료된 것이다. 이 경우 스택 트레이스의 내용을 참조해서 MySQL버그라면 버전을 업그레이드하거나 회피책을 찾는것이 최적의 방법이다.

제너럴 쿼리 로그 파일

• MySQL서버에서 실행되는 쿼리를 기록한다.

• 쿼리 로그를 활성화 하면 쿼리 로그 파일에 기록된다.

• 시간 단위로 실행됐던 쿼리의 내용이 기록된다.

• 슬로우 쿼리 로그와는 다르게 쿼리가 실행되기 전에 MySQL이 쿼리 요청을 받으면 바로 기록하기 때문에 쿼리 실행 중 오류가 발생해도 일단 로그 파일에 기록된다.

• 쿼리 로그 파일 경로는 general_log_file이라는 이름에 설정돼 있다.

• log_output이라는 값에 따라 쿼리 로그를 파일로 저장할지 테이블로 저장할지 결정된다.

슬로우 쿼리 로그

• long_query_time 시스템 변수에 설정한 시간(초 단위, 소수점 가능)이상의 시간이 소요된 쿼리가 기록된다.

• 슬로우 쿼리 로그는 MySQL이 쿼리를 실행한 후, 실제 소요된 시간을 기준으로 기록하기 때문에 쿼리가 정상적으로 실행이 되어야 기록될 수 있다.

• 슬로우 쿼리 로그에 기록되는 쿼리는 기능은 정상적이나 실행 시간이 long_query_time에 정의된 시간보다 많이 걸린 쿼리인 것이다.

• log_output옵션을 이용해 파일로 저장할지, 테이블로 저장할지 선택할 수 있다.

• table로 설정하면 제너럴, 슬로우 로그를 테이블 (general_log, slow_log)에 저장한다.
  해당 테이블은 CSV 스토리지 엔진을 사용하기 때문에 CSV 파일로 저장하는것과 동일하다.

• MySQL의 경우 잠금 처리가 MySQL 엔진 레벨과 스토리지 엔진 레벨 두 가지 레이어로 처리된다.

슬로우 쿼리 로그 출력 내용
# Time: 2022-09-02T00:50:22.123456+09:00
# User@Host: root[root] @ localhost [] Id: 10
# Query_time: 1.123456 Lock_time: 0.000005 Rows_sent: 1 Rows_examined:2844047
use employees;
SET timestamp=1234123410;
select emp_no, max(salary) from salaries;

• Time: 쿼리가 종료된 시점 (시작시점을 확인하려면 Time - Query_time을 해야한다.)

• User@Host: 쿼리 실행한 사용자 계정

• Query_time: 쿼리가 실행되는데 걸린 전체 시간을 의미

• Lock_time: MySQL엔진 레벨에서 관장하는 테이블 잠금에 대한 대기 시간(Lock_time 시간은 실제 쿼리가 실행되는 데 필요한 잠금 체크와 같은 코드 실행 부분의 시간까지 모두 포함된다. 이 값이 작은 값이면 무시해도 된다.)

• Rows_sent: 실제 몇 건의 처리 결과를 클라이언트로 보냈는지를 나타내는 수

• Rows_examined: 쿼리가 처리되기 위해 접근한 레코드의 건 수.

• MySQL엔진 레벨에서 설정한 테이블 잠금 때문에 Lock_time이 1초 이상 소요될 수 있는데, InnoDB 테이블에만 접근하는 쿼리 문장의 슬로우 쿼리 로그에서는 Lock_time값은 튜닝이나 쿼리 분석에 별로 도움이 되지 않는다.

• Percona에서 개발한 Percona Toolkit의 pt-query-digest 스크립트를 이용하면 쉽게 빈도나 처리 성능별로 쿼리를 정렬해서 살펴볼 수 있다.

슬로우 쿼리 통계

• 분석 결과 최상단에 표시된다.

• 모든 쿼리를 대상으로 슬로우 쿼리 로그의 샐힝 시간, 잠금 대기 시간등에 대해 평균 및 최소/최대 값을 표시한다.

실행 빈도 및 누석 실행 시간순 랭킹

• 각 쿼리별로 응답 시간과 실행 횟수를 보여준다.

• pt-query-digest 명령 실행 시 --order-by옵션으로 정렬 순서를 변경할 수 있다.

• Query ID는 실행된 쿼리 문장을 정규화해서 만들어진 해시 값이다. 일반적으로 같은 쿼리라면 동일한 Query ID를 가진다.

쿼리별 실행 횟수 및 누적 실행 시간 상세 정보

• Query ID별 쿼리를 쿼리 랭킹에 표시된 순서대로 자세한 내용을 보여준다.

• 쿼리가 얼마나 실행됐는지, 쿼리의 응답 시간에 대한 히스토그램 같은 내용을 보여준다.