strace 的命令使用
usage
这里 是使用例子，有几个option，会用的是-c, -e 和 -p。
-c
$ strace -c ls /usr/local/lib64/perl5/5.18.2/DDP.pm
/usr/local/lib64/perl5/5.18.2/DDP.pm
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
0.00 0.000000 0 3 read
0.00 0.000000 0 1 write
0.00 0.000000 0 5 open
0.00 0.000000 0 7 close
0.00 0.000000 0 1 stat
0.00 0.000000 0 6 fstat
0.00 0.000000 0 1 lstat
0.00 0.000000 0 14 mmap
0.00 0.000000 0 8 mprotect
0.00 0.000000 0 2 munmap
0.00 0.000000 0 3 brk
0.00 0.000000 0 2 ioctl
0.00 0.000000 0 1 1 access
0.00 0.000000 0 1 execve
0.00 0.000000 0 1 arch_prctl
------ ----------- ----------- --------- --------- ----------------
100.00 0.000000 56 1 total
-e
$ strace -e open cat /dev/null
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
open("/usr/lib64/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
open("/dev/null", O_RDONLY) = 3
+++ exited with 0 +++
$ strace sleep 2
execve("/usr/bin/sleep", ["sleep", "2"], [/* 33 vars */]) = 0
brk(0) = 0x608000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9c2592b000
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=37485, ...}) = 0
mmap(NULL, 37485, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f9c25921000
close(3) = 0
open("/lib64/libc.so.6", 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\300N\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1716472, ...}) = 0
mmap(NULL, 3828824, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f9c25365000
mprotect(0x7f9c25503000, 2093056, PROT_NONE) = 0
mmap(0x7f9c25702000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19d000) = 0x7f9c25702000
mmap(0x7f9c25708000, 15448, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f9c25708000
close(3) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9c25920000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9c2591f000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9c2591e000
arch_prctl(ARCH_SET_FS, 0x7f9c2591f700) = 0
mprotect(0x7f9c25702000, 16384, PROT_READ) = 0
mprotect(0x606000, 4096, PROT_READ) = 0
mprotect(0x7f9c2592c000, 4096, PROT_READ) = 0
munmap(0x7f9c25921000, 37485) = 0
brk(0) = 0x608000
brk(0x629000) = 0x629000
open("/usr/lib64/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=1607712, ...}) = 0
mmap(NULL, 1607712, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f9c25795000
close(3) = 0
nanosleep({2, 0}, NULL) = 0
close(1) = 0
close(2) = 0
exit_group(0) = ?
+++ exited with 0 +++
example
这里做一个练习，观察一下nginx的启动，read/write，reload，stop。
nginx.conf
user nginx nginx;
worker_processes 1;
error_log /var/log/nginx/error_log info;
events {
worker_connections 1024;
use epoll;
}
http {
include /etc/nginx/mime.types;
...
server {
listen 80;
listen 443 ssl;
ssl_certificate /etc/ssl/datlet/datlet.com.crt;
ssl_certificate_key /etc/ssl/datlet/datlet.com.key;
...
start
$ sudo strace -c nginx
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
0.00 0.000000 0 25 read
0.00 0.000000 0 4 write
0.00 0.000000 0 30 open
0.00 0.000000 0 27 close
0.00 0.000000 0 4 stat
0.00 0.000000 0 26 fstat
0.00 0.000000 0 1 poll
0.00 0.000000 0 5 lseek
0.00 0.000000 0 45 mmap
0.00 0.000000 0 26 mprotect
0.00 0.000000 0 10 munmap
0.00 0.000000 0 5 brk
0.00 0.000000 0 14 rt_sigaction
0.00 0.000000 0 1 rt_sigprocmask
0.00 0.000000 0 2 ioctl
0.00 0.000000 0 2 pread
0.00 0.000000 0 1 1 access
0.00 0.000000 0 2 socket
0.00 0.000000 0 2 bind
0.00 0.000000 0 4 listen
0.00 0.000000 0 2 setsockopt
0.00 0.000000 0 1 clone
0.00 0.000000 0 1 execve
0.00 0.000000 0 2 uname
0.00 0.000000 0 5 fcntl
0.00 0.000000 0 3 3 mkdir
0.00 0.000000 0 3 getrlimit
0.00 0.000000 0 1 getuid
0.00 0.000000 0 1 geteuid
0.00 0.000000 0 1 arch_prctl
0.00 0.000000 0 2 1 futex
0.00 0.000000 0 1 epoll_create
0.00 0.000000 0 1 set_tid_address
0.00 0.000000 0 1 set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00 0.000000 261 5 total
关闭后我们重新在来一次,观察一下为何出现mkdir错误
$ sudo strace -e mkdir nginx
mkdir("//var/lib/nginx/tmp/client", 0700) = -1 EEXIST (File exists)
mkdir("//var/lib/nginx/tmp/proxy", 0700) = -1 EEXIST (File exists)
mkdir("//var/lib/nginx/tmp/fastcgi", 0700) = -1 EEXIST (File exists)
+++ exited with 0 +++
那么这个异常可以忽略。
open, write, socket 观察
在:80存在的情况下运行nginx看看情况如何
open("/var/log/nginx/error_log", O_WRONLY|O_CREAT|O_APPEND, 0644) = 4
...
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 7
setsockopt(7, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
ioctl(7, FIONBIO, [1]) = 0
bind(7, {sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("0.0.0.0")}, 16) = -1 EADDRINUSE (Address already in use)
write(4, "2015/01/15 16:41:16 [emerg] 5066"..., 94) = 94
write(2, "nginx: [emerg] bind() to 0.0.0.0"..., 73nginx: [emerg] bind() to 0.0.0.0:443 failed (98: Address already in use)
) = 73
close(7) = 0
write(4, "2015/01/15 16:41:16 [notice] 506"..., 69) = 69
nanosleep({0, 500000000}, NULL) = 0
...
反复出现上面的socket错误，而对应的(4)中，也能看到数次的重试。
$ sudo grep "2015/01/15 16:4" /var/log/nginx/error_log
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:443 failed (98: Address already in use)
2015/01/15 16:41:16 [notice] 5066#0: try again to bind() after 500ms
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:443 failed (98: Address already in use)
2015/01/15 16:41:16 [notice] 5066#0: try again to bind() after 500ms
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:443 failed (98: Address already in use)
2015/01/15 16:41:16 [notice] 5066#0: try again to bind() after 500ms
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:443 failed (98: Address already in use)
2015/01/15 16:41:16 [notice] 5066#0: try again to bind() after 500ms
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/01/15 16:41:16 [emerg] 5066#0: bind() to 0.0.0.0:443 failed (98: Address already in use)
2015/01/15 16:41:16 [notice] 5066#0: try again to bind() after 500ms
2015/01/15 16:41:16 [emerg] 5066#0: still could not bind()
nginx @ gentoo 问题
这个错误一直存在，这里有很旧的处理文档，但我怀疑和太旧不一定合用。鉴于它退出的时候是exit 0，暂时先放放。
$ sudo strace -e access nginx
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
+++ exited with 0 +++