分类:
2012-05-19 18:30:31
原文地址:【原创】关于MySQL的慢日志分析工具 作者:yueliangdao0608
Reading mysql slow query log from localhost-slow.log Count: 2 Time=7.00s (14s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@localhost select * from t_page_sample order by id desc limit N,N Count: 1 Time=11.00s (11s) Lock=0.00s (0s) Rows=1.0 (1), root[root]@localhost select count(*) from t_page_sample Count: 1 Time=1418.00s (1418s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@localhost insert ignore into t_page_sample select ceil(rand()*N), ceil(rand()*N), date_sub(now(),interval floor(rand()*N) day), now() from t_page_sample |
Reading mysql slow query log from localhost-slow.log Count: 2 Time=7.00s (14s) Lock=0.00s (0s) Rows=0.0 (0), root[root]@localhost select * from t_page_sample order by id desc limit N,N |
# 280ms user time, 80ms system time, 11.56M rss, 16.65M vsz # Current date: Sat May 8 02:47:39 2010 # Files: localhost-slow.log # Overall: 4 total, 3 unique, 0.01 QPS, 1.96x concurrency ________________ # total min max avg 95% stddev median # Exec time 1443s 5s 1418s 361s 1357s 584s 684s # Lock time 0 0 0 0 0 0 0 # Rows sent 1 0 1 0.25 0.99 0.43 0 # Rows exam 6.98M 1.69M 1.89M 1.74M 1.86M 76.62k 1.69M # Time range 2010-05-08 00:28:42 to 2010-05-08 00:40:58 # Profile # Rank Query ID Response time Calls R/Call Item # ==== ================== ================ ===== ========= =============== # 1 0x2A94F91D8C3B4B26 1418.0000 99.0% 1 1418.0000 INSERT SELECT t_page_sample # 2 0x06754F1BD3C8D697 14.0000 1.0% 2 7.0000 SELECT t_page_sample # Query 1: 0 QPS, 0x concurrency, ID 0x2A94F91D8C3B4B26 at byte 0 ________ # This item is included in the report because it matches --limit. # pct total min max avg 95% stddev median # Count 25 1 # Exec time 98 1418s 1418s 1418s 1418s 1418s 0 1418s # Lock time 0 0 0 0 0 0 0 0 # Rows sent 0 0 0 0 0 0 0 0 # Rows exam 27 1.89M 1.89M 1.89M 1.89M 1.89M 0 1.89M # Time range 2010-05-08 00:28:42 to 2010-05-08 00:28:42 # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s # 10s+ ################################################################ # Review information # first_seen: 2010-05-08 00:28:42 # last_seen: 2010-05-08 00:28:42 # reviewed_by: # reviewed_on: # comments: # Tables # SHOW TABLE STATUS FROM `t_girl` LIKE 't_page_sample'\G # SHOW CREATE TABLE `t_girl`.`t_page_sample`\G insert ignore into t_page_sample select ceil(rand()*10000000), ceil(rand()*9), date_sub(now(),interval floor(rand()*20) day), now() from t_page_sample\G # Query 2: 0.07 QPS, 0.47x concurrency, ID 0x06754F1BD3C8D697 at byte 1499 # This item is included in the report because it matches --limit. # pct total min max avg 95% stddev median # Count 50 2 # Exec time 0 14s 5s 9s 7s 9s 3s 7s # Lock time 0 0 0 0 0 0 0 0 # Rows sent 0 0 0 0 0 0 0 0 # Rows exam 48 3.39M 1.69M 1.69M 1.69M 1.69M 0 1.69M # Time range 2010-05-08 00:40:28 to 2010-05-08 00:40:58 # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s ################################################################ # 10s+ # Review information # first_seen: 2010-05-08 00:40:28 # last_seen: 2010-05-08 00:40:58 # reviewed_by: # reviewed_on: # comments: # Tables # SHOW TABLE STATUS FROM `t_girl` LIKE 't_page_sample'\G # SHOW CREATE TABLE `t_girl`.`t_page_sample`\G # EXPLAIN select * from t_page_sample order by id desc limit 4400000,2\G |
*************************** 1. row *************************** checksum: 465365117438580375 fingerprint: select * from t_page_sample order by id desc limit ? sample: select * from t_page_sample order by id desc limit 4400000,2 first_seen: 2010-05-08 00:40:28 last_seen: 2010-05-08 00:40:58 reviewed_by: NULL reviewed_on: NULL comments: NULL 1 rows in set (0.00 sec) |
# Caught SIGINT. # 690ms user time, 2.4s system time, 11.27M rss, 16.41M vsz # Current date: Sat May 8 03:17:39 2010 # Files: STDIN # Overall: 1 total, 1 unique, 0 QPS, 0x concurrency ______________________ # total min max avg 95% stddev median # Exec time 1273313855s 1273313855s 1273313855s 1273313855s 1273313855s 0 1273313855s # Lock time 0 0 0 0 0 0 0 # Profile # Rank Query ID Response time Calls R/Call Ite # ==== ================== ====================== ===== =============== === # 1 0xB52E1970DE36E57F 1273313854.8595 100.0% 1 1273313854.8595 SELECT t_page_sample # Query 1: 0 QPS, 0x concurrency, ID 0xB52E1970DE36E57F at byte 0 ________ # This item is included in the report because it matches --limit. # pct total min max avg 95% stddev median # Count 100 1 # Exec time 100 1273313855s 1273313855s 1273313855s 1273313855s 1273313855s 0 1273313855s # Lock time 0 0 0 0 0 0 0 0 # Query_time distribution # 1us # 10us # 100us # 1ms # 10ms # 100ms # 1s # 10s+ ################################################################ # Tables # SHOW TABLE STATUS FROM `t_girl` LIKE 't_page_sample'\G # SHOW CREATE TABLE `t_girl`.`t_page_sample`\G # EXPLAIN select count(*) from t_page_sample\G [root@localhost ~]# |