strace 命令
strace 命令常用参数
-tt 在每行输出的前面，显示毫秒级别的时间
-T 显示每次系统调用所花费的时间
-v 对于某些相关调用，把完整的环境变量，文件stat结构等打出来。
-f 跟踪目标进程，以及目标进程创建的所有子进程
-e 控制要跟踪的事件和跟踪行为,比如指定要跟踪的系统调用名称
-o 把strace的输出单独写到指定的文件
-s 当系统调用的某个参数是字符串时，最多输出指定长度的内容，默认是32个字节
-p 指定要跟踪的进程pid, 要同时跟踪多个pid, 重复多次-p选项即可。
系统调用主要分为几类:
文件和设备访问类 比如open/close/read/write/chmod等
进程管理类 fork/clone/execve/exit/getpid等
信号类 signal/sigaction/kill 等
内存管理 brk/mmap/mlock等
进程间通信IPC shmget/semget * 信号量，共享内存，消息队列等
网络通信 socket/connect/sendto/sendmsg 等
其他
-e trace=file 跟踪和文件访问相关的调用(参数中有文件名)
-e trace=process 和进程管理相关的调用，比如fork/exec/exit_group
-e trace=network 和网络通信相关的调用，比如socket/sendto/connect
-e trace=signal 信号发送和处理相关，比如kill/sigaction
-e trace=desc 和文件描述符相关，比如write/read/select/epoll等
-e trace=ipc 进程见同学相关，比如shmget等
strace命令主要用于跟踪用户态、内核态的系统调用，
1、使用strace命令，观察MySQL启动过程
篇幅有限，只截取了前边的一些内容，可以看到有很多调用，{brk mmap open close read 等} ，strace 命令默认只跟踪进程的系统调用，其中线程的调用并不会采集,如果要查看到线程的系统调用需要加参数 -f
execve("bin/mysqld", ["bin/mysqld", "--defaults-file=/etc/my57.cnf", "--user=root"], 0x7ffd2fcf6460 /* 22 vars */) = 0
brk(NULL) = 0x30d7000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8097b0a000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=26180, ...}) = 0
mmap(NULL, 26180, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f8097b03000
close(3) = 0
open("/lib64/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200m\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=142144, ...}) = 0
mmap(NULL, 2208904, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f80976ce000
mprotect(0x7f80976e5000, 2093056, PROT_NONE) = 0
mmap(0x7f80978e4000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0x7f80978e4000
mmap(0x7f80978e6000, 13448, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f80978e6000
close(3) = 0
open("/lib64/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\16\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=19248, ...}) = 0
mmap(NULL, 2109744, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f80974ca000
mprotect(0x7f80974cc000, 2097152, PROT_NONE) = 0
mmap(0x7f80976cc000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f80976cc000
close(3) = 0
open("/lib64/libaio.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\5\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=6264, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8097b02000
mmap(NULL, 2101328, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f80972c8000
mprotect(0x7f80972c9000, 2093056, PROT_NONE) = 0
mmap(0x7f80974c8000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0) = 0x7f80974c8000
close(3) = 0
open("/lib64/libnuma.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0004\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=50704, ...}) = 0
mmap(NULL, 2144448, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f80970bc000
mprotect(0x7f80970c6000, 2097152, PROT_NONE) = 0
mmap(0x7f80972c6000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xa000) = 0x7f80972c6000
close(3) = 0
open("/lib64/libcrypt.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\16\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=40600, ...}) = 0
mmap(NULL, 2318912, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f8096e85000
mprotect(0x7f8096e8d000, 2093056, PROT_NONE) = 0
mmap(0x7f809708c000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7f809708c000
mmap(0x7f809708e000, 184896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f809708e000
close(3) = 0
open("/lib64/librt.so.1", O_RDONLY|O_CLOEXEC) = 3
......
2、常用方法：
strace -T -tt -s 100 -f -o start.log bin/mysqld --defaults-file=/etc/my57.cnf --user=root
可以将各个线程的调用全部打印出来
24885 02:49:42.393497 close(52) = 0 <0.000034>
24885 02:49:42.393672 mprotect(0x7f134095c000, 32768, PROT_READ|PROT_WRITE) = 0 <0.000030>
24885 02:49:42.393963 stat("./ceshi/tt4.frm", {st_mode=S_IFREG|0640, st_size=8556, ...}) = 0 <0.000074>
24885 02:49:42.394195 access("./ceshi/tt4.TRG", F_OK) = -1 ENOENT (No such file or directory) <0.000073>
24885 02:49:42.394466 sendto(49, "'\0\0\1\3def\5ceshi\3tt4\3tt4\2id\2id\f?\0\v\0\0\0\3\3P\0\0\0\0010\7\0\0\2\376\0\0\2\0\0\0", 54, MSG_DONTWAIT, NULL, 0) = 54 <0.000143>
24885 02:49:42.394803 recvfrom(49, "\5\0\0\0", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000038>
24885 02:49:42.395001 recvfrom(49, "\4tt5\0", 5, MSG_DONTWAIT, NULL, NULL) = 5 <0.000041>
24885 02:49:42.395248 open("./ceshi/tt5.frm", O_RDONLY) = 52 <0.000103>
24885 02:49:42.395435 getcwd("/usr/local/mysql57/data", 4096) = 24 <0.000081>
24885 02:49:42.395566 lstat("/usr/local/mysql57/data/ceshi", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0 <0.000084>
24885 02:49:42.395734 read(52, "\376\1\t\f\3\0\0\20\1\0\0000\0\0i\1\5\0\0\0\0\0\0\0\0\0\0\2!\0\10\0\0\5\0\0\0\0!\0\0\0\0\0\0\0\0i\1\0\0.\306\0\0\36\0\0\0\0\0\0\0\0", 64) = 64 <0.000016>
24885 02:49:42.395855 lseek(52, 64, SEEK_SET) = 64 <0.000032>
24885 02:49:42.395996 read(52, "//\0\0 \0\0", 7) = 7 <0.000049>
24885 02:49:42.396225 lseek(52, 8192, SEEK_SET) = 8192 <0.000023>
24885 02:49:42.396474 read(52, "l\1\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\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\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\0\0\0\0"..., 288) = 288 <0.000038>
24885 02:49:42.396672 lseek(52, 4096, SEEK_SET) = 4096 <0.000017>
24885 02:49:42.396797 read(52, "\1\1\0\0\n\0\0\0\4\0\1\0\0\0\1\200\2\0\0\33@\4\0\377PRIMARY\377\0", 33) = 33 <0.000016>
24885 02:49:42.396906 pread64(52, "\0\0\6\0InnoDB\0\0\0\0\0\0\n\0\0\0\0\0\0\0\0\0\0\0\0\0", 30, 4462) = 30 <0.000042>
24885 02:49:42.397024 pread64(52, "\377\0\0\0\0", 5, 4457) = 5 <0.000015>
24885 02:49:42.397123 lseek(52, 8480, SEEK_SET) = 8480 <0.000014>
24885 02:49:42.397218 read(52, "6\0\2\1\2\24) \0\4\0\3id\0\4\3\v\v\0\2\0\0\33@\0\0\0\3!\0\0\377id\377\0", 76) = 76 <0.000014>
24885 02:49:42.397348 close(52) = 0 <0.000062>
24885 02:49:42.397569 mprotect(0x7f1340964000, 4096, PROT_READ|PROT_WRITE) = 0 <0.000089>
24885 02:49:42.397883 stat("./ceshi/tt5.frm", {st_mode=S_IFREG|0640, st_size=8556, ...}) = 0 <0.000065>
24885 02:49:42.398063 access("./ceshi/tt5.TRG", F_OK) = -1 ENOENT (No such file or directory) <0.000047>
24885 02:49:42.398410 sendto(49, "'\0\0\1\3def\5ceshi\3tt5\3tt5\2id\2id\f?\0\v\0\0\0\3\3P\0\0\0\0010\7\0\0\2\376\0\0\2\0\0\0", 54, MSG_DONTWAIT, NULL, 0) = 54 <0.000179>
24885 02:49:42.398692 recvfrom(49, "\20\0\0\0", 4, MSG_DONTWAIT, NULL, NULL) = 4 <0.000063>
24885 02:49:42.398850 recvfrom(49, "\3select * from t", 16, MSG_DONTWAIT, NULL, NULL) = 16 <0.000086>
24885 02:49:42.399169 sendto(49, "\1\0\0\1\3!\0\0\2\3def\5ceshi\1t\1t\2id\2id\f?\0\v\0\0\0\3\3P\0\0\0\37\0\0\3\3def\5ceshi\1t\1t\1c\1c\f?\0\v\0\0\0\3\10@\0\0\0\37\0\0\4\3def\5ceshi\1t\1t\1d\1d\f"..., 195, MSG_DONTWAIT, NULL, 0) = 195 <0.000157>
24885 02:49:42.399449 recvfrom(49, <unfinished ...>
24851 02:49:42.399537 <... io_getevents resumed>[], {tv_sec=0, tv_nsec=500000000}) = 0 <0.500114>
24885 02:49:42.399628 <... recvfrom resumed>0x7f134000a210, 4, MSG_DONTWAIT, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) <0.000151>
24851 02:49:42.399658 io_getevents(0x7f1381a35000, 1, 256, <unfinished ...>
24885 02:49:42.399723 poll([{fd=49, events=POLLIN|POLLPRI}], 1, 7200000 <unfinished ...>
24860 02:49:42.446576 <... nanosleep resumed>NULL) = 0 <1.000675>
24858 02:49:42.446667 <... futex resumed>) = -1 ETIMEDOUT (Connection timed out) <1.000465>
24857 02:49:42.446682 <... futex resumed>) = -1 ETIMEDOUT (Connection timed out) <1.000737>
24860 02:49:42.446698 nanosleep({tv_sec=1, tv_nsec=0}, <unfinished ...>
......
3、针对某类调用进行显示
strace -T -tt -s 100 -f -e trace=file -o start.log bin/mysqld --defaults-file=/etc/my57.cnf --user=root
结果显示，可以看到MySQL要打开【/ceshi/czg.TRG】文件，但报错没有这个文件，这个文件是触发器，只有该表上的触发器的时候，才会生成 trg 文件，由此可以看出，数据库打开文件时，不止打开ibd frm 文件，也会尝试打开 trg 文件，即使它不存在，日志中有许多类似报错，我只截取了其中一条####
26870 03:26:46.620137 lstat("/usr/local/mysql57/data/172_16_1_10_3357_ceshi", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0 <0.000051>
26870 03:26:46.620521 open("./inception/db.opt", O_RDONLY) = 50 <0.000064>
26870 03:26:46.620676 getcwd("/usr/local/mysql57/data", 4096) = 24 <0.000069>
26870 03:26:46.620846 lstat("/usr/local/mysql57/data/inception", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0 <0.000048>
26870 03:26:46.621109 open("./mysql/db.opt", O_RDONLY) = 50 <0.000054>
26870 03:26:46.621237 getcwd("/usr/local/mysql57/data", 4096) = 24 <0.000043>
26870 03:26:46.621364 lstat("/usr/local/mysql57/data/mysql", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0 <0.000045>
26870 03:26:46.621633 open("./performance_schema/db.opt", O_RDONLY) = 50 <0.000069>
26870 03:26:46.621798 getcwd("/usr/local/mysql57/data", 4096) = 24 <0.000060>
26870 03:26:46.622004 lstat("/usr/local/mysql57/data/performance_schema", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0 <0.000076>
26870 03:26:46.622432 open("./sys/db.opt", O_RDONLY) = 50 <0.000082>
26870 03:26:46.622699 getcwd("/usr/local/mysql57/data", 4096) = 24 <0.000060>
26870 03:26:46.622878 lstat("/usr/local/mysql57/data/sys", {st_mode=S_IFDIR|0750, st_size=12288, ...}) = 0 <0.000048>
26870 03:26:46.623650 openat(AT_FDCWD, "./ceshi/", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 50 <0.000083>
26870 03:26:46.624211 open("./ceshi/czg.frm", O_RDONLY) = 50 <0.000102>
26870 03:26:46.624441 getcwd("/usr/local/mysql57/data", 4096) = 24 <0.000056>
26870 03:26:46.624684 lstat("/usr/local/mysql57/data/ceshi", {st_mode=S_IFDIR|0750, st_size=4096, ...}) = 0 <0.000075>
26870 03:26:46.625414 stat("./ceshi/czg.frm", {st_mode=S_IFREG|0640, st_size=8556, ...}) = 0 <0.000082>
26870 03:26:46.627994 access("./ceshi/czg.TRG", F_OK) = -1 ENOENT (No such file or directory) <0.000065>
......
4、其它常用
查看执行语句
strace -f -F -ff -o mysqld-strace -s 1024 -p $mysqld_pid
find ./ -name “mysqld-strace” -type f -print |xargs grep -n “SELECT.FROM”
查看读写文件
strace -o /tmp/strace_output.txt -T -tt -f -e trace=read,open -p “mysqld_pid”
