Sporadic byte loss in read builtin

[Rob Foehl]

The attached script will provoke an occasional loss of a single byte when 
the read builtin is used with a timeout.  Output will eventually look 
something like this after a failure:

x: ab (2)
x: cd (2)
x: ef (2)
x: g (1)
x: hi (2)
x: j (1)
x: l (1)
x: mn (2)
x: op (2)
x: q (1)
x: rs (2)
x: tu (2)
x: v (1)
x: wx (2)
x: yz (2)
x:  (0)
a: abcdefghijlmnopqrstuvwxyz (25)

missed k (1); failed after 5 iterations


Looking at strace output for the same run, the "missing" byte is clearly 
read before it disappears:

read(0, "j", 1)                         = 1
read(0, "k", 1)                         = 1
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = 1
setitimer(ITIMER_REAL, {it_interval={tv_sec=0, tv_usec=0}, it_value={tv_sec=0, 
tv_usec=0}}, {it_interval={tv_sec=0, tv_usec=0}, it_value={tv_sec=0, 
tv_usec=0}}) = 0
rt_sigaction(SIGALRM, {sa_handler=0x55a25bf02330, sa_mask=[], 
sa_flags=SA_RESTORER, sa_restorer=0x7ff79afdc6e0}, {sa_handler=0x55a25bf249e0, 
sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7ff79afdc6e0}, 8) = 0
write(1, "x: j (1)\n", 9)               = 9
ioctl(0, TCGETS, 0x7ffe0644fde0)        = -1 ENOTTY (Inappropriate ioctl for 
device)
lseek(0, 0, SEEK_CUR)                   = -1 ESPIPE (Illegal seek)
fstat(0, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
rt_sigaction(SIGALRM, {sa_handler=0x55a25bf249e0, sa_mask=[], 
sa_flags=SA_RESTORER, sa_restorer=0x7ff79afdc6e0}, {sa_handler=0x55a25bf02330, 
sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7ff79afdc6e0}, 8) = 0
setitimer(ITIMER_REAL, {it_interval={tv_sec=0, tv_usec=0}, it_value={tv_sec=0, 
tv_usec=10000}}, {it_interval={tv_sec=0,tv_usec=0}, it_value={tv_sec=0, 
tv_usec=0}}) = 0
read(0, "l", 1)                         = 1
read(0, 0x7ffe0644ff76, 1)              = ? ERESTARTSYS (To be restarted if 
SA_RESTART is set)
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---
rt_sigreturn({mask=[]})                 = -1 EINTR (Interrupted system call)
setitimer(ITIMER_REAL, {it_interval={tv_sec=0, tv_usec=0}, it_value={tv_sec=0, 
tv_usec=0}}, {it_interval={tv_sec=0, tv_usec=0}, it_value={tv_sec=0, 
tv_usec=0}}) = 0
rt_sigaction(SIGALRM, {sa_handler=0x55a25bf02330, sa_mask=[], 
sa_flags=SA_RESTORER, sa_restorer=0x7ff79afdc6e0}, {sa_handler=0x55a25bf249e0, 
sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7ff79afdc6e0}, 8) = 0
write(1, "x: l (1)\n", 9)               = 9


This happens at random intervals on all machines I've tested with a 4.4 
release, including 4.4.19 on current Fedora 27.  Curiously, it seems to 
reliably return none of the read bytes but still consumes all input (and 
terminates) when run on various earlier 4.x releases, at least with the 
default timing parameters.

The missing byte(s) are always the last read prior to a SIGALRM.  Poking 
around in builtins/read.def, I'd guess that it's due to one of the 
CHECK_ALRM calls between the actual read and the update to input_string 
causing this bit to run with i == 0:

          /* Tricky.  The top of the unwind-protect stack is the free of
             input_string.  We want to run all the rest and use input_string,
             so we have to save input_string temporarily, run the unwind-
             protects, then restore input_string so we can use it later */
          orig_input_string = 0;
          input_string[i] = '\0';       /* make sure it's terminated */
          if (i == 0)
            {
              t = (char *)xmalloc (1);
              t[0] = 0;
            }
          else
            t = savestring (input_string);


I haven't actually tested this theory, though.  Like it says, "tricky". ;)

-Rob

bash-read-timeout-test
Description: Text document