線上慢查詢的排查

     最近查看慢查詢日志，一直有看到SELECT * FROM tb_name的SQL語句，在之前SQL審核的時候，也沒發現有這些SQL的存在，所以很好奇這里怎么出現的，后來用了vc-mysql-sniffer腳本去抓SQL來分析，也沒有找出SELECT * 之類的SQL，下面我上圖讓分析一下：

slow.log

可以看到大量的SELECT * 的SQL，如果細心的小伙伴會發現，SQL之前都有use某個庫，從這里應該可以想到一般程序里不可能會出現use xxx之類的SQL，所以可以排除程序在作怪的可能了，一般use某個庫再執行SQL，普遍都是人為操作的比較多，但是DB服務器只有我才有權限，所以覺得好奇怪，在想這些SQL從哪里飛出來的，后來認真分析了一下slow log發現每次出現這類SQL的頻率都是間隔一個小時左右，后來我再檢查一下些庫是否有定時器，結果發現沒有，這下我就大概知道什么原因了，我在slave上是每個小時一備份的，以下是模擬的過程：

 

在測試服務器把慢查詢時間設置為0.5s，然后把查詢日志打開：（測試完后，記得關掉general_log）

mysql> set global long_query_time=0.5;
Query OK, 0 rows affected (0.00 sec)
mysql> set global general_log=on;
Query OK, 0 rows affected (0.01 sec)

然后把備份導入測試服務器：

[root@Test_server ~]# mysql -uroot -p123456 testdb < ./testdb.sql 
[root@Test_server ~]#

在session1窗口執行查看general_log的操作：

[root@Test_server ~]# tail -f /data/mysql3306/Test_server.log

在session2窗口執行備份操作：

[root@Test_server ~]# mysqldump -uroot -p123456  -R --events --triggers=true --master-data=2 --single-transaction  testdb > testdb.sql

再在session1上查看打印日志：

[root@Test_server ~]# tail -f /data/mysql3306/Test_server.log 
/data/service/mysql/bin/mysqld, Version: 5.6.25-log (MySQL Community Server (GPL)). started with:
Tcp port: 3306  Unix socket: /tmp/mysql3306.sock
Time                 Id Command    Argument
151006 14:21:21 583376 Quit
151006 14:21:22 583389 Connect  root@localhost on 
                583389 Query    select @@version_comment limit 1
151006 14:21:24 583389 Query    show variables like '%gen%'
151006 14:21:25 583389 Quit
151006 14:43:18 583786 Connect  root@localhost on 
                583786 Query    /*!40100 SET @@SQL_MODE='' */
                583786 Query    /*!40103 SET TIME_ZONE='+00:00' */
                583786 Query    FLUSH /*!40101 LOCAL */ TABLES
151006 14:43:19 583786 Query    FLUSH TABLES WITH READ LOCK
                583786 Query    SET SESSION TRANSACTION ISOLATION LEVEL REPEATABLE READ
                583786 Query    START TRANSACTION /*!40100 WITH CONSISTENT SNAPSHOT */
                583786 Query    SHOW VARIABLES LIKE 'gtid\_mode'
                583786 Query    SHOW MASTER STATUS
                583786 Query    UNLOCK TABLES
                583786 Query    SELECT LOGFILE_GROUP_NAME, FILE_NAME, TOTAL_EXTENTS, INITIAL_SIZE, ENGINE, EXTRA FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'UNDO LOG' AND FILE_NAME IS NOT NULL AND LOGFILE_GROUP_NAME IN (SELECT DISTINCT LOGFILE_GROUP_NAME FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'DATAFILE' AND TABLESPACE_NAME IN (SELECT DISTINCT TABLESPACE_NAME FROM INFORMATION_SCHEMA.PARTITIONS WHERE TABLE_SCHEMA IN ('testdb'))) GROUP BY LOGFILE_GROUP_NAME, FILE_NAME, ENGINE ORDER BY LOGFILE_GROUP_NAME
                583786 Query    SELECT DISTINCT TABLESPACE_NAME, FILE_NAME, LOGFILE_GROUP_NAME, EXTENT_SIZE, INITIAL_SIZE, ENGINE FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'DATAFILE' AND TABLESPACE_NAME IN (SELECT DISTINCT TABLESPACE_NAME FROM INFORMATION_SCHEMA.PARTITIONS WHERE TABLE_SCHEMA IN ('testdb')) ORDER BY TABLESPACE_NAME, LOGFILE_GROUP_NAME
151006 14:43:20 583786 Query    SHOW VARIABLES LIKE 'ndbinfo\_version'
                583786 Init DB  testdb
                583786 Query    SAVEPOINT sp
                583786 Query    show tables
                583786 Query    show table status like 'sys\_config'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `sys_config`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `sys_config`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `sys_aa`
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'sys\_config'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    show table status like 'testdb\_auto\_login'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `testdb_auto_login`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `testdb_auto_login`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `testdb_bb`
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'testdb\_auto\_login'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    show table status like 'testdb\_fans'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `testdb_fans`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `testdb_fans`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `testdb_cc`
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'testdb\_fans'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    show table status like 'testdb\_media'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `testdb_media`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `testdb_media`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `testdb_dd`
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'testdb\_media'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    show table status like 'testdb\_message'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `testdb_message`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `testdb_message`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `testdb_ee`
151006 14:43:23 583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'testdb\_message'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    show table status like 'testdb\_qrcode'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `testdb_qrcode`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `testdb_qrcode`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `testdb_ff`
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'testdb\_qrcode'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    show table status like 'testdb\_ticket'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `testdb_ticket`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `testdb_ticket`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `testdb_gg`
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'testdb\_ticket'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    show table status like 'testdb\_token'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `testdb_token`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `testdb_token`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `testdb_hh`
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'testdb\_token'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    show table status like 'wexin\_template\_msg'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `wexin_template_msg`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `wexin_template_msg`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `wexin_tem`
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'wexin\_template\_msg'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    show table status like 'wexin\_template\_msg\_data'
                583786 Query    SET SQL_QUOTE_SHOW_CREATE=1
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    show create table `wexin_template_msg_data`
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    show fields from `wexin_template_msg_data`
                583786 Query    SELECT /*!40001 SQL_NO_CACHE */ * FROM `testdb_template`
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SHOW TRIGGERS LIKE 'wexin\_template\_msg\_data'
                583786 Query    SET SESSION character_set_results = 'utf8'
                583786 Query    ROLLBACK TO SAVEPOINT sp
                583786 Query    RELEASE SAVEPOINT sp
                583786 Query    show events
                583786 Query    use `testdb`
                583786 Query    select @@collation_database
                583786 Query    SET SESSION character_set_results = 'binary'
                583786 Query    SHOW FUNCTION STATUS WHERE Db = 'testdb'
                583786 Query    SHOW PROCEDURE STATUS WHERE Db = 'testdb'
                583786 Query    SET SESSION character_set_results = 'utf8'
151006 14:43:27 583786 Quit

再查看一下慢查詢日志：

[root@Test_server ~]# tail -f /data/mysql3306log/slow.log 
# User@Host: root[root] @ localhost []  Id: 583786
# Query_time: 0.678000  Lock_time: 0.000452 Rows_sent: 0  Rows_examined: 0
SET timestamp=1444113800;
SELECT DISTINCT TABLESPACE_NAME, FILE_NAME, LOGFILE_GROUP_NAME, EXTENT_SIZE, INITIAL_SIZE, ENGINE FROM INFORMATION_SCHEMA.FILES WHERE FILE_TYPE = 'DATAFILE' AND TABLESPACE_NAME IN (SELECT DISTINCT TABLESPACE_NAME FROM INFORMATION_SCHEMA.PARTITIONS WHERE TABLE_SCHEMA IN ('testdb')) ORDER BY TABLESPACE_NAME, LOGFILE_GROUP_NAME;
# Time: 151006 14:43:23
# User@Host: root[root] @ localhost []  Id: 583786
# Query_time: 3.427523  Lock_time: 0.000101 Rows_sent: 303198  Rows_examined: 303198
use testdb;
SET timestamp=1444113803;
SELECT /*!40001 SQL_NO_CACHE */ * FROM `testdb_aa`;

可以看到問題所在了。

 

這是用xtrabackup備份時打印的查詢日志：

[root@Test_server soft]# tail -f /data/mysql3306/Test_server.log   
151006 15:49:50 584992 Connect  root@localhost on 
                584992 Query    set autocommit=1
                584992 Query    SET SESSION wait_timeout=2147483
                584992 Query    SELECT CONCAT(@@hostname, @@port)
151006 15:49:52 584992 Quit
                584993 Connect  root@localhost on 
                584993 Query    set autocommit=1
                584993 Query    SET SESSION wait_timeout=2147483
                584993 Query    SHOW VARIABLES
                584993 Query    SHOW VARIABLES
                584993 Query    SHOW SLAVE STATUS
151006 15:50:35 584993 Query    SET SESSION lock_wait_timeout=31536000
                584993 Query    FLUSH TABLES
                584993 Query    FLUSH TABLES WITH READ LOCK
                584993 Query    SHOW MASTER STATUS
                584993 Query    FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS
151006 15:50:36 584993 Query    UNLOCK TABLES
                584993 Query    SELECT UUID() AS uuid
151006 15:50:37 584993 Query    SELECT VERSION() as version
                584993 Quit

 

 

總結：

    一、做好SQL的監控工作，把所有影響性能的SQL抓出來，處理掉，這樣才能讓服務器壓力更少

    二、現在普遍公司都搭建有MySQL主從架構，在從上面進行數據備份，對用戶的使用體驗影響比較少，所以建議在從上備份

    三、數據量大的時候，用xtrabackup備份比mysqldump備份要快得多，而且是沒有出現SELECT * 之類的SQL語句，如果數據量大，出現SELECT *之類的SQL，影響是灰常大的，建議用xtrabackup備份（我兩個都用，因為我的slave不對外提供服務）

 

 

 

 

作者：陸炫志

出處：xuanzhi的博客 http://www.cnblogs.com/xuanzhi201111

您的支持是對博主最大的鼓勵，感謝您的認真閱讀。本文版權歸作者所有，歡迎轉載，但請保留該聲明。