[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: bash randomly logs out on VT / serial console
|
From: |
Russell King |
|
Subject: |
Re: bash randomly logs out on VT / serial console |
|
Date: |
Mon, 2 Jan 2017 23:33:16 +0000 |
|
User-agent: |
Mutt/1.5.23 (2014-03-12) |
On Mon, Jan 02, 2017 at 02:06:01PM -0500, Chet Ramey wrote:
> On 1/2/17 6:09 AM, Russell King wrote:
> > On Sun, Jan 01, 2017 at 09:14:45PM -0500, Chet Ramey wrote:
> >> On 1/1/17 4:01 PM, rmk@armlinux.org.uk wrote:
> >>> Bash Version: 4.3
> >>> Patch Level: 30
> >>> Release Status: release
> >>>
> >>> Description:
> >>> Running:
> >>> while :; do s=$(sleep .005 | cat); echo $s; done | uniq
> >>> in a login shell on a virtual terminal or serial console results
> >>> in the shell randomly logging out after ^C.
> >>
> >> I believe this is fixed in bash-4.4.
> >
> > Thank you for your reply.
> >
> > However, while testing bash-4.4 with the five additional patches (bringing
> > it to 4.4.5) shows that it is not fixed in bash-4.4 - see below. The line
> > from __tty_check_change() is from the debug I added to the kernel, which
> > shows that the reason for the EIO error is because the tty pgrp doesn't
> > match the process' pgrp.
>
> OK. I can't reproduce it on Fedora 25.
Thank you for your reply.
Here's more information from the strace logs in case it helps - these
are from the "useful" command rather than the one which I quoted in
the bug report which reproduces it as well - "mii-diag" for the "sleep"
and "sed" for the "cat" part - otherwise identical. Note that I'm
running a modified mii-diag here...
PID 10928 - the top level login shell:
=========
17:38:38.716472 pipe2([3, 4], 0) = 0
17:38:38.716555 rt_sigprocmask(SIG_BLOCK, [INT CHLD], [CHLD], 8) = 0
17:38:38.716617 pipe2([5, 6], 0) = 0
17:38:38.716677 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7fae66c0d0) = 14119
17:38:38.717076 setpgid(14119, 14119) = 0
17:38:38.717185 rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
17:38:38.717249 close(4) = 0
17:38:38.717301 close(4) = -1 EBADF (Bad file descriptor)
17:38:38.717398 rt_sigprocmask(SIG_BLOCK, [INT CHLD], [CHLD], 8) = 0
17:38:38.717463 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7fae66c0d0) = 14120
17:38:38.717936 setpgid(14120, 14119) = 0
17:38:38.719654 rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
17:38:38.719764 close(3) = 0
17:38:38.722508 rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
17:38:38.722576 close(5) = 0
17:38:38.722626 close(6) = 0
17:38:38.745323 ioctl(255, TIOCGPGRP, [14119]) = 0
17:38:38.745381 rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
17:38:38.745501 rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
17:38:38.745560 wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGINT}],
WSTOPPED|WCONTINUED, NULL) = 14120
17:38:39.477455 wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGINT}],
WSTOPPED|WCONTINUED, NULL) = 14119
Here, the two sub-shells (pid 14119 and 14120) that bash has
spawned were terminated by SIGINT.
17:38:39.477971 rt_sigprocmask(SIG_BLOCK, [CHLD TSTP TTIN TTOU], [CHLD], 8) = 0
17:38:39.478119 ioctl(255, SNDRV_TIMER_IOCTL_SELECT or TIOCSPGRP, [10928]) = 0
17:38:39.478250 rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
17:38:39.478395 ioctl(255, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE
or TCGETS, {B115200 opost isig icanon echo ...}) = 0
17:38:39.478626 ioctl(255, SNDCTL_TMR_STOP or SNDRV_TIMER_IOCTL_GINFO or
TCSETSW, {B115200 opost isig icanon echo ...}) = 0
17:38:39.478782 ioctl(255, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE
or TCGETS, {B115200 opost isig icanon echo ...}) = 0
17:38:39.479323 ioctl(255, TIOCGWINSZ, {ws_row=25, ws_col=80, ws_xpixel=0,
ws_ypixel=0}) = 0
17:38:39.479488 write(1, "\n", 1) = 1
17:38:39.479583 rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
17:38:39.479653 close(3) = -1 EBADF (Bad file descriptor)
17:38:39.479711 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.479802 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED,
si_pid=14120, si_status=SIGINT, si_utime=0, si_stime=0} ---
17:38:39.479857 wait4(-1, 0x7fc81f8300, WNOHANG|WSTOPPED|WCONTINUED, NULL) = -1
ECHILD (No child processes)
17:38:39.479921 rt_sigreturn() = 0
17:38:39.480088 rt_sigaction(SIGINT, {0x45e080, [], 0}, {0x45e080, [], 0}, 8) = 0
17:38:39.480311 rt_sigprocmask(SIG_BLOCK, [CHLD TSTP TTIN TTOU], [], 8) = 0
17:38:39.480458 ioctl(255, SNDRV_TIMER_IOCTL_SELECT or TIOCSPGRP, [10928]) = 0
Here, the top level shell sets the TTY PGRP to 10928. Note
the time stamp - 17:38:39.480458.
17:38:39.480614 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.480740 rt_sigaction(SIGINT, {0x45e080, [], 0}, {0x45e080, [], 0}, 8) = 0
17:38:39.480941 ioctl(0, TIOCGWINSZ, {ws_row=25, ws_col=80, ws_xpixel=0,
ws_ypixel=0}) = 0
17:38:39.481081 ioctl(0, SNDRV_TIMER_IOCTL_STATUS or TIOCSWINSZ, {ws_row=25,
ws_col=80, ws_xpixel=0, ws_ypixel=0}) = 0
17:38:39.481198 ioctl(0, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE
or TCGETS, {B115200 opost isig icanon echo ...}) = 0
17:38:39.481367 ioctl(0, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE
or TCGETS, {B115200 opost isig icanon echo ...}) = 0
17:38:39.481478 ioctl(0, SNDCTL_TMR_STOP or SNDRV_TIMER_IOCTL_GINFO or TCSETSW,
{B115200 opost isig -icanon -echo ...}) = 0
17:38:39.481606 ioctl(0, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE
or TCGETS, {B115200 opost isig -icanon -echo ...}) = 0
17:38:39.481713 rt_sigprocmask(SIG_BLOCK, [HUP INT QUIT ALRM TERM TSTP TTIN
TTOU], [], 8) = 0
17:38:39.481779 rt_sigaction(SIGINT, {0x4aaa78, [], 0}, {0x45e080, [], 0}, 8) = 0
17:38:39.481868 rt_sigaction(SIGTERM, {0x4aaa78, [], 0}, {0x45dc08, [],
SA_RESTART}, 8) = 0
17:38:39.481962 rt_sigaction(SIGHUP, {0x4aaa78, [], 0}, {0x45e2f8, [HUP INT ILL
TRAP ABRT BUS FPE USR1 SEGV USR2 PIPE ALRM TERM XCPU XFSZ VTALRM SYS], 0}, 8) = 0
17:38:39.482055 rt_sigaction(SIGQUIT, {0x4aaa78, [], 0}, {SIG_IGN, [], 0}, 8) = 0
17:38:39.482145 rt_sigaction(SIGQUIT, {SIG_IGN, [], 0}, {0x4aaa78, [], 0}, 8) = 0
17:38:39.482216 rt_sigaction(SIGALRM, {0x4aaa78, [], 0}, {0x45e2f8, [HUP INT
ILL TRAP ABRT BUS FPE USR1 SEGV USR2 PIPE ALRM TERM XCPU XFSZ VTALRM SYS], 0},
8) = 0
17:38:39.482278 rt_sigaction(SIGTSTP, {0x4aaa78, [], 0}, {SIG_IGN, [], 0}, 8) = 0
17:38:39.482338 rt_sigaction(SIGTSTP, {SIG_IGN, [], 0}, {0x4aaa78, [], 0}, 8) = 0
17:38:39.482430 rt_sigaction(SIGTTOU, {0x4aaa78, [], 0}, {SIG_IGN, [], 0}, 8) = 0
17:38:39.482520 rt_sigaction(SIGTTOU, {SIG_IGN, [], 0}, {0x4aaa78, [], 0}, 8) = 0
17:38:39.482615 rt_sigaction(SIGTTIN, {0x4aaa78, [], 0}, {SIG_IGN, [], 0}, 8) = 0
17:38:39.482695 rt_sigaction(SIGTTIN, {SIG_IGN, [], 0}, {0x4aaa78, [], 0}, 8) = 0
17:38:39.482752 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.482802 rt_sigaction(SIGWINCH, {0x4aa11c, [], SA_RESTART}, {0x45dbf8,
[], 0}, 8) = 0
17:38:39.482909 write(2, "root@mcbin:~# ", 14) = 14
17:38:39.483027 read(0, "\33", 1) = 1
Here, it had access to the tty to read a character.
17:38:39.870424 read(0, 0x7fc81f8737, 1) = -1 EIO (Input/output error)
But here it's lost access to it.
17:38:39.884115 write(2, "\7", 1) = 1
17:38:39.884212 read(0, 0x7fc81f87a7, 1) = -1 EIO (Input/output error)
PID 14119 - this is the sub-shell process running the while() loop:
=========
17:38:39.471277 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
17:38:39.471405 pipe2([3, 4], 0) = 0
17:38:39.471471 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
17:38:39.471528 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.471579 rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) = 0
17:38:39.471636 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7fae66c0d0) = 14241
It spawns pid 14241, that being the $(...) part of the command.
17:38:39.472177 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.472275 rt_sigaction(SIGCHLD, {0x4474ac, [], SA_RESTART}, {0x4474ac,
[], SA_RESTART}, 8) = 0
17:38:39.472381 close(4) = 0
17:38:39.472522 read(3, 0x7fc81f8998, 128) = ? ERESTARTSYS (To be restarted if
SA_RESTART is set)
17:38:39.476768 --- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
It receives the SIGINT.
17:38:39.476803 rt_sigreturn() = -1 EINTR (Interrupted system call)
17:38:39.476878 rt_sigprocmask(SIG_BLOCK, [CHLD TSTP TTIN TTOU], [], 8) = 0
17:38:39.476968 ioctl(255, SNDRV_TIMER_IOCTL_SELECT or TIOCSPGRP, [10875]) = 0
Sets the TTY's PGRP to 10875 - the login process - but this is
before the top-level shell has done anything, so this one is
safe. However, note that this doesn't wait for the process it
spawned for the $(...).
17:38:39.477053 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.477123 setpgid(0, 10875) = 0
17:38:39.477271 rt_sigaction(SIGINT, {SIG_DFL, [], 0}, {0x45e2f8, [], 0}, 8) =
017:38:39.477350 kill(14119, SIGINT) = 0
17:38:39.477421 --- SIGINT {si_signo=SIGINT, si_code=SI_USER, si_pid=14119,
si_uid=0} ---
17:38:39.477819 +++ killed by SIGINT +++
The top level shell gets notified of this thread dying at in
the wait4() call issued at 17:38:39.477455.
PID 14120 - this is the "uniq" thread:
=========
17:38:39.471192 read(0, 0x7f83fc5000, 4096) = ? ERESTARTSYS (To be restarted if
SA_RESTART is set)
17:38:39.476335 --- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
17:38:39.476646 +++ killed by SIGINT +++
The top level shell gets notified of this thread dying at in
the wait4() call issued at 17:38:38.745560.
PID 14241 - the sub-shell running the $(...) pipeline:
=========
17:38:39.472098 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.472248 rt_sigaction(SIGTSTP, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.472355 rt_sigaction(SIGTTIN, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.472495 rt_sigaction(SIGTTOU, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.472580 rt_sigaction(SIGINT, {SIG_DFL, [], 0}, {0x45e2f8, [], 0}, 8) =
017:38:39.472646 rt_sigaction(SIGQUIT, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.472709 rt_sigaction(SIGTERM, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.472771 rt_sigaction(SIGCHLD, {SIG_DFL, [], SA_RESTART}, {0x4474ac,
[], SA_RESTART}, 8) = 0
17:38:39.472838 rt_sigaction(SIGCHLD, {0x4474ac, [], SA_RESTART}, {SIG_DFL, [],
SA_RESTART}, 8) = 0
17:38:39.472902 rt_sigaction(SIGINT, {0x45e2f8, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.472980 dup3(4, 1, 0) = 1
17:38:39.473035 close(4) = 0
17:38:39.473086 close(3) = 0
17:38:39.473243 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
17:38:39.473439 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
17:38:39.473506 pipe2([3, 4], 0) = 0
17:38:39.473581 rt_sigprocmask(SIG_BLOCK, [INT CHLD], [CHLD], 8) = 0
17:38:39.473644 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7fae66c0d0) = 14242
17:38:39.474112 rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
17:38:39.474236 close(4) = 0
17:38:39.474344 close(4) = -1 EBADF (Bad file descriptor)
17:38:39.474470 rt_sigprocmask(SIG_BLOCK, [INT CHLD], [CHLD], 8) = 0
17:38:39.474545 clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0x7fae66c0d0) = 14243
17:38:39.475232 rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
17:38:39.475313 close(3) = 0
17:38:39.475468 rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
17:38:39.475541 rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
17:38:39.475608 rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
17:38:39.475687 rt_sigaction(SIGINT, {0x4445d0, [], 0}, {0x45e2f8, [], 0}, 8) = 0
17:38:39.475790 wait4(-1, 0x7fc81f8210, 0, NULL) = ? ERESTARTSYS (To be
restarted if SA_RESTART is set)
17:38:39.476106 --- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
Here, this shell receives the SIGINT...
17:38:39.476147 rt_sigreturn() = -1 EINTR (Interrupted system call)
17:38:39.476214 wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGINT}], 0, NULL)
= 14243
17:38:39.479198 wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGPIPE}], 0,
NULL) = 14242
and waits for both processes of the pipeline to finish before
exiting...
17:38:39.485326 rt_sigaction(SIGINT, {0x45e2f8, [], 0}, {0x4445d0, [], 0}, 8) = 0
17:38:39.485396 rt_sigprocmask(SIG_BLOCK, [CHLD TSTP TTIN TTOU], [CHLD], 8) = 0
17:38:39.485459 ioctl(255, SNDRV_TIMER_IOCTL_SELECT or TIOCSPGRP, [10875]) = 0
Remember, the top level bash process issued its TIOCSPGRP
call at 17:38:39.480458, and the read() call to read the
first character of new input at 17:38:39.483027.
So this sub-shell process sets the terminal PGRP to 10875
(login) _after_ PID 10928 has set the TTY to itself and
issued the first read().
17:38:39.485527 rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
17:38:39.485584 setpgid(0, 10875) = 0
Sets its own PGRP to 10875, and...
17:38:39.485652 rt_sigaction(SIGINT, {SIG_DFL, [], 0}, {0x45e2f8, [], 0}, 8) =
017:38:39.485781 kill(14241, SIGINT) = 0
17:38:39.485839 --- SIGINT {si_signo=SIGINT, si_code=SI_USER, si_pid=14241,
si_uid=0} ---
17:38:39.486130 +++ killed by SIGINT +++
Kills itself.
PID 14242 - which eventually becomes the mii-diag command (sleep as per the
========= example I submitted.)
17:38:39.474043 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.474205 rt_sigaction(SIGTSTP, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.474288 rt_sigaction(SIGTTIN, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.474365 rt_sigaction(SIGTTOU, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.474449 close(3) = 0
17:38:39.474524 dup3(4, 1, 0) = 1
17:38:39.474588 close(4) = 0
17:38:39.474868 newfstatat(AT_FDCWD, ".", {st_mode=S_IFDIR|0700, st_size=4096,
...}, 0) = 0
17:38:39.475152 newfstatat(AT_FDCWD, "/root/bin/mii-diag",
{st_mode=S_IFREG|0755, st_size=81712, ...}, 0) = 0
17:38:39.475259 newfstatat(AT_FDCWD, "/root/bin/mii-diag",
{st_mode=S_IFREG|0755, st_size=81712, ...}, 0) = 0
17:38:39.475333 geteuid() = 0
17:38:39.475448 getegid() = 0
17:38:39.475522 getuid() = 0
17:38:39.475590 getgid() = 0
17:38:39.475662 faccessat(AT_FDCWD, "/root/bin/mii-diag", X_OK) = 0
17:38:39.475743 newfstatat(AT_FDCWD, "/root/bin/mii-diag",
{st_mode=S_IFREG|0755, st_size=81712, ...}, 0) = 0
17:38:39.476059 geteuid() = 0
17:38:39.476128 --- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
We're still in the shell, and preparing to run the mii-diag
command. However, we appear to do nothing with the SIGINT
that we received....
17:38:39.476168 rt_sigreturn() = 0
17:38:39.476234 getegid() = 0
17:38:39.476564 getuid() = 0
17:38:39.476745 getgid() = 0
17:38:39.476822 faccessat(AT_FDCWD, "/root/bin/mii-diag", R_OK) = 0
17:38:39.476905 newfstatat(AT_FDCWD, "/root/bin/mii-diag",
{st_mode=S_IFREG|0755, st_size=81712, ...}, 0) = 0
17:38:39.476993 newfstatat(AT_FDCWD, "/root/bin/mii-diag",
{st_mode=S_IFREG|0755, st_size=81712, ...}, 0) = 0
17:38:39.477078 geteuid() = 0
17:38:39.477144 getegid() = 0
17:38:39.477251 getuid() = 0
17:38:39.477330 getgid() = 0
17:38:39.477395 faccessat(AT_FDCWD, "/root/bin/mii-diag", X_OK) = 0
17:38:39.477507 newfstatat(AT_FDCWD, "/root/bin/mii-diag",
{st_mode=S_IFREG|0755, st_size=81712, ...}, 0) = 0
17:38:39.477777 geteuid() = 0
17:38:39.477952 getegid() = 0
17:38:39.478100 getuid() = 0
17:38:39.478232 getgid() = 0
17:38:39.478370 faccessat(AT_FDCWD, "/root/bin/mii-diag", R_OK) = 0
17:38:39.478599 rt_sigaction(SIGINT, {SIG_DFL, [], 0}, {0x45e2f8, [], 0}, 8) =
017:38:39.478756 rt_sigaction(SIGQUIT, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.479172 rt_sigaction(SIGTERM, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.479259 rt_sigaction(SIGCHLD, {SIG_DFL, [], SA_RESTART}, {0x4474ac,
[], SA_RESTART}, 8) = 0
17:38:39.479414 execve("/root/bin/mii-diag", ["mii-diag", "eth0", "-p",
"32775", "-W", "1,25,26,27,0xa026,0xa027,0xa028"], [/* 18 vars */]) = 0
... since we continue on blindly and start the command,
completely ignoring the SIGINT signal. I've omitted most
of the trace from mii-diag here...
17:38:39.484932 close(3) = 0
17:38:39.485006 write(1, "Using the specified MII PHY inde"..., 195) = -1 EPIPE
(Broken pipe)
17:38:39.485076 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=14242,
si_uid=0} ---
17:38:39.485235 +++ killed by SIGPIPE +++
eventually only being killed when mii-diag produces the
first line of output due to the other side of the pipe
having died. This causes PID 14241's wait4() at
17:38:39.479198 to complete - note the time stamp here,
way after the top level shell has issued its prompt and
entered requested a character from the TTY.
PID 14243 - this would have become the sed (cat as per the example I
========= submitted)
17:38:39.475018 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.475419 rt_sigaction(SIGTSTP, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.475882 rt_sigaction(SIGTTIN, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.475940 rt_sigaction(SIGTTOU, {SIG_DFL, [], 0}, {SIG_DFL, [], 0}, 8) =
017:38:39.476035 --- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
17:38:39.476298 rt_sigreturn() = 0
17:38:39.476689 dup3(3, 0, 0) = 0
17:38:39.477485 close(3) = 0
17:38:39.477742 rt_sigprocmask(SIG_BLOCK, [CHLD TSTP TTIN TTOU], [], 8) = 0
17:38:39.477927 ioctl(255, SNDRV_TIMER_IOCTL_SELECT or TIOCSPGRP, [10875]) = 0
17:38:39.478074 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
17:38:39.478209 setpgid(0, 10875) = 0
17:38:39.478342 rt_sigaction(SIGINT, {SIG_DFL, [], 0}, {0x45e2f8, [], 0}, 8) =
017:38:39.478575 kill(14243, SIGINT) = 0
17:38:39.478732 --- SIGINT {si_signo=SIGINT, si_code=SI_USER, si_pid=14243,
si_uid=0} ---
17:38:39.479079 +++ killed by SIGINT +++
This never got far enough to start anything, having just set
the default handler for SIGINT, and then been terminated by
the SIGINT - this closes the other end of PID 14242's pipe.
This also causes PID 14240's wait4() at 17:38:39.476214 to
complete.
This is far from a rare event - for me it is very reproducable.
Trying different sleep durations from .1 to .001sec shows that it's
most prevalent at around .005 - .05 seconds. Trying 1 second seems
to make it difficult to hit.
As I see it from the above strace, there are two problems with bash
in the above strace:
1. PID 14242 received but otherwise totally ignored the SIGINT, and
proceeded to execute the command it was planning to all along.
2. PID 14119 failed to wait for PID 14241 to exit before itself
exiting, orphaning the $(...) commands - which then causes the
top level shell to present its prompt.
I consider both of these to be bugs in bash which add up to cause this
undesirable and annoying behaviour.
--
Russell King