strace -f not following child process

Florian Kelbert florian_kelbert at gmx.de
Fri Jul 5 11:18:58 UTC 2013


Hi all,

while trying to strace nginx (http://nginx.org/), using strace -f, I 
realized that strace fails to trace a forked child process.

As you can see in the trace below, process 13644 forks a new child 
13645. 13644 and 13643 then exit and the new process 13645 does not get 
traced. As far as I have understood the strace source code, the reason 
may be that all parent processes exit before 16345 has executed any 
single system call.

Am I doing something wrong? Is this behaviour intended? Is it a bug?

Thank you in advance,
Florian


Trace:

13644 rt_sigaction(SIGHUP, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGUSR1, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGWINCH, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGTERM, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGQUIT, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGUSR2, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGALRM, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGINT, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGIO, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGCHLD, {0x8065cb0, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGSYS, {SIG_IGN, [], 0}, NULL, 8) = 0
13644 rt_sigaction(SIGPIPE, {SIG_IGN, [], 0}, NULL, 8) = 0
13644 clone(child_stack=0, 
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, 
child_tidptr=0xb727e728) = 13645
13644 exit_group(0)                     = ?
13644 +++ exited with 0 +++
13643 <... select resumed> )            = ? ERESTARTNOHAND (To be 
restarted if no handler)
13643 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=13644, 
si_status=0, si_utime=0, si_stime=0} ---
13643 write(6, "\21", 1)                = 1
13643 rt_sigreturn()                    = -1 EINTR (Interrupted system call)
13643 select(6, [3 5], [], NULL, NULL)  = 1 (in [5])
13643 read(5, "\21", 1)                 = 1
13643 waitpid(13644, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 
WNOHANG|WSTOPPED) = 13644
13643 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
13643 getuid32()                        = 0
13643 time(NULL)                        = 1372776660
13643 send(7, "<86>Jul  2 16:51:00 sudo: pam_un"..., 77, MSG_NOSIGNAL) = 77
13643 geteuid32()                       = 0
13643 stat64("/run/user", {st_mode=S_IFDIR|0755, st_size=160, ...}) = 0
13643 open("/run/user/.www.lock", O_RDWR) = 4
13643 flock(4, LOCK_EX)                 = 0
13643 fcntl64(4, F_GETFL)               = 0x2 (flags O_RDWR)
13643 fstat64(4, {st_mode=S_IFREG|0600, st_size=2, ...}) = 0
13643 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, 
-1, 0) = 0xb738c000
13643 _llseek(4, 0, [0], SEEK_CUR)      = 0
13643 read(4, "2\n", 4096)              = 2
13643 _llseek(4, 2, [2], SEEK_SET)      = 0
13643 ftruncate(4, 0)                   = 0
13643 _llseek(4, -2, [0], SEEK_CUR)     = 0
13643 write(4, "1\n", 2)                = 2
13643 close(4)                          = 0
13643 socket(PF_NETLINK, SOCK_RAW, 9)   = 4
13643 fcntl64(4, F_SETFD, FD_CLOEXEC)   = 0
13643 readlink("/proc/self/exe", "/usr/bin/sudo", 4096) = 13
13643 sendto(4, "x\0\0\0R\4\5\0\3\0\0\0\0\0\0\0op=PAM:session_c"..., 
120, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 120
13643 poll([{fd=4, events=POLLIN}], 1, 500) = 1 ([{fd=4, revents=POLLIN}])
13643 recvfrom(4, 
"$\0\0\0\2\0\0\0\3\0\0\0K5\0\0\0\0\0\0x\0\0\0R\4\5\0\3\0\0\0"..., 8988, 
MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 
[12]) = 36
13643 recvfrom(4, 
"$\0\0\0\2\0\0\0\3\0\0\0K5\0\0\0\0\0\0x\0\0\0R\4\5\0\3\0\0\0"..., 8988, 
MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 36
13643 close(4)                          = 0
13643 open("/etc/security/pam_env.conf", O_RDONLY|O_LARGEFILE) = 4
13643 fstat64(4, {st_mode=S_IFREG|0644, st_size=2980, ...}) = 0
13643 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, 
-1, 0) = 0xb7386000
13643 read(4, "#\n# This is the configuration fi"..., 4096) = 2980
13643 read(4, "", 4096)                 = 0
13643 close(4)                          = 0
13643 munmap(0xb7386000, 4096)          = 0
13643 open("/etc/environment", O_RDONLY|O_LARGEFILE) = 4
13643 fstat64(4, {st_mode=S_IFREG|0644, st_size=96, ...}) = 0
13643 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, 
-1, 0) = 0xb7386000
13643 read(4, "PATH=\"/usr/local/sbin:/usr/local"..., 4096) = 96
13643 read(4, "", 4096)                 = 0
13643 close(4)                          = 0
13643 munmap(0xb7386000, 4096)          = 0
13643 open("/etc/security/pam_env.conf", O_RDONLY|O_LARGEFILE) = 4
13643 fstat64(4, {st_mode=S_IFREG|0644, st_size=2980, ...}) = 0
13643 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, 
-1, 0) = 0xb7386000
13643 read(4, "#\n# This is the configuration fi"..., 4096) = 2980
13643 read(4, "", 4096)                 = 0
13643 close(4)                          = 0
13643 munmap(0xb7386000, 4096)          = 0
13643 open("/etc/default/locale", O_RDONLY|O_LARGEFILE) = 4
13643 fstat64(4, {st_mode=S_IFREG|0644, st_size=19, ...}) = 0
13643 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, 
-1, 0) = 0xb7386000
13643 read(4, "LANG=\"en_US.UTF-8\"\n", 4096) = 19
13643 read(4, "", 4096)                 = 0
13643 close(4)                          = 0
13643 munmap(0xb7386000, 4096)          = 0
13643 socket(PF_NETLINK, SOCK_RAW, 9)   = 4
13643 fcntl64(4, F_SETFD, FD_CLOEXEC)   = 0
13643 readlink("/proc/self/exe", "/usr/bin/sudo", 4096) = 13
13643 sendto(4, "p\0\0\0P\4\5\0\4\0\0\0\0\0\0\0op=PAM:setcred a"..., 
112, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 112
13643 poll([{fd=4, events=POLLIN}], 1, 500) = 1 ([{fd=4, revents=POLLIN}])
13643 recvfrom(4, 
"$\0\0\0\2\0\0\0\4\0\0\0K5\0\0\0\0\0\0p\0\0\0P\4\5\0\4\0\0\0"..., 8988, 
MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 
[12]) = 36
13643 recvfrom(4, 
"$\0\0\0\2\0\0\0\4\0\0\0K5\0\0\0\0\0\0p\0\0\0P\4\5\0\4\0\0\0"..., 8988, 
MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 36
13643 close(4)                          = 0
13643 munmap(0xb7387000, 16504)         = 0
13643 munmap(0xb72c4000, 107008)        = 0
13643 munmap(0xb727b000, 201052)        = 0
13643 munmap(0xb7383000, 8220)          = 0
13643 munmap(0xb7380000, 8228)          = 0
13643 munmap(0xb737c000, 12408)         = 0
13643 munmap(0xb7376000, 20824)         = 0
13643 munmap(0xb72c0000, 12408)         = 0
13643 munmap(0xb72bc000, 12404)         = 0
13643 munmap(0xb72b0000, 45420)         = 0
13643 munmap(0xb7277000, 12416)         = 0
13643 munmap(0xb7212000, 12400)         = 0
13643 munmap(0xb7216000, 299836)        = 0
13643 exit_group(0)                     = ?
13643 +++ exited with 0 +++




More information about the Strace-devel mailing list