strace, wait4 and pending SIGALRM
Dmitry V. Krivenok
krivenok at orangesystem.ru
Mon May 25 09:36:14 UTC 2009
Hello!
I have a question about strace and signals.
Please take a look at this simple example:
////////////////////////////////////////////////////////////////////////////////////////////////////////////
#include <cassert>
#include <iostream>
#include <signal.h>
#include <unistd.h>
#include <sys/types.h>
#include <sys/wait.h>
const int alarm_timeout = 3;
pid_t pid;
void alarm_handler(int)
{
std::cout << "Alarm clock. Killing child process using signal TERM."
<< std::endl;
kill(pid, SIGTERM);
}
void term_handler(int)
{
std::cout << "Signal TERM received. Exiting immediately." << std::endl;
exit(0);
}
void register_signal_handler(int signo, void (*handler)(int))
{
struct sigaction sa;
sa.sa_handler = handler;
sigemptyset(&sa.sa_mask);
sa.sa_flags = 0;
int r = sigaction(signo, &sa, NULL);
assert(r!=-1);
}
int main()
{
pid = fork();
assert(pid != -1);
if(pid)
{
// *** Parent ***
alarm(alarm_timeout);
register_signal_handler(SIGALRM, &alarm_handler);
wait(0);
alarm(0);
}
else
{
// *** Child ***
register_signal_handler(SIGTERM, &term_handler);
sleep(alarm_timeout * 2);
}
return 0;
}
////////////////////////////////////////////////////////////////////////////////////////////////////////////
It can be compiled as follows:
krivenok at develop2 17:14:27 ~/alarm $ g++ -Wall alarm.cpp
krivenok at develop2 17:14:28 ~/alarm $ ls -l
total 12
-rwxr-xr-x 1 krivenok krivenok 8158 May 19 17:14 a.out
-rw-r--r-- 1 krivenok krivenok 990 May 19 17:13 alarm.cpp
krivenok at develop2 17:14:31 ~/alarm $
Lets run the program:
krivenok at develop2 17:14:31 ~/alarm $ time ./a.out
Alarm clock. Killing child process using signal TERM.
Signal TERM received. Exiting immediately.
real 0m3.001s
user 0m0.000s
sys 0m0.000s
krivenok at develop2 17:15:00 ~/alarm $
As you can see it works as expected.
Now lets trace the process using strace utility:
krivenok at develop2 17:15:00 ~/alarm $ time strace -e trace=signal -tt
./a.out > /dev/null
17:16:20.897472 rt_sigaction(SIGALRM, {0x8048a9c, [], 0}, NULL, 8) = 0
17:16:23.897484 --- SIGALRM (Alarm clock) @ 0 (0) ---
17:16:23.897759 kill(30435, SIGTERM) = 0
17:16:23.897919 sigreturn() = ? (mask now [])
17:16:23.898129 --- SIGCHLD (Child exited) @ 0 (0) ---
real 0m3.003s
user 0m0.000s
sys 0m0.010s
krivenok at develop2 17:16:23 ~/alarm $
As you can see parent process receives SIGALRM and then sends
SIGTERM signal to the child process.
After child process termination kernel sends SIGCHLD to parent process.
So far, so good.
Lets run strace with "-f" option:
krivenok at develop2 17:31:11 ~/alarm $ time strace -e trace=signal,process
-f -tt ./a.out > /dev/null
17:31:21.011254 execve("./a.out", ["./a.out"], [/* 64 vars */]) = 0
17:31:21.012997 clone(Process 11550 attached
child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7c8ab58) = 11550
[pid 11550] 17:31:21.013237 rt_sigaction(SIGTERM, {0x8048a66, [], 0},
NULL, 8) = 0
[pid 11550] 17:31:21.013352 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 11550] 17:31:21.013497 rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [],
0}, 8) = 0
[pid 11550] 17:31:21.013596 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 11549] 17:31:21.013773 rt_sigaction(SIGALRM, {0x8048a9c, [], 0},
NULL, 8) = 0
[pid 11549] 17:31:21.013984 wait4(-1, Process 11549 suspended
<unfinished ...>
[pid 11550] 17:31:27.013861 exit_group(0) = ?
Process 11549 resumed
Process 11550 detached
17:31:27.013882 <... wait4 resumed> NULL, 0, NULL) = ? ERESTARTSYS (To
be restarted)
17:31:27.013921 --- SIGALRM (Alarm clock) @ 0 (0) ---
17:31:27.014110 --- SIGCHLD (Child exited) @ 0 (0) ---
17:31:27.014201 kill(11550, SIGTERM) = 0
17:31:27.014223 sigreturn() = ? (mask now [])
17:31:27.014283 exit_group(0) = ?
real 0m6.004s
user 0m0.000s
sys 0m0.000s
krivenok at develop2 17:31:27 ~/alarm $
As you can see, SIGALRM is received _after_ termination of child process.
I searched through the google and strace manual page, but didn't find
anything describing such behavior of "strace -f".
The scenario looks like
1) SIGALRM is implicitly (according to strace output) blocked.
2) Then SIGALRM is generated by kernel, but it remains pending.
3) Then child process exits and it leads to implicit unblocking of SIGALRM.
4) SIGALRM is delivered to the parent process (wait4 is interrupted).
It's just a guess of course.
Could anyone explain what's going on here?
Thank you beforehand!
P.S.
I examined the content of /proc/<PARENT_PID>/status before
and after SIGALRM generation.
Before:
krivenok at develop2 16:55:07 ~ $ cat /proc/26262/status
Name: a.out
State: T (tracing stop)
Tgid: 26262
Pid: 26262
PPid: 26261
TracerPid: 26261
Uid: 1000 1000 1000 1000
Gid: 1000 1000 1000 1000
FDSize: 32
Groups: 10 16 100 250 1000 1003 1005 1006 1008 1010 1027 1028
VmPeak: 2720 kB
VmSize: 2620 kB
VmLck: 0 kB
VmHWM: 736 kB
VmRSS: 736 kB
VmData: 52 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 2412 kB
VmPTE: 12 kB
Threads: 1
SigQ: 0/32756
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000000000000
SigCgt: 0000000000002000
CapInh: 0000000000000000
CapPrm: 0000000000000000
CapEff: 0000000000000000
voluntary_ctxt_switches: 168
nonvoluntary_ctxt_switches: 0
krivenok at develop2 17:46:41 ~ $
After:
krivenok at develop2 17:46:41 ~ $ cat /proc/26262/status
Name: a.out
State: T (tracing stop)
Tgid: 26262
Pid: 26262
PPid: 26261
TracerPid: 26261
Uid: 1000 1000 1000 1000
Gid: 1000 1000 1000 1000
FDSize: 32
Groups: 10 16 100 250 1000 1003 1005 1006 1008 1010 1027 1028
VmPeak: 2720 kB
VmSize: 2620 kB
VmLck: 0 kB
VmHWM: 736 kB
VmRSS: 736 kB
VmData: 52 kB
VmStk: 88 kB
VmExe: 4 kB
VmLib: 2412 kB
VmPTE: 12 kB
Threads: 1
SigQ: 1/32756
SigPnd: 0000000000000000
ShdPnd: 0000000000002000
SigBlk: 0000000000000000
SigIgn: 0000000000000000
SigCgt: 0000000000002000
CapInh: 0000000000000000
CapPrm: 0000000000000000
CapEff: 0000000000000000
voluntary_ctxt_switches: 168
nonvoluntary_ctxt_switches: 0
krivenok at develop2 17:46:52 ~ $
That is there is one pending signal in the signals queue.
--
Sincerely yours, Dmitry V. Krivenok
Orange System Co., Ltd.
Saint-Petersburg, Russia
work phone: +7 812 332-32-40
cellular phone: +7 921 576-70-91
e-mail: krivenok at orangesystem.ru
web: http://www.orangesystem.ru
skype: krivenok_dmitry
jabber: krivenok_dmitry at jabber.ru
icq: 242-526-443
More information about the Strace-devel
mailing list