straceコマンドmysqlに関する問題の解析
straceコマンドmysqlに関する問題の解析
このブログでは、MySQLに関する5つの質問を簡単に紹介します.
1.strace観察mysqld対my.cnfプロファイルのロード順序
コマンドは次のとおりです.
2.mysql起動スレッド数の表示
オペレーティングシステムの表示:ps-T
pstackの利用
次のこの過程は特に遅いです.mysqlの打ち上げにつながるので、オンラインで直接MySQLを使用しないでください.デフォルトの起動スレッド数は28です.
推奨MySQL 5.7以上のバージョンmysqlのデフォルト起動スレッド数は28個
conn_のマッチング方法idとos_thread_id
MySQL 5.6時代に採用された方法:
MySQL 5.7&8.0時代に採用された方法:
sysを利用できます.プロセスリストとperformance_schema.threadsによる関連付け
クエリエラー:
解決策:
straceは現在接続されているスレッドIDを追跡し、システムosに対する操作を表示する
デモ:データベース操作:
クライアント側SQLの実行をstraceで観察します.つまり、プロセス出力を追跡します.
MySQL 5.7以降はsysを利用できます.processlist:
strace -T -tt -s 100 -o/tmp/strace.log -p $PID
ここではmysqldに関するio操作を見る必要があります.
取得したスレッドidを利用してMySQLでクエリーして、何をしているのか見てみましょう.
straceコマンドの一般的な簡単な使用方法は次のとおりです.
本博文はテンセントのスクリーンの中の課程を勉強してここにまとめたものです.コンテンツ・カリキュラムのアドレスは次のとおりです.https://ke.qq.com/course/384101
strace故障分析MySQLケースは以下の通りです.https://ke.qq.com/course/331538『MySQL運維の私が踏んだ穴』https://www.percona.com/blog/2010/07/16/analyzing-the-distribution-of-innodb-log-filewrites/https://mp.weixin.qq.com/s/wP_ivItVKbodkV1FluTcsg(楊奇?龍の公衆番号:システム調?用追跡分析神器?--strace)https://www.actionsky.com/index.php?id=2393(binlog rotateによる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
[root@mgr04 ~]# 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=\"\\\\u@\\\\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, " #\ton
innodb_change_buffering =all #\tall
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[root@mgr04 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/mysqldpstackの利用
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;root@localhost [(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)root@localhost [(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 -p11646MySQL 5.7&8.0時代に採用された方法:
sysを利用できます.プロセスリストと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;クエリエラー:
root@localhost [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解決策:
root@localhost [sys]>
root@localhost [sys]>SET SQL_BIG_SELECTS=1 ;
Query OK, 0 rows affected (0.00 sec)
root@localhost [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)
root@localhost [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;クライアント側SQLの実行をstraceで観察します.つまり、プロセス出力を追跡します.
strace -T -tt -e trace=recvfrom,write,access,read,open,pwrite64,pread64 -p 13071[root@mgr04 ~]# 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\0\0\0", 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\0\0\0", 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\0\0\0", 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\0\0\0", 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\0\0\0", 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\0\0\0", 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\0\0\0", 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\0\0\0", 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, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096 <0.000226>
06:07:14.890372 write(83, "//\0", 3) = 3 <0.000135>
06:07:14.890799 write(83, "\0 \0\0", 4) = 4 <0.000024>
06:07:14.890906 write(83, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096 <0.000035>
06:07:14.890993 pwrite64(83, "\376\1
\f\3\0\0\20\1\0\0000\0\0i\1\257\1\0\0\0\0\0\0\0\0\0\2!\0\t\0"..., 64, 0) = 64 <0.000020>
06:07:14.891073 pwrite64(83, "\1\1\0\0
\0\0\0\4\0\1\0\0\0\1\200\2\0\0\33\0\4\0\377PRIMARY\377"..., 33, 4096) = 33 <0.000019>
06:07:14.891183 write(83, "\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 431) = 431 <0.000020>
06:07:14.891448 write(83, "\0\0", 2) = 2 <0.000028>
06:07:14.891732 write(83, "\6\0", 2) = 2 <0.000023>
06:07:14.891814 write(83, "InnoDB", 6) = 6 <0.000019>
06:07:14.891881 write(83, "\0\0\0\0\0\0", 6) = 6 <0.000018>
06:07:14.891948 write(83, "\r\0\0\0\0\0\0\0\0\0\0\0\0", 13) = 13 <0.000018>
06:07:14.892015 write(83, "\0\0", 2) = 2 <0.000019>
06:07:14.892078 write(83, "\0\0", 2) = 2 <0.000205>
06:07:14.892358 write(83, "\30\2\0\20\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 288) = 288 <0.000039>
06:07:14.892453 write(83, "w\0\5\4\2\24) "..., 119) = 119 <0.000023>
06:07:14.892526 write(83, "\4\f\v\v\0\2\0\0\33\0\17\0\0\3!\0\0", 17) = 17 <0.000281>
06:07:14.892864 write(83, "\5\17,,\1\6\0\0\0@\0\0\0\17!\0\0", 17) = 17 <0.000027>
06:07:14.892949 write(83, "\6\20?x\0004\1\0\0@\0\0\0\17!\0\0", 17) = 17 <0.000022>
06:07:14.893021 write(83, "\7\20
\0\255\1\0p\200\0\0\0\16\10\0\0", 17) = 17 <0.000022>
06:07:14.893093 write(83, "\377", 1) = 1 <0.000021>
06:07:14.893162 write(83, "tutorial_id\377", 12) = 12 <0.000188>
06:07:14.893407 write(83, "tutorial_title\377", 15) = 15 <0.000027>
06:07:14.893491 write(83, "tutorial_author\377", 16) = 16 <0.000021>
06:07:14.893559 write(83, "submission_date\377\0", 17) = 17 <0.000376>
06:07:14.911739 open("./test02/", O_RDONLY) = 84 <0.000037>
06:07:14.912031 open("./test02/tutorials_tbl.frm", O_RDONLY) = 83 <0.000026>
06:07:14.912188 read(83, "\376\1
\f\3\0\0\20\1\0\0000\0\0i\1\257\1\0\0\0\0\0\0\0\0\0\2!\0\t\0"..., 64) = 64 <0.000036>
06:07:14.912772 read(83, "//\0\0 \0\0", 7) = 7 <0.000227>
06:07:14.913170 read(83, "\30\2\0\20\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 288) = 288 <0.000018>
06:07:14.913272 read(83, "\1\1\0\0
\0\0\0\4\0\1\0\0\0\1\200\2\0\0\33\0\4\0\377PRIMARY\377"..., 33) = 33 <0.000015>
06:07:14.913485 pread64(83, "\0\0\6\0InnoDB\0\0\0\0\0\0\r\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 33, 4888) = 33 <0.000019>
06:07:14.913579 pread64(83, "\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 431, 4457) = 431 <0.000252>
06:07:14.914061 read(83, "w\0\5\4\2\24) "..., 248) = 248 <0.000137>
06:07:14.914505 open("./test02/tutorials_tbl.ibd", O_RDWR|O_CREAT|O_EXCL, 0640) = 83 <0.000603>
06:07:14.915312 pwrite64(83, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 65536, 0) = 65536 <0.000124>
06:07:14.925026 pwrite64(83, "\315\331\225\240\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 16384, 0) = 16384 <0.000227>
06:07:14.929051 open("./test02/tutorials_tbl.ibd", O_RDWR) = 83 <0.000251>
06:07:14.929985 pwrite64(83, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 32768, 65536) = 32768 <0.000175>
06:07:14.932909 pwrite64(4, "\200\0\24\211\2\0\0A\0\0\0^)\242\0\0\1\25\1A\\\215q\213\0\0\0\0\0\0\0\1"..., 10752, 2684416) = 10752 <0.000223>
06:07:14.935588 pwrite64(4, "\200\0\24\220\1\262\0\356\0\0\0^\377\4-\2\1r\360\377\377\377\377\4-\2\1v\360\377\377\377"..., 512, 2688000) = 512 <0.000191>
06:07:14.938442 pwrite64(4, "\200\0\24\220\2\0\0\356\0\0\0^\377\4-\2\1r\360\377\377\377\377\4-\2\1v\360\377\377\377"..., 1536, 2688000) = 1536 <0.000213>
06:07:14.942039 pwrite64(4, "\200\0\24\222\0C\0006\0\0\0^\1r\\\215s\222\0\0\0\0\0\0\0\1Number"..., 512, 2689024) = 512 <0.000406>
06:07:14.944196 write(37, "\222s\215\\!\372\273\23\0=\0\0\0\23\r\0\0\0\0\1\232-\217\206\32\271\21\351\263x\0\f"..., 346) = 346 <0.000176>
06:07:14.955507 recvfrom(59, 0x7f2e48007990, 4, MSG_DONTWAIT, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) <0.000233>
06:10:27.191228 recvfrom(59, "\201\0\0\0", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000014>
06:10:27.191364 recvfrom(59, "\3insert into tutorials_tbl(tutor"..., 129, MSG_DONTWAIT, NULL, NULL) = 129 <0.000012>
06:10:27.191504 write(35, "2019-03-17T06:10:27.191478+08:00"..., 174) = 174 <0.000040>
06:10:27.191627 open("./test02/tutorials_tbl.frm", O_RDONLY) = 84 <0.000020>
06:10:27.191738 read(84, "\376\1
\f\3\0\0\20\1\0\0000\0\0i\1\257\1\0\0\0\0\0\0\0\0\0\2!\0\t\0"..., 64) = 64 <0.000012>
06:10:27.191799 read(84, "//\0\0 \0\0", 7) = 7 <0.000010>
06:10:27.191856 read(84, "\30\2\0\20\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 288) = 288 <0.000010>
06:10:27.191913 read(84, "\1\1\0\0
\0\0\0\4\0\1\0\0\0\1\200\2\0\0\33\0\4\0\377PRIMARY\377"..., 33) = 33 <0.000022>
06:10:27.191973 pread64(84, "\0\0\6\0InnoDB\0\0\0\0\0\0\r\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 33, 4888) = 33 <0.000010>
06:10:27.192176 pread64(84, "\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 431, 4457) = 431 <0.000012>
06:10:27.192248 read(84, "w\0\5\4\2\24) "..., 248) = 248 <0.000010>
06:10:27.192584 access("./test02/tutorials_tbl.TRG", F_OK) = -1 ENOENT (No such file or directory) <0.000025>
06:10:27.192854 pwrite64(4, "\200\0\24\222\2\0\0006\0\0\0`\1r\\\215s\222\0\0\0\0\0\0\0\1Number"..., 1024, 2689024) = 1024 <0.000281>
06:10:27.221914 write(37, "St\215\\!\372\273\23\0=\0\0\0m\16\0\0\0\0\0\232-\217\206\32\271\21\351\263x\0\f"..., 421) = 421 <0.000313>
06:10:27.245928 recvfrom(59, 0x7f2e48007990, 4, MSG_DONTWAIT, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) <0.000232>
submission_date
06:20:22.957977 recvfrom(59, "\34\0\0\0", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000016>
06:20:22.958107 recvfrom(59, "\3select * from tutorials_tbl", 28, MSG_DONTWAIT, NULL, NULL) = 28 <0.000016>
06:20:22.958258 write(35, "2019-03-17T06:20:22.958225+08:00"..., 73) = 73 <0.000052>
06:20:22.958649 recvfrom(59, 0x7f2e48007990, 4, MSG_DONTWAIT, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) <0.000014>
^Cstrace: Process 13071 detachedMySQL 5.7以降はsysを利用できます.processlist:
select thd_id, conn_id,user, pid,program_name,command,current_statement from processlist where conn_id>0 and pid>0;root@localhost [sys]>use sys;
Database changed
root@localhost [sys]>select thd_id, conn_id,user, pid,program_name,command,current_statement from processlist where conn_id>0 and pid>0;
+--------+---------+----------------+-------+--------------+---------+-------------------------------------------------------------------+
| thd_id | conn_id | user | pid | program_name | command | current_statement |
+--------+---------+----------------+-------+--------------+---------+-------------------------------------------------------------------+
| 29 | 3 | root@localhost | 59903 | mysql | Query | select thd_id, conn_id,user, p ... list where conn_id>0 and pid>0 |
+--------+---------+----------------+-------+--------------+---------+-------------------------------------------------------------------+
1 row in set (0.08 sec)
root@localhost [sys]>strace -T -tt -s 100 -o/tmp/strace.log -p $PID
ここではmysqldに関するio操作を見る必要があります.
mysql: read, write, open
Innodb: pread64, pwrite64
strace -o /tmp/strace.log -T -tt -f -e trace=read,open,write,pwrite64,pread64 -p `pidof mysqld` strace -o /tmp/test.log -T -tt -ff -p `pidof mysqld`
-ff ， fork thread ， 取得したスレッドidを利用してMySQLでクエリーして、何をしているのか見てみましょう.
select thread_id, thread_os_id,name from threads where thread_os_id in (15871,15872,15874,15901);straceコマンドの一般的な簡単な使用方法は次のとおりです.
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 -o /tmp/strace.log CMD
strace -T -tt -s 100 -e trace=XXXX -o /tmp/strace.log CMD
strace -T -tt -s 100 -ff -o /root/strace.log /usr/local/mysql/bin/mysqld
strace -T -tt -s 100 -e trace=write -o /root/strace.log /usr/local/mysql/bin/mysqld本博文はテンセントのスクリーンの中の課程を勉強してここにまとめたものです.コンテンツ・カリキュラムのアドレスは次のとおりです.https://ke.qq.com/course/384101
strace故障分析MySQLケースは以下の通りです.https://ke.qq.com/course/331538『MySQL運維の私が踏んだ穴』https://www.percona.com/blog/2010/07/16/analyzing-the-distribution-of-innodb-log-filewrites/https://mp.weixin.qq.com/s/wP_ivItVKbodkV1FluTcsg(楊奇?龍の公衆番号:システム調?用追跡分析神器?--strace)https://www.actionsky.com/index.php?id=2393(binlog rotateによるMySQLブロックイベント)