利用strace和perf分析MySQL运行

利用strace和perf分析MySQL运行
周万春

perf
strace
pstack
pt-pmp
都是一类工具

[root@db01 ~]# perf top
Samples: 330  of event ‘cpu-clock‘, 4000 Hz, Event count (approx.): 42848685 lost: 0/0 drop: 0/0
Overhead  Shared Object     Symbol
  21.09%  [kernel]          [k] vmw_cmdbuf_header_submit
  19.02%  [kernel]          [k] e1000_xmit_frame
  15.93%  [kernel]          [k] _raw_spin_unlock_irqrestore

[root@db01 ~]# cp -a /usr/local/mysql/bin/mysqld /usr/local/mysql/bin/mysqld_bak
[root@db01 ~]# ls -lh /usr/local/mysql/bin/mysqld{,_bak}
-rwxr-xr-x 1 mysql mysql 249M Sep 27 16:53 /usr/local/mysql/bin/mysqld
-rwxr-xr-x 1 mysql mysql 249M Sep 27 16:53 /usr/local/mysql/bin/mysqld_bak

[root@db01 ~]# strip /usr/local/mysql/bin/mysqld_bak 
[root@db01 ~]# ls -lh /usr/local/mysql/bin/mysqld{,_bak}
-rwxr-xr-x 1 mysql mysql 249M Sep 27 16:53 /usr/local/mysql/bin/mysqld
-rwxr-xr-x 1 mysql mysql  27M Mar  8 10:36 /usr/local/mysql/bin/mysqld_bak
mysqld命令由200多M变成20多M

strace介绍及用途
    MySQL启动后默认会启动多少线程
    如何匹配conn_id和os_thread_id
    利用strace观察client的SQL执行
    利用strace观察server端执行

whereis pt-pmp
strace是一个用于诊断，分析Linux用户态进程的工具
pstrace  losf  gdb  pstack
Python写的 pstrace  pstack

简单使用
strace -T -tt -o /tmp/strace.log CMD
strace -T -tt CMD 2>&1 |tee /tmp/strace.log
strace -T -tt -s 100 -o /tmp/strace.log CMD
strace -T -tt -s 100 -ff /tmp/strace.log CMD
strace -T -tt -s 100 -e strace=xxx -o /tmp/strace.log CMD

MySQL默认启动的线程数
mysql -S /tmp/mysql.sock -p
use sys;
show tables;
select * from sys.session;
select * from performance_schema.threads;

用户态线程，用户运行的线程
select thd_id,conn_id,thread_os_id,name 
    from sys.processlist a,performance_schema.threads b
        where a.thd_id = b.thread_id and conn_id > 0;

[dba@localhost:mysql.sock] [(none)]> select thd_id,conn_id,thread_os_id,name 
    ->     from sys.processlist a,performance_schema.threads b
    ->         where a.thd_id = b.thread_id and conn_id > 0;
+--------+---------+--------------+--------------------------------+
| thd_id | conn_id | thread_os_id | name                           |
+--------+---------+--------------+--------------------------------+
|     26 |       1 |        23452 | thread/sql/compress_gtid_table |
|    656 |     631 |        23475 | thread/sql/one_connection      |
|    657 |     632 |         5081 | thread/sql/one_connection      |
+--------+---------+--------------+--------------------------------+
3 rows in set (0.13 sec)

[dba@localhost:mysql.sock] [(none)]> select * from sys.processlist;

操作系统查看
    ps -T `pidof mysqld`
利用 pstack
    pstack `pidof mysqld`
推荐MySQL 5.7以上的版本
    [dba@localhost:mysql.sock] [(none)]> select thread_id,name from performance_schema.threads;

conn_id 和 os_thread_id匹配
gdb attach 3711 拿到线程
拿到线程之后跟踪线程 strace -T -tt -s 100 -p 1042

gdb attach这个动作会导致要跟踪的进程卡着。
strace -T -tt -s 100 -o ./3711_c.log -p 3711

select thd_id,conn_id,pid,program_name from sys.processlist;
select * from sys.processlist where pid=1086\G

利用strace观察client的SQL执行
开发：为什么你们DB的响应这么慢呢？应用端大量的慢查询。
DBA有点不好意思：忙去查看show log干干净净，啥也没有？？？~~~~~~
人在家中坐，锅从天上来。
MySQL中没有慢查询，但应用端有很多慢查询，怎么办？

利用strace观察server端执行
利用strace观察mysqld端执行
这里就需要看看mysqld相关的io操作
    mysql:read,write,open
    innodb:pread64,pwrite64
    strace -o /tmp/zst_strace.log -T -tt -f -e trace=read,open,write,pwrite64,pread64 -p `pidof mysqld`
    strace -c /usr/local/mysql/bin/mysqld

strace -o /tmp/zst_strace.log -T -tt -ff -p `pidof mysqld`
-ff 参数，在跟踪的线程fork出新的thread时，会产生一个新文件存放。

利用获取的线程id在MySQL查询时，看看都是干什么的？
select thread_id,thread_os_id,name 
    from performance_schema.threads
        where thread_os_id in (15871,15872,15873,15901);

ls -l /proc/3536/fd/11

yum install ps_mem

抓包
tcpdump -i eth0 -S 0 tcp port 3306 -w xxx.cap
结合wireshark

ps -T `pidof mysqld`
top -H -c -p `pidof mysqld`