Falling Down the Rabbit Hole: A historia dun erro de reinicio de verniz - Parte 1

ghostinushanka, que levaba 20 minutos golpeando os botóns coma se a súa vida dependese diso, vólvese cara a min cunha mirada semisalvaxe nos seus ollos e un sorriso astuto: "Amigo, creo que o entendín".

"Mira aquí", di, sinalando un dos símbolos da pantalla, "Aposto o meu sombreiro vermello a que se engadimos aquí o que che acabo de enviar", sinalando outra sección do código, "o erro xa non será mostrarase".

Un pouco desconcertado e canso, modifico a expresión sed na que estivemos traballando un tempo, gardo o ficheiro e executo systemctl varnish reload. A mensaxe de erro desapareceu...

"Os correos electrónicos que intercambiei co candidato", continuou o meu colega, mentres o seu sorriso converteuse nun auténtico sorriso de alegría, "De súpeto entendín que este é exactamente o mesmo problema!"

Como comezou todo

O artigo supón unha comprensión de como funcionan bash, awk, sed e systemd. O coñecemento de verniz é preferible, pero non obrigatorio.
Modificáronse as marcas de tempo dos fragmentos.
Escrito con ghostinushanka.
Este texto é unha tradución do orixinal publicado en inglés hai dúas semanas; tradución boikoden.

O sol brilla polas fiestras panorámicas noutra mañá cálida de outono, unha cunca de bebida rica en cafeína recén preparada descansa lonxe do teclado, a túa sinfonía de sons favorita soa nos teus auriculares, afogando o ruído dos teclados mecánicos e a primeira entrada. na lista de tickets atrasados ​​no taboleiro de Kanban brilla de xeito lúdico co fatídico título "Investigue varnishreload" sh: echo: I/O error in staging" (Investigue "varnishreload sh: echo: I/O error" na posta en escena). No que se refire ao verniz, hai e non pode haber lugar para erros, aínda que non supoñan problemas como neste caso.

Para os que non estean familiarizados carga de verniz, este é un script de shell sinxelo usado para recargar a configuración verniz - tamén chamado VCL.

Como suxire o título do ticket, o erro ocorreu nun dos servidores do escenario e, como estaba seguro de que o enrutamento do verniz no escenario funcionaba correctamente, supuxín que se trataría dun erro menor. Entón, só unha mensaxe que acabou nun fluxo de saída xa pechado. Tomo o billete para min, coa plena confianza de que o marcarei listo en menos de 30 minutos, dámeme palmaditas nas costas para limpar o taboleiro doutro lixo e volver a asuntos máis importantes.

Chocar contra un muro a 200 km/h

Abrindo o ficheiro varnishreload, nun dos servidores que executaban Debian Stretch, vin un script de shell de menos de 200 liñas.

Despois de revisar o script, non notei nada que puidese producir problemas ao executalo varias veces directamente desde o terminal.

A fin de contas, esta é unha etapa, aínda que rompa, ninguén se queixará, bueno... non demasiado. Execute o script e vexo o que se escribirá no terminal, pero os erros xa non son visibles.

Un par de carreiras máis para asegurarme de que non podo reproducir o erro sen ningún esforzo adicional, e estou comezando a descubrir como cambiar este script e facer que aínda se produza un erro.

O script pode anular STDOUT (usando > &-)? Ou STDERR? Ningunha das dúas funcionou ao final.

Ao parecer, systemd modifica dalgún xeito o ambiente de inicio, pero como e por que?
Abro vim e edito varnishreload, engadindo set -x xusto debaixo do shebang, esperando que a saída de depuración do script arroxa algo de luz.

O ficheiro está corrixido, así que recargo o verniz e vexo que o cambio rompeu todo por completo... O escape é unha desorde completa, na que hai toneladas de código tipo C. Mesmo desprazarse polo terminal non é suficiente para atopar onde comeza. Estou completamente confundido. O modo de depuración pode afectar o funcionamento dos programas iniciados nun script? Non, é unha tontería. Erro na cuncha? Varios escenarios posibles corren pola miña cabeza como cascudas en diferentes direccións. A cunca da bebida con cafeína baleira ao instante, unha rápida viaxe á cociña para repoñer o stock e... marchamos. Abro o guión e bótolle unha ollada máis atenta ao shebang: #!/bin/sh.

/bin/sh - esta é só unha ligazón simbólica para bash, polo que o script interprétase en modo compatible con POSIX, non? Non tanto! O shell predeterminado en Debian é dash, e iso é exactamente o que parece. refírese /bin/sh.

# ls -l /bin/sh
lrwxrwxrwx 1 root root 4 Jan 24  2017 /bin/sh -> dash

Como proba, cambiei o shebang a #!/bin/bash, eliminado set -x e intentouno de novo. Finalmente, tras o reinicio posterior do verniz, apareceu un erro tolerable na saída:

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

Liña 124, aquí está!

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                         # all this ceremony to handle blanks in FILE
120                         read -r DELIM VCL_SHOW INDEX SIZE FILE
121                         echo "$FILE"
122                 }
123         ) || :
124
125         if [ -z "$VCL_FILE" ]
126         then
127                 echo "$VCL_SHOW" >&2
128                 fail "failed to get the VCL file name"
129         fi
130
131         echo "$VCL_FILE"
132 }

Pero como se ve, a liña 124 está bastante baleira e sen interese. Só podería supoñer que o erro ocorreu como parte dunha cadea de varias liñas que comeza na liña 116.
Que se escribe finalmente na variable? VCL_FILE como resultado da execución do subshell anterior?

Ao principio, envía o contido da variable VLC_SHOW, creado na liña 115, seguindo o comando a través do tubo. E entón que pasa alí?

En primeiro lugar, úsase alí varnishadm, que forma parte do paquete de instalación de verniz, para configurar o verniz sen reiniciar.

Sub-equipo vcl.show -v usado para emitir toda a configuración VCL especificada en ${VCL_NAME}, a STDOUT.

Para mostrar a configuración activa actual de VCL, así como varias versións anteriores das configuracións de enrutamento de verniz que aínda están na memoria, pode usar o comando varnishadm vcl.list, cuxa saída será similar á seguinte:

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

Valor variable ${VCL_NAME} está instalado noutra parte do script varnishreload ao nome da VCL activa actualmente, se a hai. Neste caso será “reload_20190101_120000_12397”.

Genial, variable ${VCL_SHOW} contén a configuración completa para o verniz, claro por agora. Agora finalmente entendo por que é a saída do guión set -x resultou estar tan roto: incluía o contido da configuración resultante.

É importante entender que unha configuración completa de VCL a miúdo pódese combinar a partir de varios ficheiros. Os comentarios de estilo C utilízanse para identificar onde se incluíron determinados ficheiros de configuración noutros, e iso é o que trata a seguinte liña de fragmento de código.
A sintaxe dos comentarios que describen os ficheiros incluídos ten o seguinte formato:

// VCL.SHOW <NUM> <NUM> <FILENAME>

Os números non son importantes neste contexto, interésanos o nome do ficheiro.

Que pasa finalmente no pantano de comandos que comezan na liña 116?
A ver.
O equipo consta de catro partes:

1. Simple echo, que imprime o valor da variable ${VCL_SHOW}

   echo "$VCL_SHOW"

2. awk, que busca unha liña (rexistro) onde o primeiro campo, despois de romper o texto, sexa “//”, e o segundo “VCL.SHOW”.
   Awk escribirá a primeira liña que coincida con estes patróns e despois deixará de procesar inmediatamente.

   awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'

3. Un bloque de código que almacena valores de campo en cinco variables, separadas por espazos. A quinta variable FILE recibe o resto da liña. Finalmente, o último eco escribe o contido da variable ${FILE}.

   { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }

4. Xa que todos os pasos do 1 ao 3 están encerrados nun subshell, dando saída ao valor $FILE escribirase nunha variable VCL_FILE.

Como suxire o comentario da liña 119, isto ten o único propósito de xestionar de forma fiable os casos nos que VCL fará referencia a ficheiros con espazos nos seus nomes.

Comentei a lóxica de procesamento orixinal para ${VCL_FILE} e intentou cambiar a secuencia de comandos, pero non levou a nada. Todo funcionou ben para min, pero cando iniciei o servizo deu un erro.

Parece que o erro simplemente non é reproducible cando se executa o script manualmente, mentres que os supostos 30 minutos xa expiraron seis veces e, ademais, apareceu unha tarefa de maior prioridade, deixando de lado outros asuntos. O resto da semana estivo cheo de diversas tarefas e só se viu lixeiramente diluído por un informe sobre sed e unha entrevista cun candidato. Problema co erro en varnishreload perdeuse irremediablemente nas areas do tempo.

O teu chamado sed-fu... é en realidade... lixo

A semana seguinte tiven un día bastante libre, así que decidín abordar este billete de novo. Esperaba que no meu cerebro, algún proceso de fondo estivera buscando unha solución a este problema durante todo este tempo, e esta vez entendería definitivamente o que estaba a pasar.

Dado que simplemente cambiar o código non axudou a última vez, só decidín reescribilo a partir da liña 116. En calquera caso, o código existente era estúpido. E non hai absolutamente ningunha necesidade de usalo read.

Mirando de novo o erro:
sh: echo: broken pipe — echo aparece en dous lugares neste comando, pero sospeito que o primeiro é o culpable máis probable (ou polo menos un cómplice). Awk tampouco inspira confianza. E no caso de que realmente o sexa awk | {read; echo} o deseño leva a todos estes problemas, por que non substituílo? Este comando dunha liña non usa todas as funcións de awk, nin sequera esta extra read ademáis.

Desde a semana pasada houbo un informe sobre sed, quería probar as miñas habilidades recentemente adquiridas e simplificar echo | awk | { read; echo} nun máis comprensible echo | sed. Aínda que definitivamente non é o mellor enfoque para identificar o erro, pensei que polo menos probaría o meu sed-fu e quizais aprendería algo novo sobre o problema. Durante o camiño, pedinlle ao meu colega, o autor da charla sed, que me axudase a elaborar un guión sed máis eficiente.

Soltei o contido varnishadm vcl.show -v "$VCL_NAME" a un ficheiro, polo que podería centrarme en escribir o script sed sen ningún problema de reinicios do servizo.

Pódese atopar unha breve descrición de exactamente como procesa a entrada de sed o seu manual de GNU. Nas fontes sed o símbolo n especificado explícitamente como separador de liñas.

En varias pasadas e coas recomendacións do meu compañeiro, escribimos un script sed que deu o mesmo resultado que toda a liña orixinal 116.

A continuación móstrase un ficheiro de mostra con datos de entrada:

> 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

Isto pode non ser obvio coa descrición anterior, pero só nos interesa o primeiro comentario // VCL.SHOW, e pode haber varios deles nos datos de entrada. É por iso que o awk orixinal remata despois da primeira partida.

# шаг первый, вывести только строки с комментариями
# используя возможности sed, определяется символ-разделитель с помощью конструкции '#' вместо обычно используемого '/', за счёт этого не придётся экранировать косые в искомом комментарии
# определяется регулярное выражение “// VCL.SHOW”, для поиска строк с определенным шаблоном
# флаг -n позаботится о том, чтобы sed не выводил все входные данные, как он это делает по умолчанию (см. ссылку выше)
# -E позволяет использовать расширенные регулярные выражения
> cat vcl-processor-1.sed
#// VCL.SHOW#p
> sed -En -f vcl-processor-1.sed vcl-example.vcl
// VCL.SHOW 0 1578 file with 3 spaces.vcl
// VCL.SHOW 0 1578 file.vcl
// VCL.SHOW 0 1578 file with TWOspaces.vcl

# шаг второй, вывести только имя файла
# используя команду “substitute”, с группами внутри регулярных выражений, отображается только нужная группa
# и это делается только для совпадений, ранее описанного поиска
> cat vcl-processor-2.sed
#// VCL.SHOW# {
    s#.* [0-9]+ [0-9]+ (.*)$#1#
    p
}
> sed -En -f vcl-processor-2.sed vcl-example.vcl
file with 3 spaces.vcl
file.vcl
file with TWOspaces.vcl

# шаг третий, получить только первый из результатов
# как и в случае с awk, добавляется немедленное завершения после печати первого найденного совпадения
> cat vcl-processor-3.sed
#// VCL.SHOW# {
    s#.* [0-9]+ [0-9]+ (.*)$#1#
    p
    q
}
> sed -En -f vcl-processor-3.sed vcl-example.vcl
file with 3 spaces.vcl

# шаг четвертый, схлопнуть всё в однострочник, используя двоеточия для разделения команд
> sed -En -e '#// VCL.SHOW#{s#.* [0-9]+ [0-9]+ (.*)$#1#p;q;}' vcl-example.vcl
file with 3 spaces.vcl

Entón, o contido do script vernishreload terá un aspecto así:

VCL_FILE="$(echo "$VCL_SHOW" | sed -En '#// VCL.SHOW#{s#.*[0-9]+ [0-9]+ (.*)$#1#p;q;};')"

A lóxica anterior pódese expresar brevemente do seguinte xeito:
Se a cadea coincide cunha expresión regular // VCL.SHOW, despois devora con avidez o texto que inclúe os dous números nesta liña e garda todo o que quede despois desta operación. Emite o valor almacenado e finaliza o programa.

Simple, non?

Estabamos satisfeitos co script sed e co feito de que substituíu todo o código orixinal. Todas as miñas probas deron os resultados desexados, polo que cambiei o "varnishreload" no servidor e executei de novo systemctl reload varnish. Mal erro echo: write error: Broken pipe ría na nosa cara outra vez. O cursor chiscando o ollo estaba esperando a que se introduza un novo comando no baleiro escuro do terminal...

Fonte: www.habr.com