以前一直依賴慣了經過mysql
慢查詢文本日誌來解決問題,此次遇到的狀況是沒法訪問文本日誌,只能在mysql
客戶端裏鼓搗,通過一番周折以後,終於順利解決問題,原先一個頁面的首字節返回時間長達24秒,通過優化後縮短爲1秒。如下記錄操做步驟。mysql
首先,看一下慢查詢日誌有沒有開:sql
show variables like '%slow%';
Variable_name | Value |
---|---|
log_slow_admin_statements | ON |
log_slow_slave_statements | OFF |
slow_launch_time | 2 |
slow_query_log | ON |
slow_query_log_file | /home/mysql/data3001/mysql/slow_query.log |
第4行爲ON,說明已經開了,若是沒有開的話,就先開一下吧。數據庫
show variables like '%long%';
Variable_name | Value |
---|---|
long_query_time | 1.000000 |
performance_schema_events_stages_history_long_size | 0 |
performance_schema_events_statements_history_long_size | 0 |
performance_schema_events_transactions_history_long_size | 0 |
performance_schema_events_waits_history_long_size | 0 |
第1行說明慢查詢門檻值是1秒,也就是說只要任意一個查詢時間超過了1秒的就會被記錄,若是你以爲這個值有點過低,也能夠改成5秒或者10秒,看你以爲多長時間的一個查詢是不可接受的。優化
show variables like '%log_output%';
Variable_name | Value |
---|---|
log_output | TABLE |
這裏比較關鍵,log的輸出方式是TABLE
,才能把結果記錄在數據庫表中。日誌
use mysql; show tables;
Tables_in_mysql |
---|
columns_priv |
db |
engine_cost |
event |
func |
general_log |
gtid_executed |
help_category |
help_keyword |
help_relation |
help_topic |
innodb_index_stats |
innodb_table_stats |
ndb_binlog_index |
plugin |
proc |
procs_priv |
proxies_priv |
server_cost |
servers |
slave_master_info |
slave_relay_log_info |
slave_worker_info |
slow_log |
tables_priv |
time_zone |
time_zone_leap_second |
time_zone_name |
time_zone_transition |
time_zone_transition_type |
user |
這裏有一個表slow_log
,它就是存儲咱們的慢查詢日誌的地方了。code
desc slow_log;
Field | Type | Null | Key | Default | Extra |
---|---|---|---|---|---|
start_time | timestamp(6) | NO | CURRENT_TIMESTAMP(6) | on update CURRENT_TIMESTAMP(6) | |
user_host | mediumtext | NO | NULL | ||
query_time | time(6) | NO | NULL | ||
lock_time | time(6) | NO | NULL | ||
rows_sent | int(11) | NO | NULL | ||
rows_examined | int(11) | NO | NULL | ||
db | varchar(512) | NO | NULL | ||
last_insert_id | int(11) | NO | NULL | ||
insert_id | int(11) | NO | NULL | ||
server_id | int(10) unsigned | NO | NULL | ||
sql_text | mediumblob | NO | NULL | ||
thread_id | bigint(21) unsigned | NO | NULL |
在slow_log
表中,query_time
是咱們最關心的:orm
select query_time, rows_sent, rows_examined, db from mysql.slow_log where query_time > 10 and rows_sent < 100 limit 10;
query_time | rows_sent | rows_examined | db |
---|---|---|---|
00:00:17.187272 | 15 | 15733 | mydb |
00:00:18.948918 | 15 | 15733 | mydb |
00:00:18.901217 | 15 | 15733 | mydb |
00:00:18.590528 | 15 | 15733 | mydb |
00:00:17.173634 | 15 | 15733 | mydb |
00:00:13.013449 | 15 | 15733 | mydb |
00:00:15.114500 | 15 | 15733 | mydb |
00:00:19.771646 | 15 | 15733 | mydb |
00:00:21.683656 | 15 | 15733 | mydb |
00:00:22.271268 | 15 | 15733 | mydb |
能夠看到有不少次查詢雖然只返回15條數據,而耗時居然長達17秒!是可忍,孰不可忍!咱們先只取第1條數據看一下:server
select sql_text from mysql.slow_log order by start_time desc limit 1;
結果就是這條語句:索引
select * from a left join b on b.parentid=a.id LEFT join d on d.memberid=b.memberid limit 0, 15;
就是這麼一條簡單的sql語句,怎麼就會須要17秒呢?咱們首先懷疑的就是有沒有加索引,索引不須要在每一個字段上加,可是這裏的查詢關係上必須有,好比a.id, b.parentid, d.memberid, b.memberid。it
show index from b;
Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment |
---|---|---|---|---|---|---|---|---|---|---|---|---|
b | 0 | PRIMARY | 1 | id | A | 6714 | NULL | NULL | BTREE |
不出所料,果真只在主鍵上加了索引,而關鍵的parentid
沒有索引。
alter table b add index b_parent (parentid);
再次查看索引:
show index from b;
Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment |
---|---|---|---|---|---|---|---|---|---|---|---|---|
b | 0 | PRIMARY | 1 | id | A | 6714 | NULL | NULL | BTREE | |||
b | 1 | b_parent | 1 | parentid | A | 6593 | NULL | NULL | YES | BTREE |
依此類推,把咱們全部缺索引的地方通通都加上索引,再次查詢,時間縮短到1秒之內,收工!