When I run the slow query log analyzer, I see huge time of requests in seconds. I tried to execute these requests manually, they are executed very fast(0.01sec). What could be the problem?
mysql Ver 15.1 Distrib 10.1.9-MariaDB, for Linux (x86_64) using readline 5.1
CREATE DEFINER = 'root'@'192.168.1.101' EVENT `DEL_EXPIRED_BANS`
ON SCHEDULE EVERY 10 MINUTE STARTS '2013-10-18 13:38:54'
ON COMPLETION NOT PRESERVE
ENABLE
COMMENT '' DO
BEGIN
update users set ban_type=0, ban_expire=null, ban_expire=null, ban_reason=null
where ban_type > 0 and ban_expire < CURRENT_TIMESTAMP();
delete from `flash_client_log` where TIMESTAMPADD(DAY,4, `dttm` ) < CURRENT_TIMESTAMP() and `log_type`=1;
delete from `flash_client_log` where TIMESTAMPADD(DAY,4, `dttm` ) < CURRENT_TIMESTAMP() and `log_type`=0;
END;
[root@xy1 GameServer]# mysqldumpslow -a -s t -t 15 /var/log/mysql_slow.log
Reading mysql slow query log from /var/log/mysql_slow.log
Count: 1344 Time=18446679593472.00s (24792337373626364s) Lock=0.00s (0s) Rows_sent=0.0 (0), Rows_examined=41408.5 (55653024), Rows_affected=0.0 (0), 2users@localhost
update users set ban_type=0, ban_expire=null, ban_expire=null, ban_reason=null
where ban_type > 0 and ban_expire < CURRENT_TIMESTAMP()
Count: 672 Time=18446679593471.92s (12396168686813130s) Lock=0.15s (98s) Rows_sent=0.0 (0), Rows_examined=33953.0 (22816416), Rows_affected=0.0 (0), root[root]@localhost
delete from `flash_client_log` where TIMESTAMPADD(DAY,1, `dttm` ) < CURRENT_TIMESTAMP() and `log_type`=1
Count: 672 Time=18446679593471.92s (12396168686813128s) Lock=0.15s (100s) Rows_sent=0.0 (0), Rows_examined=33953.0 (22816416), Rows_affected=0.0 (0), root[root]@localhost
delete from `flash_client_log` where TIMESTAMPADD(DAY,3, `dttm` ) < CURRENT_TIMESTAMP() and `log_type`=0
Count: 672 Time=18446679593471.91s (12396168686813120s) Lock=0.09s (63s) Rows_sent=0.0 (0), Rows_examined=14599.2 (9810684), Rows_affected=22.5 (15144), root[root]@192.168.1.101
delete from `flash_client_log` where TIMESTAMPADD(DAY,4, `dttm` ) < CURRENT_TIMESTAMP() and `log_type`=1
Count: 672 Time=18446679593470.33s (12396168686812064s) Lock=1.70s (1140s) Rows_sent=0.0 (0), Rows_examined=28865.1 (19397320), Rows_affected=0.4 (237), root[root]@192.168.1.101
delete from `flash_client_log` where TIMESTAMPADD(DAY,4, `dttm` ) < CURRENT_TIMESTAMP() and `log_type`=0
Count: 1 Time=18446679639052.95s (18446679639052s) Lock=0.00s (0s) Rows_sent=0.0 (0), Rows_examined=0.0 (0), Rows_affected=0.0 (0), billiards3d_net[billiards3d_net]@localhost
delete from guests_log WHERE dttm < DATE_SUB(CURDATE(), INTERVAL 1 WEEK)
log_queries_not_using_indexes=on
, and you hit a bug which affects queries meeting the criteria and executed via events. A bug report has been filed based on this question: jira.mariadb.org/browse/MDEV-11552 . The bug will be fixed in future versions of MariaDB. Meanwhile, if you aren't really in the process of analyzing queries not using indexes, you can set the variableoff
(if you do it in the config, you need to restart the server; if you do it at runtime, make sure it's a global value that you are changing, and restartevent_scheduler
). – elenst Dec 12 '16 at 18:29