본문 바로가기
Database/MYSQL

갑자기 Mysql slow_log crash 나는 이유는 무엇일까?

by 반화넬 2025. 2. 14.
반응형

 

Mysql 재구동을 했거나 운영중에 갑자기 slow_log crash 가 발생하는 경우가 있는데 어떤 이유때문에 이런 에러가 발생할까 궁금합니다. 

[ERROR] /usr/local/libexec/mysqld: Table 'slow_log' is marked as crashed and should be repaired
 
 
MySQL slow_log가 충돌하는 경우, slow_log 테이블이 손상되었을 경우니데요. 이유는 이런듯 합니다. 
 
원인 하드디스크 용량 부족, query_time이 35일 이상인 경우. 
 
위처럼 증상이 발생하는 이유는 인듯합니다.

 

  • MySQL Administrator에서 slow query를 확인하려고 할 때 충돌 
     
  • Select 시 "is marked as crashed and should be repaired"라는 에러가 발생 
     
Repair table mysql.slow_log;
 
MySQL 로그 종류 
 
  • Error log: MySQL 시작, 실행, 종료 시 발생한 문제 기록
  • General log: 클라이언트 연결 설정 및 실행된 쿼리 기록
  • Binary log: 테이블 생성 및 데이터 변경
서버의 로그를 확인해서 더욱 확인이 가능하겠지만 갑자기 발생하는 이유는 찾기 정말 힘들지 않을까 싶은데요.
그래도 원인 파악을 해야 다음에 동일 문제가 발생하지 않는다는점 꼭! 명심하시길 바랍니다.
 
감사합니다.


버그사항으로 공유된 내역도 있으니 참고하세요.
 
 

MySQL Bugs: #96373: query_time greater than 35 days lead to slow log corruption

 

bugs.mysql.com

 

[30 Jul 2019 6:46] Fungo Wang
Description:
If there is a query running longer than 35 days and logged to slow_log, we can not retrieve data from mysql.slow_log.

mysql> select * from mysql.slow_log;
ERROR 1194 (HY000): Table 'slow_log' is marked as crashed and should be repaired

How to repeat:
Make sure slow log is enabled and log_output is set to table.

set global slow_query_log = ON;
set global log_output = 'TABLE';

Then execute a long query 

select sleep(35*24*3600);

then query from slow_log
select * from mysql.slow_log;

==============

select sleep(35*24*3600); will run a very long time(35 days), to make it quick, we can use gdb to change the start_time back to 35 days before.

for example:
break on mysql_execute_command
then change start_time and start_utime

p thd->start_time.tv_sec = 1555826389
p thd->start_utime = (longlong)1555826389*1000000

Suggested fix:
If check the CSV data file, we can see the query_time (838:59:59.266398) is bigger than 838:59:59.000000, the max legal value.

"2019-07-30 09:29:05.726679","root[root] @ localhost [127.0.0.1]","838:59:59.726679","838:59:59.266398",3,3,"",0,0,1,"select * from mysql.slow_log",12

This illegal value lead to query failed.

If we don't fetch query_time field, the select is successful.

mysql> select start_time, user_host from mysql.slow_log;
+----------------------------+------------------------------------+
| start_time                 | user_host                          |
+----------------------------+------------------------------------+
| 2019-07-30 09:28:06.823172 | root[root] @ localhost [127.0.0.1] |
| 2019-07-30 09:28:18.067313 | root[root] @ localhost [127.0.0.1] |
| 2019-07-30 09:28:30.163309 | root[root] @ localhost [127.0.0.1] |
| 2019-07-30 09:29:05.726679 | root[root] @ localhost [127.0.0.1] |
+----------------------------+------------------------------------+
4 rows in set (0.00 sec)

mysql> select start_time, user_host, query_time from mysql.slow_log;
ERROR 1194 (HY000): Table 'slow_log' is marked as crashed and should be repaired

Both latest 5.7.27 and 8.0.17 are affected, 5.6 series don't have this issue, because in 5.6 slow_log query_time don't allow fractional  part time.

BTW, lock_time field also have this issue.

A simple fix is to cap fractional time properly in `calc_time_from_sec()` when writing to slow_log.

 


Thank you for the report.
Verified as described on 8.0.17 build.
반응형