Depois de pressionar os botões do teclado nos últimos 20 minutos, como se ele estivesse digitando sua vida, ghostinushanka se vira para mim com um olhar meio louco nos olhos e um sorriso malicioso: “Cara, acho que entendi.
Veja isso ”- enquanto ele aponta para um dos personagens na tela -“ Aposto meu chapéu vermelho que se adicionarmos o que acabei de enviar para você aqui ”- como ele aponta para outro lugar no código -“ haverá não há mais erro. ”
Ligeiramente confuso e cansado, modifico a expressão sed que estamos descobrindo há algum tempo, salve o arquivo e execute o systemctl varnish reload . Mensagem de erro desaparecida ...
“Os e-mails que eu troquei com o candidato”, continua meu colega, enquanto seu sorriso muda para um sorriso amplo e genuíno, “De repente me ocorreu que esse é exatamente o mesmo problema!”
Como tudo começou
Este artigo pressupõe alguma familiaridade com bash, awk e systemd. Algum conhecimento de verniz é benéfico, mas não obrigatório.
Os carimbos de data e hora nos exemplos de snippets foram editados.
Co-autoria com ghostinushanka .
O sol brilha através das janelas do tamanho da parede em mais uma manhã quente de outono, uma xícara de líquido com cafeína recém-preparado fica ao lado do teclado, fones de ouvido vocalizam a amada sinfonia de sons cobrindo o farfalhar dos teclados mecânicos e a primeira entrada na lista de pendências no quadro Kanban exibe divertidamente o título do bilhete fatídico “Investigar vernizreload sh: echo: I/O error na preparação”. Quando se trata de verniz, não há espaço para erros, mesmo que esse em particular não pareça estar causando problemas reais.
Para aqueles que não estão familiarizados com o varnishreload , é simplesmente um script de shell usado para recarregar a configuração - também chamada de VCL - do servidor de cache do Varnish .
Como o título do tíquete sugere, o erro foi encontrado em uma das máquinas de preparo e eu tinha certeza de que o roteamento Varnish funciona no ambiente de preparo, então minha suposição foi que esse deve ser um problema menor. Apenas uma mensagem de saída amigável ao usuário gravada em um fluxo fechado. Pego o ingresso, acreditando firmemente que vou conseguir resolvê-lo em menos de 30 minutos, dou um tapinha nas costas por limpar outra tarefa mundana e voltar a coisas mais importantes.
Bater na parede a 200 km / h
Abrindo o arquivo varnishreload em um dos servidores afetados em execução no Debian Stretch, encontro um script de shell com menos de 200 linhas. Lendo brevemente, não vejo nada perigoso que me impeça de executar o script do terminal repetidamente. Afinal, isso é encenação, mesmo que quebre, ninguém vai reclamar, bem ... não é demais. Eu corro o script e observo, apenas para descobrir que não há erros a serem vistos. Mais algumas execuções repetidas para garantir razoavelmente que não posso reproduzir o erro sem nenhum esforço extra e começo a planejar planos de ajustar e distorcer o ambiente do script. Fechar STDOUT para o script completamente (com > &- ) ajuda alguma coisa? Ou stderr? Nem fez.
Obviamente, systemd manipula o ambiente de alguma forma, mas como e ... por quê? Eu varnishreload o vim e edito a varnishreload de varnishreload do sistema, adicionando set -x logo abaixo do shebang, esperando que a saída detalhada da execução do script varnishreload alguma luz.
O arquivo está corrigido, então recarrego o verniz, apenas para ver que a alteração quebrou completamente o script ... A saída é uma bagunça completa exibindo toneladas de código no estilo C e o buffer de rolagem padrão não é suficiente para descobrir de onde vem. Eu me sinto confusa. A configuração da opção de depuração para o shell script poderia interromper o programa que chama? Não, não pode ser. Um bug no shell? Vários cenários possíveis rodando descontroladamente em diferentes direções em minha mente. Um copo de bebida com cafeína é instantaneamente finalizado, viagem rápida à cozinha para reabastecimento e aqui vamos nós novamente. Abro o arquivo e olho atentamente para o shebang: #!/bin/sh .
Mas /bin/sh é certamente apenas um link simbólico para bash, de modo que o script seja interpretado no modo compatível com POSIX, certo? Errado! O shell não interativo padrão no Debian é o dash, e é exatamente para isso que o /bin/sh aponta .
Se apenas para depuração, alterei o shebang para #!/bin/bash , removi o set -x e tentei novamente. Finalmente, uma saída de erro razoável do próximo recarregamento de verniz:
Jan 01 12:00:00 hostname varnishreload[32604]: /usr/sbin/varnishreload: line 124: echo: write error: Broken pipe Jan 01 12:00:00 hostname varnishreload[32604]: VCL 'reload_20190101_120000_32604' compiled
Linha 124, agora estamos conversando!
114 find_vcl_file() { 115 VCL_SHOW=$(varnishadm vcl.show -v "$VCL_NAME" 2>&1) || : 116 VCL_FILE=$( 117 echo "$VCL_SHOW" | 118 awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}' | { 119
Mas, como se vê, a linha 124 é bem monótona. Só pude supor que o erro foi produzido como parte do comando multilinha em execução na linha 116.
Então, o que o subshell acima produz até para armazenar na variável VCL_FILE ? Na primeira parte, envia o conteúdo da variável VCL_SHOW criada na linha 115 para o tubo. O que acontece então?
Primeiro, ele usa varnishadm , que é uma parte padrão de uma instalação do Varnish usada para configurar o Varnish sem ter que reiniciá-lo. O subcomando vcl.show -v é usado para imprimir toda a configuração da VCL especificada por ${VCL_NAME} para STDOUT.
Para exibir a configuração atual da VCL ativa, bem como várias versões anteriores do roteamento de verniz que ainda estão na memória, você pode usar outro comando varnishadm vcl.list , cuja saída seria semelhante à abaixo:
discarded cold/busy 1 reload_20190101_120000_11903 discarded cold/busy 2 reload_20190101_120000_12068 discarded cold/busy 16 reload_20190101_120000_12259 discarded cold/busy 16 reload_20190101_120000_12299 discarded cold/busy 28 reload_20190101_120000_12357 active auto/warm 32 reload_20190101_120000_12397 available auto/warm 0 reload_20190101_120000_12587
A variável ${VCL_NAME} é configurada em outro lugar no script varnishreload para o nome da VCL atualmente ativa, se houver. Nesse caso, isso seria "reload_20190101_120000_12397".
Ótimo, então ${VCL_SHOW} agora contém uma configuração completa para o Varnish, fácil o suficiente até o momento. Agora finalmente entendi por que a saída do traço com o set -x parecia estar tão quebrada - incluía o conteúdo da configuração resultante do verniz.
O importante aqui é que a configuração completa da VCL geralmente pode ser unida a partir de vários arquivos. Comentários no estilo C são usados para delinear onde os arquivos de configuração foram incluídos em outros arquivos de configuração, que é exatamente o que é a próxima linha do trecho de código.
A sintaxe dos comentários que denotam arquivos tem o seguinte formato
Os números não são importantes aqui, o que nos interessa é o nome do arquivo.
Então, o que está acontecendo no mundo dos comandos que começam na linha 116?
Vamos separá-lo.
Existem quatro partes no comando:
- Um
echo simples que imprime o valor de ${VCL_SHOW}
echo "$VCL_SHOW"
awk que procura uma linha (registro) em que o primeiro campo é '//' e o segundo é "VCL.SHOW".
O Awk é instruído a imprimir a primeira linha correspondente a esses padrões e parar imediatamente o processamento.
awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'
- Um bloco de código que lê nos campos delimitados por espaço em branco em cinco variáveis. A quinta variável FILE obtém o restante da linha. Finalmente, um último eco imprime o conteúdo da variável
${FILE} .
{ read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }.
- Como as etapas de 1 a 3 são encerradas em um subshell, a saída de
$FILE terminará na variável VCL_FILE .
Como o comentário na linha 119 sugere, essa maneira de fazer as coisas serve a um único propósito: tratar de maneira confiável o caso em que a VCL faria referência a nomes de arquivos com espaços.
Comentei a lógica de processamento original do ${VCL_FILE} e tentei ajustar a cadeia de comandos, mas sem um objetivo razoável. Tudo funcionou no meu shell, mas nunca quando executado como um serviço.
Parece que o erro não é de todo replicável quando executado por mim - enquanto isso, os estimados 30 minutos passaram seis vezes e uma nova tarefa de alta prioridade deixou tudo de lado. O resto da semana foi bastante cheio de tarefas diferentes, as duas exceções sendo uma conversa interna que nossa equipe teve sobre o uso de sed e uma entrevista com um candidato promissor. O problema com o desaparecimento do erro de varnishreload foi completamente perdido nas areias do tempo.
Seu chamado sed-fu ... é realmente ... bastante patético
Um dos dias da semana que se seguiu foi bastante gratuito, então peguei a tarefa novamente. Eu esperava que talvez algum processo em segundo plano em meu cérebro ainda estivesse destruindo o problema e eu finalmente fosse capaz de resolvê-lo.
Como dobrar o código da última vez não ajudou, optei por reescrever a linha 116. De qualquer maneira, o código existente era insano. Não há absolutamente nenhuma necessidade de usar a read aqui.
Olhando para o erro novamente:
sh: echo: broken pipe - echo está em dois lugares nesse comando, mas suspeito que o primeiro seja um culpado mais provável (ou cúmplice). Awk também não inspira confiança. Bem, caso seja realmente o awk | {read; echo} awk | {read; echo} awk | {read; echo} causando todo esse problema, por que não usar outra coisa? O Awk não está realmente acostumado a todas as suas capacidades nessa linha e existe esse excedente de read .
Como tivemos uma conversa interna sobre sed na outra semana, eu queria experimentar minhas habilidades recém-adquiridas e otimizar o echo | awk | { read; echo } echo | awk | { read; echo } echo | awk | { read; echo } em um echo | sed mais simples echo | sed echo | sed . Embora essa não seja definitivamente a maneira correta de abordar a depuração, pensei em pelo menos experimentar meu sed-fu e talvez aprender algo novo sobre o problema no processo. No processo, pedi ao meu colega - o autor da conversa sed - que me ajudasse a criar um comando sed mais eficiente.
varnishadm vcl.show -v "$VCL_NAME" o varnishadm vcl.show -v "$VCL_NAME" em um arquivo, para que eu pudesse me concentrar em escrever sed sem todas as dificuldades em recarregar os serviços.
Um pequeno resumo sobre como exatamente a entrada dos processos sed pode ser encontrada em seu manual GNU . Nas fontes sed, o caractere \n é explicitamente especificado como o separador de linhas.
Após várias iterações e contribuições do meu colega, criamos uma expressão sed que produziu exatamente o mesmo resultado que a linha original 116.
Vamos criar um arquivo de entrada de amostra aqui,
> cat vcl-example.vcl Text // VCL.SHOW 0 1578 file with 3 spaces.vcl More text // VCL.SHOW 0 1578 file.vcl Even more text // VCL.SHOW 0 1578 file with TWOspaces.vcl Final text
Pode não ser aparente na descrição acima, mas estamos interessados apenas no primeiro comentário // VCL.SHOW , e pode haver vários na entrada. É exatamente por isso que o awk sai após a primeira partida.
Portanto, o conteúdo do script varnishreload ficaria assim:
VCL_FILE="$(echo "$VCL_SHOW" | sed -En '\#// VCL.SHOW#{s#.*[0-9]+ [0-9]+ (.*)$#\1#p;q;};')"
A lógica acima pode ser expressa de forma sucinta por:
se uma linha corresponder ao regex // VCL.SHOW , corresponda avidamente ao texto, incluindo os dois números nessa linha, e capture o que vier depois. Emita a captura e saia.
Simples, não é?
Ficamos felizes com o script sed e com o fato de que o código original ele substitui, todas as execuções de teste que eu produzi produziram os resultados desejados, por isso modifiquei o varnishreload no servidor e disparei o systemctl reload varnish novamente. O echo: write error: Broken pipe temido echo: write error: Broken pipe estava sorrindo em nossos rostos. O cursor piscando aguardava uma nova entrada de comando no vazio escuro do terminal ...