strace 命令分析mysql的相关的问题
Posted
tags:
篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了strace 命令分析mysql的相关的问题相关的知识,希望对你有一定的参考价值。
strace 命令分析mysql的相关的问题
使用方式: strace -p pid or strace command
本篇博文主要简单介绍下面关于MySQL的5个问题:
利用strace观察mysqld对my.cnf 配置文件的加载顺序
MySQL启动后默认会启动多少线程
如何匹配conn_id和os_thread_id
利用strace观察client的SQL执行
利用strace观察server端执行
1.strace观察mysqld对my.cnf 配置文件的加载顺序
命令如下:
strace -T -tt -s 100 -o start.log /usr/local/mysql/bin/mysqld
[[email protected] ~]# cat -n start.log |sed -n ‘152,165p‘
152 03:43:41.399411 futex(0x7fb060f058b8, FUTEX_WAKE_PRIVATE, 2147483647) = 0 <0.000013>
153 03:43:41.400839 stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=11064, ...}) = 0 <0.000015>
154 03:43:41.400951 open("/etc/my.cnf", O_RDONLY) = 3 <0.000024>
155 03:43:41.401026 fstat(3, {st_mode=S_IFREG|0644, st_size=11064, ...}) = 0 <0.000009>
156 03:43:41.401068 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb061d94000 <0.000016>
157 03:43:41.401116 read(3, "[client]
port = 3306
[mysql]
auto-rehash
prompt="\\[email protected]\\h [\\d]>"
#pager="less -i -n -S"
"..., 4096) = 4096 <0.000016>
158 03:43:41.401211 read(3, " # 0
#rpl_semi_sync_master_timeout =1000 # 1000(1 second)
#plu"..., 4096) = 4096 <0.000011>
159 03:43:41.401303 read(3, " # on
innodb_change_buffering =all # all
innodb"..., 4096) = 2872 <0.000011>
160 03:43:41.401376 read(3, "", 4096) = 0 <0.000010>
161 03:43:41.401423 close(3) = 0 <0.000052>
162 03:43:41.401564 munmap(0x7fb061d94000, 4096) = 0 <0.000080>
163 03:43:41.401777 stat("/etc/mysql/my.cnf", 0x7fff5ec1c170) = -1 ENOENT (No such file or directory) <0.000022>
164 03:43:41.402070 stat("/usr/local/mysql/etc/my.cnf", 0x7fff5ec1c170) = -1 ENOENT (No such file or directory) <0.000016>
165 03:43:41.402134 stat("/root/.my.cnf", 0x7fff5ec1c170) = -1 ENOENT (No such file or directory) <0.000012>
2. 查看mysql启动的线程数
操作系统查看:
ps -T pidof mysqld
[[email protected] opt]# ps -T `pidof mysqld`|sed ‘1d‘
59592 59592 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59593 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59594 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59595 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59596 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59597 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59598 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59599 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59600 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59601 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59602 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59603 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59604 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59607 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59608 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59609 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59610 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59611 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59612 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59613 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59614 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59615 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59616 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59617 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59618 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59619 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
59592 59620 pts/0 Sl 0:00 /usr/local/mysql/bin/mysqld
利用pstack
pstack `pidof mysql` 或者pstack `pidof mysqld` 2>&1|tee /tmp/pstack.log
下面的这个过程特别的慢。会导致mysql夯筑,不要线上直接使用
MySQL默认的启动线程数是28
推荐MySQL 5.7以上的版本查看mysql默认启动的线程数为28个
select thread_id, name from performance_schema.threads;
select name,count(*) from performance_schema.threads group by name;
[email protected] [(none)]>select name,count(*) from performance_schema.threads group by name;
+----------------------------------------+----------+
| name | count(*) |
+----------------------------------------+----------+
| thread/innodb/buf_dump_thread | 1 |
| thread/innodb/dict_stats_thread | 1 |
| thread/innodb/io_ibuf_thread | 1 |
| thread/innodb/io_log_thread | 1 |
| thread/innodb/io_read_thread | 4 |
| thread/innodb/io_write_thread | 4 |
| thread/innodb/page_cleaner_thread | 1 |
| thread/innodb/srv_error_monitor_thread | 1 |
| thread/innodb/srv_lock_timeout_thread | 1 |
| thread/innodb/srv_master_thread | 1 |
| thread/innodb/srv_monitor_thread | 1 |
| thread/innodb/srv_purge_thread | 1 |
| thread/innodb/srv_worker_thread | 3 |
| thread/sql/compress_gtid_table | 1 |
| thread/sql/main | 1 |
| thread/sql/one_connection | 1 |
| thread/sql/signal_handler | 1 |
| thread/sql/thread_timer_notifier | 1 |
+----------------------------------------+----------+
18 rows in set (0.00 sec)
[email protected] [(none)]>select thread_id, name from performance_schema.threads;
+-----------+----------------------------------------+
| thread_id | name |
+-----------+----------------------------------------+
| 1 | thread/sql/main |
| 2 | thread/sql/thread_timer_notifier |
| 3 | thread/innodb/io_ibuf_thread |
| 4 | thread/innodb/io_read_thread |
| 5 | thread/innodb/io_read_thread |
| 6 | thread/innodb/io_read_thread |
| 7 | thread/innodb/io_read_thread |
| 8 | thread/innodb/io_log_thread |
| 9 | thread/innodb/io_write_thread |
| 10 | thread/innodb/io_write_thread |
| 11 | thread/innodb/io_write_thread |
| 12 | thread/innodb/io_write_thread |
| 13 | thread/innodb/page_cleaner_thread |
| 16 | thread/innodb/srv_lock_timeout_thread |
| 17 | thread/innodb/srv_error_monitor_thread |
| 18 | thread/innodb/srv_monitor_thread |
| 19 | thread/innodb/srv_master_thread |
| 20 | thread/innodb/srv_purge_thread |
| 21 | thread/innodb/srv_worker_thread |
| 22 | thread/innodb/srv_worker_thread |
| 23 | thread/innodb/srv_worker_thread |
| 24 | thread/innodb/buf_dump_thread |
| 25 | thread/innodb/dict_stats_thread |
| 26 | thread/sql/signal_handler |
| 27 | thread/sql/compress_gtid_table |
| 29 | thread/sql/one_connection |
+-----------+----------------------------------------+
26 rows in set (0.00 sec)
如何匹配conn_id和os_thread_id
MySQL 5.6时代采用的方法:
gdb attach 11646
strace -T -tt -s 100 -p11646
MySQL 5.7 & 8.0时代采用的方法:
可以利用sys.processlist 和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;
查询报错:
[email protected] [sys]>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;
ERROR 1104 (42000): The SELECT would examine more than MAX_JOIN_SIZE rows; check your WHERE and use SET SQL_BIG_SELECTS=1 or SET MAX_JOIN_SIZE=# if the SELECT is okay
解决办法:
[email protected] [sys]>
[email protected] [sys]>SET SQL_BIG_SELECTS=1 ;
Query OK, 0 rows affected (0.00 sec)
[email protected] [sys]>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 | 13068 | thread/sql/compress_gtid_table |
| 27 | 2 | 13071 | thread/sql/one_connection |
+--------+---------+--------------+--------------------------------+
2 rows in set (0.07 sec)
[email protected] [sys]>
strace追踪当前连接的线程ID,来查看对系统os的操作
strace -T -tt -e trace=write,access,read,open,pwrite64,pread64 -p 13071 2>&1 |tee >/tmp/strace.log
演示:
数据库操作:
show databases;
use test01;
use tets02;
create table tutorials_tbl(
tutorial_id INT NOT NULL AUTO_INCREMENT,
tutorial_title VARCHAR(100) NOT NULL,
tutorial_author VARCHAR(40) NOT NULL,
submission_date DATE,
PRIMARY KEY ( tutorial_id )
);;
insert into tutorials_tbl(tutorial_id,tutorial_title,tutorial_author,submission_date) values(‘1‘,‘作文‘,‘三毛‘,‘2019-03-10‘);
select * from tutorials_tbl;
利用strace观察client端SQL执行,也就是跟踪进程输出:
strace -T -tt -e trace=recvfrom,write,access,read,open,pwrite64,pread64 -p 13071
[[email protected] ~]# strace -T -tt -e trace=recvfrom,write,access,read,open,pwrite64,pread64 -p 13071
strace: Process 13071 attached
06:05:20.074087 recvfrom(59, "22 ", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000138>
06:05:20.074539 recvfrom(59, "3SELECT DATABASE()", 18, MSG_DONTWAIT, NULL, NULL) = 18 <0.000119>
06:05:20.074891 write(35, "2019-03-17T06:05:20.074757+08:00"..., 63) = 63 <0.000345>
06:05:20.075510 recvfrom(59, "7 ", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000097>
06:05:20.075749 recvfrom(59, "2test01", 7, MSG_DONTWAIT, NULL, NULL) = 7 <0.000109>
06:05:20.076098 access("./test01", F_OK) = 0 <0.000102>
06:05:20.076372 write(35, "2019-03-17T06:05:20.076273+08:00"..., 54) = 54 <0.000115>
06:05:20.076877 recvfrom(59, 0x7f2e48007990, 4, MSG_DONTWAIT, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) <0.000217>
06:05:46.672935 recvfrom(59, "17 ", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000117>
06:05:46.673241 recvfrom(59, "3show databases", 15, MSG_DONTWAIT, NULL, NULL) = 15 <0.000099>
06:05:46.673547 write(35, "2019-03-17T06:05:46.673430+08:00"..., 60) = 60 <0.000189>
06:05:46.675841 recvfrom(59, 0x7f2e48007990, 4, MSG_DONTWAIT, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) <0.000117>
06:06:05.768163 recvfrom(59, "22 ", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000260>
06:06:05.768871 recvfrom(59, "3SELECT DATABASE()", 18, MSG_DONTWAIT, NULL, NULL) = 18 <0.000376>
06:06:05.769551 write(35, "2019-03-17T06:06:05.769412+08:00"..., 63) = 63 <0.000137>
06:06:05.770088 recvfrom(59, "7 ", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000130>
06:06:05.770362 recvfrom(59, "2test02", 7, MSG_DONTWAIT, NULL, NULL) = 7 <0.000096>
06:06:05.770599 access("./test02", F_OK) = 0 <0.000114>
06:06:05.770882 write(35, "2019-03-17T06:06:05.770766+08:00"..., 54) = 54 <0.000191>
06:06:05.772482 recvfrom(59, "17 ", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000167>
06:06:05.772843 recvfrom(59, "3show databases", 15, MSG_DONTWAIT, NULL, NULL) = 15 <0.000095>
06:06:05.773231 write(35, "2019-03-17T06:06:05.773085+08:00"..., 60) = 60 <0.000115>
06:06:05.775112 recvfrom(59, "f ", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000274>
06:06:05.775585 recvfrom(59, "3show tables", 12, MSG_DONTWAIT, NULL, NULL) = 12 <0.000100>
06:06:05.775908 write(35, "2019-03-17T06:06:05.775782+08:00"..., 57) = 57 <0.000290>
06:06:05.776987 recvfrom(59, 0x7f2e48007990, 4, MSG_DONTWAIT, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) <0.000198>
06:07:14.887093 recvfrom(59, "324 ", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000016>
06:07:14.887219 recvfrom(59, "3create table tutorials_tbl(
"..., 212, MSG_DONTWAIT, NULL, NULL) = 212 <0.000016>
06:07:14.887395 write(35, "2019-03-17T06:07:14.887364+08:00"..., 257) = 257 <0.000050>
06:07:14.887562 access("./test02/tutorials_tbl.frm", F_OK) = -1 ENOENT (No such file or directory) <0.000306>
06:07:14.888180 access("./test02/tutorials_tbl.frm", F_OK) = -1 ENOENT (No such file or directory) <0.000144>
06:07:14.888411 open("./test02/tutorials_tbl.frm", O_RDWR|O_CREAT|O_TRUNC, 0640) = 83 <0.000877>
06:07:14.889915 write(83, " "..., 4096) = 4096 <0.000226>
06:07:14.890372 write(83, "// ", 3) = 3 <0.000135>
06:07:14.890799 write(83, " ", 4) = 4 <0.000024>
06:07:14.890906 write(83, " "..., 4096) = 4096 <0.000035>
06:07:14.890993 pwrite64(83, "3761
f3 201 000 i12571 2! "..., 64, 0) = 64 <0.000020>
06:07:14.891073 pwrite64(83, "11
4 1 12002 33 4 377PRIMARY377"..., 33, 4096) = 33 <0.000019>
06:07:14.891183 write(83, "377 "..., 431) = 431 <0.000020>
06:07:14.891448 write(83, " ", 2) = 2 <0.000028>
06:07:14.891732 write(83, "6 ", 2) = 2 <0.000023>
06:07:14.891814 write(83, "InnoDB", 6) = 6 <0.000019>
06:07:14.891881 write(83, " ", 6) = 6 <0.000018>
06:07:14.891948 write(83, "
", 13) = 13 <0.000018>
06:07:14.892015 write(83, " ", 2) = 2 <0.000019>
06:07:14.892078 write(83, " ", 2) = 2 <0.000205>
06:07:14.892358 write(83, "302 20 "..., 288) = 288 <0.000039>
06:07:14.892453 write(83, "w 54224) "..., 119) = 119 <0.000023>
06:07:14.892526 write(83, "4fvv 2 33 17 3! ", 17) = 17 <0.000281>
06:07:14.892864 write(83, "517,,16 [email protected]