Os arquivos de log são gravados quando um buffer é preenchido ou em 'tempo real'?

Question

Eu tenho um script em execução que canaliza sua saída através de outro script; esse script de wrapper adiciona um registro de data e hora a cada linha do log. No entanto, os dados estão sendo gravados no arquivo de log em blocos de aproximadamente 8000 caracteres (aproximadamente 180 linhas). Isso está fazendo com que todas essas linhas tenham o mesmo registro de data e hora. Se o script subjacente que está transmitindo informações for executado diretamente no shell, as saídas aparecerão linha por linha em tempo real.

Para referência, o script é assim:

#!/bin/bash
python foo.py | ~/timestamp.sh >> ~/logs/foo.log
exit

O script de registro de data e hora apenas adiciona um, você adivinhou, o registro de data e hora a cada linha de saída. Esse script contém o seguinte:

#!/bin/bash
while read x; do
  echo -n 'date +%d/%m/%Y\ %H:%M:%S';
  echo -n " ";
  echo $x;
done

Se eu remover o timestamp.sh da equação, o comportamento é exatamente o mesmo. Eu verifiquei isso executando o script e monitorando o arquivo de log usando tail -f script.log

Existe uma configuração que armazena em buffer a saída do arquivo antes de gravá-lo nos arquivos de log? Existem outros métodos que eu posso tentar timestamp cada linha de um arquivo de log? Eu tive esse tipo de coisa de trabalho antes em sistemas anteriores, mas não importa o que eu tente nada parece estar classificando isso.

Isso tudo está no Ubuntu 14.04.4 x64

    

Answer 1

A causa raiz é o seu processo, aqui python , está usando libc stdout em que a saída é armazenada em buffer quando é enviada para um terminal mas bloqueada em buffer quando é enviada para algo diferente, como um pipe aqui. p>

Você pode corrigir o problema no código python, limpando explicitamente o buffer após cada saída de log:

sys.stdout.flush()

ou controlando como o buffering será feito com algum hack:

stdbuf -oL python foo.py | ~/timestamp.sh >> ~/logs/foo.log

ou

unbuffer python foo.py | ~/timestamp.sh >> ~/logs/foo.log

Eu recomendaria explicitamente liberar o buffer em seu código ( sys.stdout.flush() ), já que você é o único a saber exatamente onde a saída deve ser liberada. O buffer de linha ( stdbuf -oL ) é um pouco menos otimizado, mas deve ser ok, já que você marca o timestamp por linha, e desabilitar todo o buffering ( unbuffer ou python -u sugestão de heemayl) é a pior abordagem em termos de desempenho ( embora possa ser imperceptível dependendo de como o seu código python está escrevendo sua saída).

    

Answer 2

Como o fluxo STDOUT é bloqueado em buffer por padrão (quando não vai para o terminal) por python , você precisa deixar o fluxo sem buffer (ou buffer de linha).

python fornece uma maneira de deixar os streams sem buffer, aqui está a maneira Pythonic:

python -u foo.py

Assim, toda a sua linha de comando se torna:

python -u foo.py | ~/timestamp.sh >> ~/logs/foo.log

De man python :

-u     Force stdin, stdout and stderr to be totally unbuffered

Agora estou ciente do seu script, mas dentro do script você pode liberar um determinado fluxo usando sys module:

sys.stdout.flush()