Ksh perde dados após piping 16k bytes

Question

Descobri recentemente que o ksh pode perder alguns dados depois de imprimir mais de 16K bytes no stdout se estiver bloqueado por alguns segundos.

Este script test.sh imprime 257 * 64 (16448) bytes:

#!/usr/bin/ksh
i=0
while [[ i -lt 257 ]]
do
    x=$(file /tmp)
    echo "0123456789ABCDEF0123456789ABCDEF0123456789ABCDEF0123456789ABCDE"
    i=$((i+1))
done |
while read datafile
do
    echo $datafile
done

Eu realizei o seguinte teste:

0 $ ./test.sh | wc -c
   16448
0 $ ./test.sh | (sleep 3; wc -c)
   16384

A linha x=$(file /tmp) parece afetar esse comportamento, embora não canalize nada para o segundo loop.

Se eu usar bash, isso funciona como esperado.

Parece um erro para mim no ksh. Eu estou usando o Solaris 5.10. Existe uma solução ou solução para isso? Qual é a causa raiz deste problema? Eu acho que isso pode estar relacionado ao tamanho do buffer de pipe.

Obrigado Peter

EDITAR:

Então, executando o teste com truss , vejo um erro ao gravar os últimos 64 bytes:

ioctl(0, I_PEEK, 0x08046B40)                    = 0
    Received signal #18, SIGCLD, in write() [caught]
      siginfo: SIGCLD CLD_EXITED pid=6561 status=0x0000
write(1, " 0 1 2 3 4 5 6 7 8 9 A B".., 64)      Err#4 EINTR
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
setcontext(0x08046670)
read(0, 0x0809064C, 1)                          = 0
ioctl(0, TCGETA, 0x08046B18)                    Err#22 EINVAL

Executando o mesmo script com dtksh se parece com abaixo. Como Stephane indicou, a gravação falhada é tentada novamente.

ioctl(0, I_PEEK, 0x08046694)                    = 1
read(0, " 0 1 2 3 4 5 6 7 8 9 A B".., 64)       = 64
Received signal #18, SIGCLD, in write() [caught]
  siginfo: SIGCLD CLD_EXITED pid=28276 status=0x0000
write(1, " 0 1 2 3 4 5 6 7 8 9 A B".., 64)      Err#4 EINTR
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
waitid(P_ALL, 0, 0x08046500, WEXITED|WTRAPPED|WSTOPPED|WNOHANG) = 0
waitid(P_ALL, 0, 0x08046500, WEXITED|WTRAPPED|WSTOPPED|WNOHANG) Err#10 ECHILD
sigaction(SIGCLD, 0x08046510, 0x08046580)       = 0
setcontext(0x08046430)
write(1, 0x080F0FD8, 64)        (sleeping...)
write(1, " 0 1 2 3 4 5 6 7 8 9 A B".., 64)      = 64
ioctl(0, I_PEEK, 0x08046694)                    = 0

    

Answer 1

Isso realmente parece um bug em ksh .

O que eu suspeito é que em

x=$(file /tmp)

ksh gera um novo processo para executar o comando file e lê sua saída por meio de um canal, não aguardando sua finalização (como todos os shells modernos, incluindo as versões modernas do ksh), mas esse comando retorna assim que o EOF é atingido ao ler esse pipe.

Esse comportamento pode ser confirmado pela execução:

ksh -c 'x=$(exec sh -c "echo foo;exec >&-; sleep 10"); echo "$x"'

E verifique se ksh retorna imediatamente após ter saído em foo ou após 10 segundos.

Se for esse o caso, significa que o comando file será finalizado e fará com que um SIGCLD seja enviado para seu pai (o shell), após o comando x=... retornou.

O shell destina-se a lidar com esses SIGCLD para indagar sobre a morte de seu filho. Se o shell tiver um filho correndo em segundo plano, ele deve estar pronto para que a morte aconteça a qualquer momento. Esse sinal SIGCLD, assim como qualquer sinal não ignorado, faria com que uma chamada de sistema de bloqueio fosse interrompida . O shell deve estar pronto para que isso aconteça, bloqueando o sinal enquanto faz uma chamada do sistema que pode ser interrompida, ou reativando a chamada do sistema interrompida depois de ter manipulado o sinal.

Neste caso, parece que nada disso está acontecendo. Na maioria das vezes, a chamada do sistema write executada pelo ksh sobre a execução imediata do echo retorna, portanto, não há chance de ser interrompida, mas após o canal para o qual o stdout aponta está cheio, o sistema write a chamada acaba bloqueando e é quando é interrompida pelo SIGCLD. E o ksh não tenta novamente qual é o bug.

Podemos ver o mesmo comportamento, mesmo no Linux, se corrermos

strace -e write ksh -c 'i=0; while [ "$i" -lt 2000 ]; do : &
  echo xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
  i=$(($i+1)); done' | (sleep 3; wc)

Então vemos:

write(1, "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"..., 61) = ? ERESTARTSYS (To be restarted)
--- SIGCHLD (Child exited) @ 0 (0) ---
write(1, "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"..., 61...

É o mesmo, o comando : de finalização faz com que a chamada do sistema write de bloqueio seja interrompida, mas, desta vez, o write é reativado.

Uma solução alternativa pode consistir em evitar substituições de comandos antes de uma chamada para um echo integrado, ou certificar-se de que write seja feito por um processo diferente daquele que obtém o SIGCLD, por exemplo executando echo comando em um subshell:

(echo "012...")

EDITAR : Um olhar mais atento na saída truss revela que é o rastreamento do segundo loop que deve ser executado em um processo separado daquele que está executando o outro loop, então não deveria estar recebendo o SIGCLD da morte dos comandos file . Poderia ter um SIGCLD, a partir do término do subshell executando o primeiro loop.

Além disso, se, como o resultado do seu teste sugere, o ksh esperar pelos processos gerados para a substituição de comandos, então os sinais SIGCLD recebidos não podem ser explicados pela terminação assíncrona do comando file .

O que parece mais provável é que o pipe externo fique cheio, mas não o pipe entre os dois loops while, o SIGCLD é recebido durante o bloqueio echo no segundo loop e vem da terminação do primeiro loop. Portanto, uma solução mais eficiente seria executar o segundo loop em um subshell em vez de cada comando echo .

while ...; done | (while ...;done)