Re: up-arrow no longer works right

[Vincent Lefevre <vincent@xxxxxxxxxx>]

On 2009-03-20 07:33:26 -0700, Bart Schaefer wrote:
> I'm not sure what you mean by "interpreted by zsh" but this is most
> likely a problem with something that's attempting to set the title
> bar string of the terminal.

This can be reproduced with "zsh -f", and zsh doesn't attempt to
change the terminal title. But one may need to use a machine with
several processors, so that the race condition can be reproduced
(mine has 2 processors).

I've looked at strace output and I think I understand what happens:
a SIGCHLD interrupts an ioctl system call, which leaves the terminal
in an incorrect state.

I did:

vin:~> strace -t -o strace.out zsh -f
vin% emacs file1
^Z
zsh: suspended  emacs file1
vin% bg
[1]  + continued  emacs file1
vin% ^[[A^[[A^[[A^[[A^[[B^[[B^[[D^[[C^[[D^[[A^[[B^[[B^[[B^[[B^[[B^[[B^[[A^[[A^[[A^[[A

You can see what I get when typing the arrow keys.

Here's an excerpt of the strace output:

[...]
15:29:04 read(10, "b", 1)               = 1
15:29:05 write(10, "b", 1)              = 1
15:29:05 read(10, "g", 1)               = 1
15:29:05 write(10, "\10bg", 3)          = 3
15:29:05 read(10, "\n", 1)              = 1
15:29:05 write(10, "\r\n", 2)           = 2
15:29:05 alarm(0)                       = 0
15:29:05 ioctl(10, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig -icanon -echo ...}) = 0
15:29:05 ioctl(10, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig icanon echo ...}) = 0
15:29:05 ioctl(10, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
15:29:05 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
15:29:05 write(10, "[1]  + continued  emacs file1\n", 30) = 30
15:29:05 kill(4294946362, SIGCONT)      = 0
15:29:05 rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
15:29:05 rt_sigprocmask(SIG_UNBLOCK, [CHLD], [CHLD], 8) = 0
15:29:05 ioctl(10, TIOCSPGRP, [20933])  = 0
15:29:05 fstat(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 15), ...}) = 0
15:29:05 fcntl(0, F_GETFL)              = 0x8002 (flags O_RDWR|O_LARGEFILE)
15:29:05 geteuid()                      = 1114
15:29:05 capget(0x20080522, 0, NULL)    = -1 EFAULT (Bad address)
15:29:05 capget(0x20080522, 0, {0, 0, 0}) = 0
15:29:05 rt_sigaction(SIGINT, {0x474db0, [], SA_RESTORER|SA_INTERRUPT, 0x7f49a6593190}, NULL, 8) = 0
15:29:05 write(10, "\33[1m\33[7m%\33[27m\33[1m\33[m           "..., 101) = 101
15:29:05 rt_sigaction(SIGINT, {0x474db0, [], SA_RESTORER|SA_INTERRUPT, 0x7f49a6593190}, NULL, 8) = 0
15:29:05 geteuid()                      = 1114
15:29:05 capget(0x20080522, 0, NULL)    = -1 EFAULT (Bad address)
15:29:05 capget(0x20080522, 0, {0, 0, 0}) = 0
15:29:05 ioctl(10, FIONREAD, [0])       = 0
15:29:05 ioctl(10, TIOCSPGRP, [20933])  = 0
15:29:05 ioctl(10, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
15:29:05 ioctl(10, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig -icanon -echo ...}) = -1 EINTR (Interrupted system call)
15:29:05 --- SIGCHLD (Child exited) @ 0 (0) ---
15:29:05 rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [CHLD], 8) = 0
15:29:05 rt_sigprocmask(SIG_SETMASK, [CHLD], ~[KILL STOP RTMIN RT_1], 8) = 0
15:29:05 wait4(4294967295, 0x7fffaf3a553c, WNOHANG|WSTOPPED, 0x7fffaf3a5310) = 0
15:29:05 rt_sigreturn(0xffffffff)       = -1 EINTR (Interrupted system call)
15:29:05 write(10, "\r\33[m\33[27m\33[24m\33[Jvin% ", 22) = 22
[...]

Here's the corresponding excerpt in a case where the bug doesn't
occur:

[...]
15:56:24 read(10, "b", 1)               = 1
15:56:24 write(10, "b", 1)              = 1
15:56:24 read(10, "g", 1)               = 1
15:56:24 write(10, "\10bg", 3)          = 3
15:56:24 read(10, "\n", 1)              = 1
15:56:25 write(10, "\r\n", 2)           = 2
15:56:25 alarm(0)                       = 0
15:56:25 ioctl(10, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig -icanon -echo ...}) = 0
15:56:25 ioctl(10, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig icanon echo ...}) = 0
15:56:25 ioctl(10, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
15:56:25 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
15:56:25 write(10, "[1]  + continued  emacs file1\n", 30) = 30
15:56:25 kill(4294942461, SIGCONT)      = 0
15:56:25 rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
15:56:25 rt_sigprocmask(SIG_UNBLOCK, [CHLD], [CHLD], 8) = 0
15:56:25 --- SIGCHLD (Child exited) @ 0 (0) ---
15:56:25 rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [CHLD], 8) = 0
15:56:25 rt_sigprocmask(SIG_SETMASK, [CHLD], ~[KILL STOP RTMIN RT_1], 8) = 0
15:56:25 wait4(4294967295, 0x7fff6946271c, WNOHANG|WSTOPPED, 0x7fff694624f0) = 0
15:56:25 rt_sigreturn(0xffffffff)       = 0
15:56:25 ioctl(10, TIOCSPGRP, [24834])  = 0
15:56:25 fstat(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 7), ...}) = 0
15:56:25 fcntl(0, F_GETFL)              = 0x8002 (flags O_RDWR|O_LARGEFILE)
15:56:25 geteuid()                      = 1114
15:56:25 capget(0x20080522, 0, NULL)    = -1 EFAULT (Bad address)
15:56:25 capget(0x20080522, 0, {0, 0, 0}) = 0
15:56:25 rt_sigaction(SIGINT, {0x474db0, [], SA_RESTORER|SA_INTERRUPT, 0x7fb060650190}, NULL, 8) = 0
15:56:25 write(10, "\33[1m\33[7m%\33[27m\33[1m\33[m           "..., 101) = 101
15:56:25 rt_sigaction(SIGINT, {0x474db0, [], SA_RESTORER|SA_INTERRUPT, 0x7fb060650190}, NULL, 8) = 0
15:56:25 geteuid()                      = 1114
15:56:25 capget(0x20080522, 0, NULL)    = -1 EFAULT (Bad address)
15:56:25 capget(0x20080522, 0, {0, 0, 0}) = 0
15:56:25 ioctl(10, FIONREAD, [0])       = 0
15:56:25 ioctl(10, TIOCSPGRP, [24834])  = 0
15:56:25 ioctl(10, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
15:56:25 ioctl(10, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig -icanon -echo ...}) = 0
15:56:25 ioctl(10, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig -icanon -echo ...}) = 0
15:56:25 write(10, "\r\33[m\33[27m\33[24m\33[Jvin% ", 22) = 22
[...]

-- 
Vincent Lefèvre <vincent@xxxxxxxxxx> - Web: <http://www.vinc17.org/>
100% accessible validated (X)HTML - Blog: <http://www.vinc17.org/blog/>
Work: CR INRIA - computer arithmetic / Arenaire project (LIP, ENS-Lyon)