慢查询日志中的大量时间（MariaDB）答案

【问题标题】：Huge time in slow query log (MariaDB)慢查询日志中的大量时间（MariaDB）
【发布时间】：2017-04-27 05:45:39
【问题描述】：

当我运行慢查询日志分析器时，我看到大量请求时间（以秒为单位）。我尝试手动执行这些请求，它们执行得非常快（0.01 秒）。可能是什么问题呢？

mysql Ver 15.1 Distrib 10.1.9-MariaDB，适用于 Linux (x86_64)，使用 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，并且遇到了一个错误，该错误会影响满足条件并通过事件执行的查询。已根据以下问题提交了错误报告：jira.mariadb.org/browse/MDEV-11552。该错误将在 MariaDB 的未来版本中修复。同时，如果你不是真的在分析不使用索引的查询，你可以设置变量off（如果你在config中这样做，你需要重启服务器；如果你在运行时这样做，make确保它是您正在更改的全局值，然后重新启动 event_scheduler)。
非常感谢您的回答。我认为查询很慢）

标签： mariadb mysql-slow-query-log

【解决方案1】：

正如之前在comment 中提到的，bug report 是基于此问题提交的。该错误现已修复，fix 在5.5 tree 中可用，并将与 MariaDB 的下一个版本一起发布：5.5.54、10.0.29、10.1.21、10.2.3。

【讨论】：

【解决方案2】：

时钟倒转。你需要放轻松——不要超过光速！

说真的，...在过去的 15 年里，我在所有版本的 MySQL 中都定期看到这种情况。您看到的号码可能是 -1 被视为 UNSIGNED 号码。

建议：将其视为零，然后继续。

好的，在这种情况下很难做到，因为你有一个摘要（mysqldumpslow）。问题的根源在慢日志中的某个地方。如果明天再次发生（在慢日志的不同部分），请使用http://bugs.mysql.com 提交错误（假设那里还没有几个）。

【讨论】：