[Toybox] weird timeout flake
Colin Cross
ccross at google.com
Tue Oct 3 21:43:45 PDT 2023
I caught it running in strace. There's some differences in signal
setup in the forked child, the child exits with 126 in both the good
and bad cases, but the parent exits with 127 after wait4 returns
ECHILD in the bad case.
The good case, child exits with 126, parent exits with 126:
rt_sigaction(SIGCHLD, {sa_handler=0x62dec726e4, sa_mask=[],
sa_flags=SA_NOCLDSTOP}, NULL, 8) = 0
clone(child_stack=NULL,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7aeae52190) = 9374
strace: Process 9374 attached
[pid 9374] prctl(PR_SET_VMA, PR_SET_VMA_ANON_NAME, 0x7ae9b4b000,
16384, "stack_and_tls:main") = 0
[pid 9373] rt_sigaction(SIGTTIN, {sa_handler=SIG_IGN, sa_mask=[],
sa_flags=0}, NULL, 8) = 0
[pid 9373] rt_sigaction(SIGTTOU, {sa_handler=SIG_IGN, sa_mask=[],
sa_flags=0}, NULL, 8) = 0
[pid 9373] rt_sigaction(SIGTSTP, {sa_handler=SIG_IGN, sa_mask=[],
sa_flags=0}, NULL, 8) = 0
[pid 9373] pipe2([3, 4], 0) = 0
[pid 9373] ppoll([{fd=4, events=POLLIN}], 1, {tv_sec=0,
tv_nsec=100000000}, NULL, 0 <unfinished ...>
[pid 9374] rt_sigaction(SIGCHLD, {sa_handler=SIG_DFL, sa_mask=[],
sa_flags=0}, NULL, 8) = 0
[pid 9374] setpgid(0, 0) = 0
[pid 9374] execve("/", ["/"], 0x7fcb8db718 /* 26 vars */) = -1 EACCES
(Permission denied)
[pid 9374] write(2, "timeout: ", 9timeout: ) = 9
[pid 9374] write(2, "exec /", 6exec /) = 6
[pid 9374] write(2, ": Permission denied", 19: Permission denied) = 19
[pid 9374] write(2, "\n", 1
) = 1
[pid 9374] exit_group(126) = ?
[pid 9374] +++ exited with 126 +++
<... ppoll resumed> ) = ? ERESTARTNOHAND (To be
restarted if no handler)
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=9374,
si_uid=2000, si_status=126, si_utime=0, si_stime=0} ---
rt_sigprocmask(SIG_SETMASK, [RTMIN], NULL, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, NULL, 8) = 0
close(3) = 0
close(4) = 0
wait4(9374, [{WIFEXITED(s) && WEXITSTATUS(s) == 126}], 0, NULL) = 9374
exit_group(126) = ?
+++ exited with 126 +++
The bad case, child exits with 126, parent exits with 127:
rt_sigaction(SIGCHLD, {sa_handler=0x5fda0c26e4, sa_mask=[],
sa_flags=SA_NOCLDSTOP}, NULL, 8) = 0
clone(child_stack=NULL,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7eadf59190) = 9378
strace: Process 9378 attached
[pid 9378] prctl(PR_SET_VMA, PR_SET_VMA_ANON_NAME, 0x7eacc52000,
16384, "stack_and_tls:main") = 0
[pid 9378] rt_sigaction(SIGCHLD, {sa_handler=SIG_DFL, sa_mask=[],
sa_flags=0}, NULL, 8) = 0
[pid 9378] setpgid(0, 0) = 0
[pid 9378] execve("/", ["/"], 0x7feb7bad98 /* 26 vars */) = -1 EACCES
(Permission denied)
[pid 9378] write(2, "timeout: ", 9timeout: ) = 9
[pid 9378] write(2, "exec /", 6exec /) = 6
[pid 9378] write(2, ": Permission denied", 19: Permission denied) = 19
[pid 9378] write(2, "\n", 1
) = 1
[pid 9378] exit_group(126) = ?
[pid 9378] +++ exited with 126 +++
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=9378,
si_uid=2000, si_status=126, si_utime=0, si_stime=0} ---
rt_sigprocmask(SIG_SETMASK, [RTMIN], NULL, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, NULL, 8) = 0
wait4(0, 0xe000007feb7baae0, 0, NULL) = -1 ECHILD (No child processes)
exit_group(127) = ?
+++ exited with 127 +++
More information about the Toybox
mailing list