piping strings mais longas para tr causa travamento e pico da CPU

1

MacOS Yosemite (10.10.5). Eu sei que esta é a seção Unix / Linux ... mas imagine que essa questão provavelmente se encaixa melhor aqui do que na terra do MacOS.

Meu terminal começou a travar na inicialização antes de mostrar um prompt ... e o uso da CPU aumentou ao mesmo tempo. Eu posso CTRL-C e, em seguida, obter um prompt (presumivelmente sair alguns pendurado / executando .bashrc / .profile / etc).

Eu descobri rapidamente que certas linhas na minha .bashrc estavam causando problemas. Isso é novo (ou seja, eu não mudei nada no meu .bashrc e tudo funcionou bem), então algo mudou no sistema.

Parece que o uso de strings mais longas resultará no pico de travamento / CPU.

Eu posso reproduzir isso canalizando uma string para tr -d '\n' e vendo se ela trava.

macattack:~ $ openssl rand -base64 93  | tr -d '\n'
eDsz4JqFX/HAVjplNI6WDWwPRp9l9snp6UKp/pLn+GbBvJx0+ZMvSJFS/SuCwjMRRXVXfUvBdkaH1R0UgCr2UOf283MvHVTRusLFEVPcGCIz1t3sFMU/3foRzNWVmattp@macattack:~ $ openssl rand -base64 94 | tr -d '\n'
^C
mattp@macattack:~ $ openssl rand -base64 94 | tr -du '\n'
^C

Parece que 93 caracteres é o número mágico em que tr começa a travar. openssl não está pendurado (ou seja, se eu remover o pipe para tr tudo sai). No entanto, a minha linha original do problema era de comprimento diferente.

mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log;' | tr -d '\n'
^C-bash: echo: write error: Interrupted system call

mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log' | tr -d '\n'

mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log' | wc -c
     128
mattp@macattack:~ $

Este é provavelmente um problema de pipe em vez de um problema de tr . Eu posso reproduzir o mesmo problema com sed (comando não faz sentido ... apenas ilustra pendurar).

mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log;'  | sed 's/\n/ /g'
^C-bash: echo: write error: Interrupted system call

mattp@macattack:~ $ echo 'echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log'  | sed 's/\n/ /g'
echo -e "$TS\t${TERM_SESSION_ID}\t$(pwd)\t$(history 1 | cut -c 8-)\n" >> $HOME/.history/history-$(date "+%Y-%m-%d")-${USER}.log
mattp@macattack:~

Eu fiquei sem ideias para solucionar isso.
Os comandos suspensos funcionam bem em um servidor centos linux aleatório. Os comandos rodaram bem em macos até recentemente. Eu nunca encontrei um cachimbo antes. Eu pensei que talvez fosse estranho caracteres na entrada causando um problema ... mas a string aleatória openssl mostra o contrário. Os ulimits são os mesmos que em outro mac que NÃO tem esse mesmo problema.

mattp@macattack:~ $ ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
file size               (blocks, -f) unlimited
max locked memory       (kbytes, -l) unlimited
max memory size         (kbytes, -m) unlimited
open files                      (-n) 7168
pipe size            (512 bytes, -p) 1
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 709
virtual memory          (kbytes, -v) unlimited

Usando dtruss on tr , ele parece travar na chamada read_nocancel.

Atualizar

Fazendo progresso. Encontrou um comentário sobre os tamanhos de buffer de suspensão e tubulação. Roubou um script de teste aqui: Qual é o tamanho do buffer de tubos?

A execução enquanto o problema está acontecendo mostra um buffer de tubulação de 128 bytes. Reinicialize (o problema desaparece temporariamente) e o buffer do pipe é de 65536 bytes. Veja a saída de teste abaixo.

Então, agora a questão é: por que / como é "algo" reduzindo o tamanho do buffer do pipe no sistema.

Com problema

$ /bin/bash -c 'for p in {0..18}; do pipe-buffer-test.sh $((2 ** $p)) 0.5; done'
write size:          1; bytes successfully before error: 128
write size:          2; bytes successfully before error: 128
write size:          4; bytes successfully before error: 128
write size:          8; bytes successfully before error: 128
write size:         16; bytes successfully before error: 128
write size:         32; bytes successfully before error: 128
write size:         64; bytes successfully before error: 128
write size:        128; bytes successfully before error: 128
write size:        256; bytes successfully before error: 0
write size:        512; bytes successfully before error: 0
write size:       1024; bytes successfully before error: 0
write size:       2048; bytes successfully before error: 0
write size:       4096; bytes successfully before error: 0
write size:       8192; bytes successfully before error: 0
write size:      16384; bytes successfully before error: 0
write size:      32768; bytes successfully before error: 0
write size:      65536; bytes successfully before error: 0
write size:     131072; bytes successfully before error: 0
write size:     262144; bytes successfully before error: 0

Após a reinicialização (o problema desapareceu temporariamente)

$ /bin/bash -c 'for p in {0..18}; do pipe-buffer-test.sh $((2 ** $p)) 0.5; done'
write size:          1; bytes successfully before error: 65536
write size:          2; bytes successfully before error: 65536
write size:          4; bytes successfully before error: 65536
write size:          8; bytes successfully before error: 65536
write size:         16; bytes successfully before error: 65536
write size:         32; bytes successfully before error: 65536
write size:         64; bytes successfully before error: 65536
write size:        128; bytes successfully before error: 65536
write size:        256; bytes successfully before error: 65536
write size:        512; bytes successfully before error: 65536
write size:       1024; bytes successfully before error: 65536
write size:       2048; bytes successfully before error: 65536
write size:       4096; bytes successfully before error: 65536
write size:       8192; bytes successfully before error: 65536
write size:      16384; bytes successfully before error: 65536
write size:      32768; bytes successfully before error: 65536
write size:      65536; bytes successfully before error: 65536
write size:     131072; bytes successfully before error: 0
write size:     262144; bytes successfully before error: 0
    
por mattpr 22.05.2017 / 13:16

1 resposta

0

Com base no comentário do @ Barmar sobre o vazamento de buffers do kernel, dei uma olhada nos kexts atuais que não são do SO. Percebi que havia um relativamente novo em uma instalação recente do BlockBlock ( link ).

O BlockBlock foi desinstalado, reiniciado e o problema não ocorreu novamente. Então BlockBlock foi o culpado neste caso e eu relatei a questão ao autor.

No entanto, isso não é particularmente satisfatório, já que adotei uma abordagem de adivinhação e verificação para descobrir a causa e, para ser honesto, não entendi realmente a causa raiz (em termos do sistema operacional), o que significa que sou nenhum-o-sábio para solucionar esse tipo de problema no futuro.

Se alguém se deparar com isso e puder explicar o que estava acontecendo com mais detalhes e fornecer uma abordagem de solução de problemas, seria uma resposta muito melhor do que "desinstalar o BlockBlock".

    
por 26.05.2017 / 10:20

Tags