2016-12-12 1 views
2

Lorsque j'exécute l'analyseur de journal de requête lente, je vois un temps considérable de requêtes en secondes. J'ai essayé d'exécuter ces requêtes manuellement, elles sont exécutées très rapidement (0.01sec). Quel pourrait être le problème?Temps énorme dans le journal de requête lente (MariaDB)

mysql Ver 15.1 Distrib 10.1.9-MariaDB, pour Linux (x86_64) en utilisant 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 -t -St 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), [email protected] 
    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) 
+0

Apparemment, vous avez 'log_queries_not_using_indexes = on', et vous rencontrez un bug qui affecte les requêtes répondant aux critères et exécutées via des événements. Un rapport de bogue a été déposé sur la base de cette question: https://jira.mariadb.org/browse/MDEV-11552. Le bug sera corrigé dans les futures versions de MariaDB. En attendant, si vous n'êtes pas vraiment en train d'analyser les requêtes n'utilisant pas d'index, vous pouvez définir la variable 'off' (si vous le faites dans la configuration, vous devez redémarrer le serveur, si vous le faites à l'exécution, faites Assurez-vous qu'il s'agit d'une valeur globale que vous modifiez et redémarrez 'event_scheduler'. – elenst

+0

Merci beaucoup pour la réponse. Je pensais que les requêtes étaient si lentes) – avj83

Répondre

0

L'horloge tourne en arrière. Vous devez vous y prendre facilement - ne pas dépasser la vitesse de la lumière! Sérieusement, ... Je l'ai vu régulièrement depuis 15 ans, dans toutes les versions de MySQL. Le nombre que vous voyez est probablement -1 étant traité comme un numéro UNSIGNED.

Recommandation: pensez à zéro et passez à autre chose. OK, c'est difficile à faire dans ce cas, puisque vous avez un résumé (mysqldumpslow). La source du problème est quelque part dans le slowlog. Si cela se reproduit demain (sur une autre partie du slowlog), envoyez un bug avec http://bugs.mysql.com (en supposant qu'il n'y en a pas déjà plusieurs).

0

Comme précédemment mentionné dans le comment, un bug report a été déposé sur la base de cette question. Le bug a maintenant été corrigé, le fix est disponible en 5.5 tree et sera publié avec les prochaines versions de MariaDB: 5.5.54, 10.0.29, 10.1.21, 10.2.3.