使用strace调试mysql问题的一些简单例子

strace是什么？

按照strace官网的描述, strace是一个可用于诊断、调试和教学的Linux用户空间跟踪器。我们用它来监控用户空间进程和内核的交互，比如系统调用、信号传递、进程状态变更等。

strace底层使用内核的ptrace特性来实现其功能。

strace能做什么？

strace常用来跟踪进程执行时的系统调用和所接收的信号。

在Linux世界，进程不能直接访问硬件设备，当进程需要访问硬件设备(比如读取磁盘文件，接收网络数据等等)时，必须由用户态模式切换至内核态模式，通过系统调用访问硬件设备。strace可以跟踪到一个进程产生的系统调用,包括参数，返回值，执行消耗的时间。

在运维的日常工作中，故障处理和问题诊断是个主要的内容，也是必备的技能。strace作为一种动态跟踪工具，能够帮助运维高效地定位进程和服务故障。它像是一个侦探，通过系统调用的蛛丝马迹，告诉你异常的真相。

输出参数的含义

每一行都是一条系统调用，等号左边是系统调用的函数名及其参数，右边是该调用的返回值。 strace 显示这些调用的参数并返回符号形式的值。strace 从内核接收信息，而且不需要以任何特殊的方式来构建内核。

$strace cat /dev/null
execve("/bin/cat", ["cat", "/dev/null"], [/* 22 vars */]) = 0
brk(0)                                  = 0xab1000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f29379a7000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
...

参数

-c 统计每一系统调用的所执行的时间,次数和出错的次数等.
-d 输出strace关于标准错误的调试信息.
-f 跟踪由fork调用所产生的子进程.
-ff 如果提供-o filename,则所有进程的跟踪结果输出到相应的filename.pid中,pid是各进程的进程号.
-F 尝试跟踪vfork调用.在-f时,vfork不被跟踪.
-h 输出简要的帮助信息.
-i 输出系统调用的入口指针.
-q 禁止输出关于脱离的消息.
-r 打印出相对时间关于,,每一个系统调用.
-t 在输出中的每一行前加上时间信息.
-tt 在输出中的每一行前加上时间信息,微秒级.
-ttt 微秒级输出,以秒了表示时间.
-T 显示每一调用所耗的时间.
-v 输出所有的系统调用.一些调用关于环境变量,状态,输入输出等调用由于使用频繁,默认不输出.
-V 输出strace的版本信息.
-x 以十六进制形式输出非标准字符串
-xx 所有字符串以十六进制形式输出.
-a column
设置返回值的输出位置.默认 为40.
-e expr
指定一个表达式,用来控制如何跟踪.格式如下:
[qualifier=][!]value1[,value2]...
qualifier只能是 trace,abbrev,verbose,raw,signal,read,write其中之一.value是用来限定的符号或数字.默认的 qualifier是 trace.感叹号是否定符号.例如:
-eopen等价于 -e trace=open,表示只跟踪open调用.而-etrace!=open表示跟踪除了open以外的其他调用.有两个特殊的符号 all 和 none.
注意有些shell使用!来执行历史记录里的命令,所以要使用\.
-e trace=set
只跟踪指定的系统 调用.例如:-e trace=open,close,rean,write表示只跟踪这四个系统调用.默认的为set=all.
-e trace=file
只跟踪有关文件操作的系统调用.
-e trace=process
只跟踪有关进程控制的系统调用.
-e trace=network
跟踪与网络有关的所有系统调用.
-e strace=signal
跟踪所有与系统信号有关的 系统调用
-e trace=ipc
跟踪所有与进程通讯有关的系统调用
-e abbrev=set
设定 strace输出的系统调用的结果集.-v 等与 abbrev=none.默认为abbrev=all.
-e raw=set
将指 定的系统调用的参数以十六进制显示.
-e signal=set
指定跟踪的系统信号.默认为all.如 signal=!SIGIO(或者signal=!io),表示不跟踪SIGIO信号.
-e read=set
输出从指定文件中读出 的数据.例如:
-e read=3,5
-e write=set
输出写入到指定文件中的数据.
-o filename
将strace的输出写入文件filename
-p pid
跟踪指定的进程pid.
-s strsize
指定输出的字符串的最大长度.默认为32.文件名一直全部输出.
-u username
以username 的UID和GID执行被跟踪的命令

安装

yum -y install strace

主要用法有两种:

1.从命令行调试一个新开始的程序
strace /etc/init.d/mysqld start

2.绑定到一个已有的PID上来调试一个正在运行的程序
strace -c -p 7945

常用命令举例:

strace -o ~/mysqld.strace -T -tt -e trace=all -p <PID>
strace -p <PID>
strace -cp <PID>

实用例子:

一、mysqld启动时读了的哪个配置文件？

[root@192-168-199-110 ~]# strace /etc/init.d/mysqld 2>&1 |grep my.cnf
stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=1507, ...}) = 0
access("/etc/my.cnf", R_OK)             = 0
stat("/usr/local/mysql/my.cnf", 0x7fff4f9747d0) = -1 ENOENT (No such file or directory)
stat("/usr/local/mysql/data/my.cnf", 0x7fff4f974700) = -1 ENOENT (No such file or directory)
[root@192-168-199-110 ~]# strace /etc/init.d/mysqld start 2>&1 |grep my.cnf
stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=1507, ...}) = 0
access("/etc/my.cnf", R_OK)             = 0
stat("/usr/local/mysql/my.cnf", 0x7fff93ffe970) = -1 ENOENT (No such file or directory)
stat("/usr/local/mysql/data/my.cnf", 0x7fff93ffe8a0) = -1 ENOENT (No such file or directory)

二、为什么mysqld没有打开我的文件？

三、mysqld现在在做什么?

四、是谁偷走了mysqld的时间？

[root@192-168-199-110 ~]# ps -ef |grep mysqld
root       7440      1  0 10:50 pts/2    00:00:00 /bin/sh /opt/dbaas/mysql//bin/mysqld_safe --datadir=/opt/dbaas/mysql/data/ --pid-file=/opt/dbaas/mysql/data//192-168-199-110.pid
mysql      7945   7440  1 10:50 pts/2    00:00:04 /opt/dbaas/mysql/bin/mysqld --basedir=/opt/dbaas/mysql/ --datadir=/opt/dbaas/mysql/data/ --plugin-dir=/opt/dbaas/mysql//lib/plugin --user=mysql --log-error=/opt/dbaas/mysql/data//mysql-error.log --open-files-limit=65535 --pid-file=/opt/dbaas/mysql/data//192-168-199-110.pid --socket=/tmp/mysql.sock --port=3306
root       8035   5157  0 10:53 pts/2    00:00:00 grep --color=auto mysqld
[root@192-168-199-110 ~]# strace -c -p 7945
Process 7945 attached - interrupt to quit
^CProcess 7945 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 99.92    3.130370       22045       142           poll
  0.06    0.002008           7       286           futex
  0.02    0.000526           2       286           setsockopt
  0.00    0.000000           0       143           accept
  0.00    0.000000           0       429           fcntl
  0.00    0.000000           0         1           restart_syscall
------ ----------- ----------- --------- --------- ----------------
100.00    3.132904                  1287           total

五、mysqld为什么不能连接远程服务器？

[root@192-168-199-111 ssltest57]# strace mysql -h192.168.199.118 -uroot -P3306 -pActionsky
execve("/opt/mysql-5.6/bin/mysql", ["mysql", "-h192.168.199.118", "-uroot", "-P3306", "-pActionsky"], [/* 22 vars */]) = 0
brk(0)                                  = 0x1ca0000
...
recvmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"2432r340225[301+1241"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
close(3)                                = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(3306), sin_addr=inet_addr("192.168.199.118")}, 16) = -1 ETIMEDOUT (Connection timed out)
close(3)                                = 0
shutdown(3, 2 /* send and receive */)   = -1 EBADF (Bad file descriptor)
close(3)                                = -1 EBADF (Bad file descriptor)
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4053aa8000
write(2, "ERROR 2003 (HY000): ", 20ERROR 2003 (HY000): )    = 20
write(2, "Can't connect to MySQL server on"..., 56Can't connect to MySQL server on '192.168.199.118' (110)) = 56
write(2, "
", 1
)                       = 1
write(1, "7", 1)                       = 1
rt_sigaction(SIGQUIT, {SIG_IGN, [QUIT], SA_RESTORER|SA_RESTART, 0x3623e329a0}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGINT, {SIG_IGN, [INT], SA_RESTORER|SA_RESTART, 0x3623e329a0}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGHUP, {SIG_IGN, [HUP], SA_RESTORER|SA_RESTART, 0x3623e329a0}, {SIG_DFL, [], 0}, 8) = 0
exit_group(1)                           = ?

参考:
https://linuxtools-rst.readthedocs.io/zh_CN/latest/tool/strace.html
https://www.linuxidc.com/Linux/2018-01/150654.htm
https://blog.csdn.net/csdn265/article/details/70050168