MySQL SQL Profiler性能分析器

qlks

申请了MySQL版主，说要15天的考察期
看来要好好表现了。不能再潜水了。

看到很多朋友问MySQL的性能分析器
因为MySQL在这方面做得比较差，也可能我不知道
没有Microsoft的SQL Profiler,也没有Oracle的Audit和AWR
所以我们很难得到一些SQL语句的统计，这也给我们调优带来了困难
更难的是对MySQL的追踪
以前写过个，不过在看过mysql网站上的一个bash脚本后，觉得自己的那个就是小巫见大巫了
现拿来分享给大家，很简单
# 取得网卡eth0上的所有操作
time tcpdump -i eth0 -s 1500 -w 20060427-db-traffic-01.dmp
# 这个可以指定特定IP请求的操作，可用于追踪
time tcpdump -i eth0 -s 1500 src host 192.168.2.10 -w 20060427-db-traffic-01.dmp
# 这个是格式化输出你要结果
strings 20060427-db-traffic-01.dmp | grep -i 'select' | awk '{printf("%s %s %s %s\n", $1,$2,$3, $4);}'| sort| uniq -c | awk '{printf("%06ld %s %s %s %s\n", $1,$2,$3,$4,$5);}'|sort

得到的结果:
cpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 1500 bytes
12000 packets captured
12000 packets received by filter
0 packets dropped by kernel
real 0m8.666s
user 0m0.006s
sys 0m0.016s
--------
000001 select last_insert_id() from system_parameter
...
000122 select count(1) from visit_tracking
000122 select visitor_id
000800 select web_page_id , web_page_type_id
000800 select web_page_type_id , name
003200 select count(1) from hit_count
006400 select pd.parameter_value,
006400 select rp.user_id , rp.update_time

可以看到执行各种select的次数，当然改一下就可以看insert,update这种操作次数
配合log-slow-queries，你可以进一步的优化

oncity

呵，利害。如果能有每条SQL 的执行时间报告就更好。。。

yejr

mssql的探测器还能分析出i/o次数，牛多了

qlks

yejr要求还真高啊
这个脚本么简单易用
有一定实用价值

当然和mssql的profiler比功能确实是弱多了

yejr

http://hackmysql.com/mysqlsniffer
这是c写的，分析结果更详细

imcindyzhang

看来这位就是jcy同志啦～
潜水挺也给你顶一个拉～嘿嘿～

gladness

嗯，是个好办法。但是有个问题，当查询语句换行的时候就不行了。比如我的SQL是这样写的
select *
from ....
where ....
这时候只能把第一行查出来。
但不管怎样也算是一个比较有效的方法了。
这里还有一个更牛的方法，大家可以试一下。

http://www.mysqlperformanceblog. ... log-analyzes-tools/
总的说来是编译mysql，编译前打个补丁。之后的使用效果是相当不错的：

[gulei@ARCH1220 ~]$ ./mysql_slow_log_parser /usr/local/mysql/var/ARCH1220-slow.log

Starting...
### 1 Query
### Total time: 0.000196, Average time: 0.000196
### Taking 0.000196  seconds to complete
### Rows analyzed 0
explain select * from test where no=v_no;

explain select * from test where no=v_no;


### 1 Query
### Total time: 0.000225, Average time: 0.000225
### Taking 0.000225  seconds to complete
### Rows analyzed 0
insert into tupdate values('XXX',XXX);

insert into tupdate values('abc',100);


### 1 Query
### Total time: 0.000215, Average time: 0.000215
### Taking 0.000215  seconds to complete
### Rows analyzed 0
set v_uidnum=XXX;

set v_uidnum=0;


### 1 Query
### Total time: 0.000197, Average time: 0.000197
### Taking 0.000197  seconds to complete
### Rows analyzed 0
set @@autocommit=XXX;

set @@autocommit=0;


### 1 Query
### Total time: 0.000304, Average time: 0.000304
### Taking 0.000304  seconds to complete
### Rows analyzed 0
explain select * from test where no=@v_no;

explain select * from test where no=@v_no;


### 1 Query
### Total time: 0.000177, Average time: 0.000177
### Taking 0.000177  seconds to complete
### Rows analyzed 0
set autocommit=XXX;

set autocommit=0;


### 1 Query
### Total time: 0.000357, Average time: 0.000357
### Taking 0.000357  seconds to complete
### Rows analyzed 0
select @v_no;

select @v_no;


### 1 Query
### Total time: 0.000345, Average time: 0.000345
### Taking 0.000345  seconds to complete
### Rows analyzed 0
explain select * from test where no=concat('XXX','XXX');

explain select * from test where no=concat('100','0');


### 1 Query
### Total time: 0.000247, Average time: 0.000247
### Taking 0.000247  seconds to complete
### Rows analyzed 24
select * from users;

select * from users;


### 1 Query
### Total time: 0.000229, Average time: 0.000229
### Taking 0.000229  seconds to complete
### Rows analyzed 9
select * from grade;

select * from grade;


### 1 Query
### Total time: 0.000297, Average time: 0.000297
### Taking 0.000297  seconds to complete
### Rows analyzed 1
show indexes from tupdate;

show indexes from tupdate;


### 1 Query
### Total time: 0.116153, Average time: 0.116153
### Taking 0.116153  seconds to complete
### Rows analyzed 131072
select * from test where name like 'XXX';

select * from test where name like '%1310%';


### 1 Query
### Total time: 0.001337, Average time: 0.001337
### Taking 0.001337  seconds to complete
### Rows analyzed 2
desc students;

desc students;


### 1 Query
### Total time: 0.057925, Average time: 0.057925
### Taking 0.057925  seconds to complete
### Rows analyzed 0
create table users(uid varchar(XXX) primary key,uname varchar(XXX)) engine=innodb;

create table users(uid varchar(20) primary key,uname varchar(40)) engine=innodb;


### 1 Query
### Total time: 9.3e-05, Average time: 9.3e-05
### Taking 0.000093  seconds to complete
### Rows analyzed 0
show create tupdate;

show create tupdate;


### 1 Query
### Total time: 0.000536, Average time: 0.000536
### Taking 0.000536  seconds to complete
### Rows analyzed 2
use test;
show databases;

use test;
show databases;


### 1 Query
### Total time: 0.000155, Average time: 0.000155
### Taking 0.000155  seconds to complete
### Rows analyzed 0
show create table tupdate;

show create table tupdate;


### 1 Query
### Total time: 0.000313, Average time: 0.000313
### Taking 0.000313  seconds to complete
### Rows analyzed 0
explain select * from test where no=XXX;

explain select * from test where no=10000;


### 1 Query
### Total time: 0.000297, Average time: 0.000297
### Taking 0.000297  seconds to complete
### Rows analyzed 0
set @v_no:='XXX';

set @v_no:='1000';


### 1 Query
### Total time: 9.4e-05, Average time: 9.4e-05
### Taking 0.000094  seconds to complete
### Rows analyzed 0
set @v_uidnum=XXX;

set @v_uidnum=0;


### 1 Query
### Total time: 0.000194, Average time: 0.000194
### Taking 0.000194  seconds to complete
### Rows analyzed 0
update tupdate set remain=XXX;

update tupdate set remain=80;


### 1 Query
### Total time: 0.064882, Average time: 0.064882
### Taking 0.064882  seconds to complete
### Rows analyzed 0
create table tupdate
( uid varchar(XXX),
remain int)engine=innodb;

create table tupdate
( uid varchar(20),
remain int)engine=innodb;


### 2 Queries
### Total time: 0.002204, Average time: 0.001102
### Taking 0.000748 , 0.001456  seconds to complete
### Rows analyzed 2 and 2
desc users;

desc users;


### 2 Queries
### Total time: 0.071575, Average time: 0.0357875
### Taking 0.035699 , 0.035876  seconds to complete
### Rows analyzed 0 and 0
rollback;

rollback;


### 2 Queries
### Total time: 0.023405, Average time: 0.0117025
### Taking 0.002301 , 0.021104  seconds to complete
### Rows analyzed 1072 and 11072
select * from test where no>XXX;

select * from test where no>120000;


### 2 Queries
### Total time: 0.16847, Average time: 0.084235
### Taking 0.083851 , 0.084619  seconds to complete
### Rows analyzed 131072 and 131072
select count(*) from test;

select count(*) from test;


### 2 Queries
### Total time: 0.048319, Average time: 0.0241595
### Taking 0.024039 , 0.024280  seconds to complete
### Rows analyzed 3 and 3
show indexes from test;

show indexes from test;


### 2 Queries
### Total time: 0.001163, Average time: 0.0005815
### Taking 0.000549 , 0.000614  seconds to complete
### Rows analyzed 0 and 0
explain select * from test where no='XXX';

explain select * from test where no='10000';


### 3 Queries
### Total time: 0.000342, Average time: 0.000114
### Taking 0.000102 , 0.000107 , 0.000133  seconds to complete
### Rows analyzed 0, 0 and 0
select @@autocommit;

select @@autocommit;


### 3 Queries
### Total time: 0.000861, Average time: 0.000287
### Taking 0.000271 , 0.000295 , 0.000295  seconds to complete
### Rows analyzed 0, 0 and 0
explain select * from users where uid='XXX';

explain select * from users where uid='10';


### 3 Queries
### Total time: 0.000898, Average time: 0.000299333333333333
### Taking 0.000230 , 0.000242 , 0.000426  seconds to complete
### Rows analyzed 0, 0 and 0
explain select * from users where uid=XXX;

explain select * from users where uid=10;


### 4 Queries
### Total time: 0.001043, Average time: 0.00026075
### Taking 0.000196 , 0.000212 , 0.000234 , 0.000401  seconds to complete
### Rows analyzed 0, 0, 0 and 0
explain select * from test where name like 'XXX';

explain select * from test where name like 'name1310%';


### 4 Queries
### Total time: 0.000204, Average time: 5.1e-05
### Taking 0.000025 , 0.000027 , 0.000037 , 0.000115  seconds to complete
### Rows analyzed 1, 1, 3 and 131072
# administrator command: Quit;

# administrator command: Quit;


### 4 Queries
### Total time: 8.829385, Average time: 2.20734625
### Taking 0.000305 , 0.000344 , 3.269293 , 5.559443  seconds to complete
### Rows analyzed 0, 0, 0 and 0
update tupdate set remain=remain-XXX where uid='XXX' and remain-XXX>=XXX;

update tupdate set remain=remain-50 where uid='abc' and remain-50>=0;


### 4 Queries
### Total time: 0.003654, Average time: 0.0009135
### Taking 0.000760 , 0.000845 , 0.000849 , 0.001200  seconds to complete
### Rows analyzed 2, 2, 2 and 2
desc tupdate;

desc tupdate;


### 5 Queries
### Total time: 0.001163, Average time: 0.0002326
### Taking 0.000190 , 0.000198 , 0.000219 , 0.000224 , 0.000332  seconds to complete
### Rows analyzed 4, 4, 4, 4 and 4
select * from students where snumber < XXX;

select * from students where snumber < 100;


### 5 Queries
### Total time: 0.001593, Average time: 0.0003186
### Taking 0.000288 , 0.000314 , 0.000315 , 0.000322 , 0.000354  seconds to complete
### Rows analyzed 2, 2, 2, 2 and 2
show databases;

show databases;


### 6 Queries
### Total time: 0.005737, Average time: 0.000956166666666667
### Taking 0.000797 , 0.000812 , 0.000817 , 0.000909 , 0.000977 , 0.001425  seconds to complete
### Rows analyzed 3, 3, 3, 3, 3 and 3
desc test;

desc test;


### 6 Queries
### Total time: 24.920263, Average time: 4.15337716666667
### Taking 0.000274 , 0.000284 , 0.000326 , 5.259989 , 5.269755 , 14.389635  seconds to complete
### Rows analyzed 0, 0, 0, 0, 0 and 0
update tupdate set remain=remain-XXX where uid='XXX';

update tupdate set remain=remain-10 where uid='abc';


### 13 Queries
### Total time: 0.00376, Average time: 0.000289230769230769
### Taking 0.000150  to 0.000604  seconds to complete
### Rows analyzed 4 - 5
show tables;

show tables;


### 13 Queries
### Total time: 0.312347, Average time: 0.0240266923076923
### Taking 0.000070  to 0.044422  seconds to complete
### Rows analyzed 0 - 0
commit;

commit;


### 18 Queries
### Total time: 0.003791, Average time: 0.000210611111111111
### Taking 0.000171  to 0.000486  seconds to complete
### Rows analyzed 0 - 1
select * from tupdate;

select * from tupdate;


### 22 Queries
### Total time: 0.005829, Average time: 0.000264954545454545
### Taking 0.000021  to 0.004444  seconds to complete
### Rows analyzed 0 - 0
;

;


### 24 Queries
### Total time: 1.055499, Average time: 0.043979125
### Taking 0.012817  to 0.084962  seconds to complete
### Rows analyzed 0 - 0
insert into users values(@v_uidnum:=@v_uidnum+XXX,concat('XXX',@v_uidnum));

insert into users values(@v_uidnum:=@v_uidnum+1,concat('name',@v_uidnum));

zysno1

在my.cnf里加上log-slow-queries
log-queries-not-using-indexes

会自动在datadir下面生成hostname-slow.log。这个很有用。会记录所有执行时间超过限时的query。并且记录这个query的执行时间。

ncowboy

原帖由 oncity 于 2006-9-27 10:42 发表
呵，利害。如果能有每条SQL 的执行时间报告就更好。。。

1. log-slow-queries
   
2. long-query-time=0

复制代码

打个补丁。让它记录小于1秒的查询。

qlks

LS的方法可以的