Down the Rabbit Hole: A Story of One Varnishreload Error - parte 1

Después de presionar los botones del teclado durante los últimos 20 minutos, como si estuviera escribiendo por su vida, ghostinushanka se vuelve hacia mí con una mirada medio loca en sus ojos y una sonrisa maliciosa, "Amigo, creo que lo entendí.


Mira esto ", mientras señala a uno de los personajes en la pantalla," apuesto a mi sombrero rojo que si agregamos lo que acabo de enviarte aquí ", como señala a otro lugar en el código," habrá ya no hay error ".
Ligeramente perplejo y cansado, modifico la expresión sed que hemos estado descubriendo durante algún tiempo, systemctl varnish reload el archivo y ejecuto la systemctl varnish reload . Mensaje de error desaparecido ...


"Esos correos electrónicos que he intercambiado con el candidato", continúa mi colega, mientras su sonrisa cambia a una amplia y genuina sonrisa, "¡De repente me di cuenta de que este es exactamente el mismo problema!"


Como empezó todo


Este artículo supone cierta familiaridad con bash, awk y systemd. Algunos conocimientos de barniz son beneficiosos, pero no son obligatorios.
Se han redactado marcas de tiempo en fragmentos de ejemplo.
Coautor con ghostinushanka .


El sol brilla a través de las ventanas del tamaño de una pared en otra cálida mañana de otoño, una taza de líquido cafeinado recién preparado se sienta al costado del teclado, los auriculares vocalizan la amada sinfonía de sonidos que cubren el susurro de los teclados mecánicos y la primera entrada en el registro de pedidos. en el tablero kanban muestra juguetonamente el título del boleto fatídico "Investigar varnishreload sh: echo: I/O error en la puesta en escena". Siempre que se trate de Varnish, no hay espacio para errores, a pesar de que este en particular no parece estar causando ningún problema real.


Para aquellos de ustedes que no están familiarizados con varnishreload , es simplemente un script de shell utilizado para recargar la configuración, también llamada VCL, del servidor de almacenamiento en caché de Varnish .


Como sugiere el título del ticket, se ha encontrado el error en una de las máquinas de preparación y estaba bastante seguro de que el enrutamiento de Barniz funciona en el entorno de preparación, por lo que supongo que esto debe ser un problema menor. Solo un mensaje de salida fácil de usar escrito en una secuencia cerrada. Agarro el boleto, creyendo firmemente que podré marcarlo resuelto en menos de 30 minutos, darme palmaditas en la espalda por despejar otra tarea mundana y volver a las cosas más importantes.


Golpear la pared a 200 km / h


Al abrir el archivo varnishreload en uno de los servidores afectados que se ejecutan en Debian Stretch, encuentro un script de shell de menos de 200 líneas de largo. Al leerlo brevemente, no veo nada peligroso que me impida ejecutar el script desde la terminal una y otra vez. Después de todo, esto es una puesta en escena, incluso si se rompe, nadie se va a quejar, bueno ... eso no es demasiado. Ejecuto el script y observo, solo para descubrir que no hay errores para ver. Un par de ejecuciones más repetidas para asegurarme razonablemente de que no puedo reproducir el error sin ningún esfuerzo adicional y empiezo a diseñar planes para modificar y doblar el entorno del script. ¿El cierre de STDOUT para el script por completo (con > &- ) ayuda algo? O stderr? Tampoco lo hizo.


Obviamente systemd destruye el medio ambiente de alguna manera, pero ¿cómo y por qué? varnishreload vim y edito la varnishreload de varnishreload del sistema, agregando set -x justo debajo del shebang, con la esperanza de que la salida detallada de la ejecución del script arroje algo de luz.


El archivo está parcheado, así que vuelvo a cargar el barniz, solo para ver que el cambio había roto completamente el script ... La salida es un desastre completo que muestra toneladas de código de estilo C y el búfer de desplazamiento predeterminado no es suficiente para encontrar de dónde viene. Me siento confundido ¿Podría establecer la opción de depuración para el script de shell romper el programa que llama? No, no puede ser. ¿Un error en el caparazón? Múltiples escenarios posibles corriendo salvajemente en diferentes direcciones en mi mente. Una taza de bebida con cafeína se termina instantáneamente, un viaje rápido a la cocina para una recarga y aquí vamos de nuevo. Abro el archivo y miro detenidamente el shebang: #!/bin/sh .


Pero /bin/sh seguramente es solo un enlace simbólico a bash, por lo que el script se interpreta en modo compatible con POSIX, ¿verdad? Mal! El shell no interactivo predeterminado en Debian es dash, y eso es exactamente lo que apunta /bin/sh .


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

Aunque solo fuera para depurar, cambié el shebang a #!/bin/bash , eliminé el set -x e intenté nuevamente. Finalmente, una salida de error razonable de la próxima recarga de barniz:


 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 

¡Línea 124, ahora estamos hablando!


 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 resulta que la línea 124 es bastante tranquila. Solo pude conjeturar que el error se produjo como parte del comando multilínea que se ejecuta en la línea 116.


Entonces, ¿qué produce la subshell anterior incluso para almacenar en la variable VCL_FILE ? En la primera parte, envía el contenido de la variable VCL_SHOW creada en la línea 115 a la tubería. ¿Qué pasa allí, entonces?


Primero, usa varnishadm , que es una parte estándar de una instalación de Varnish utilizada para configurar Varnish sin tener que reiniciarlo. El subcomando vcl.show -v se usa para imprimir toda la configuración de VCL especificada por ${VCL_NAME} en STDOUT.


Para mostrar la configuración VCL activa actual, así como varias versiones anteriores del enrutamiento de barniz que todavía están en la memoria, puede usar otro comando varnishadm vcl.list , cuyo resultado sería similar al siguiente:


 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 

La variable ${VCL_NAME} se establece en otra parte del script varnishreload con el nombre del VCL actualmente activo, si lo hay. En este caso, eso sería "reload_20190101_120000_12397".


Genial, por lo que ${VCL_SHOW} ahora contiene una configuración completa para Varnish, hasta ahora bastante fácil. Ahora finalmente entendí por qué la salida del guión con set -x parecía estar tan rota: incluía el contenido de la configuración de barniz resultante.


Lo importante aquí es que la configuración completa de VCL a menudo se puede unir a partir de múltiples archivos. Los comentarios de estilo C se usan para delinear dónde se incluyeron los archivos de configuración en otros archivos de configuración, que es exactamente de lo que se trata la siguiente línea del fragmento de código.


La sintaxis de los comentarios que denotan archivos tiene el siguiente formato


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

Los números no son importantes aquí, lo que nos interesa es el nombre del archivo.


Entonces, ¿qué está pasando en el mundo en la gran cantidad de comandos que comienzan en la línea 116?
Vamos a separarlo.
El comando tiene cuatro partes:


  1. Un echo simple que imprime el valor de ${VCL_SHOW}
     echo "$VCL_SHOW" 
  2. awk que busca una línea (registro) donde el primer campo es '//' y el segundo es "VCL.SHOW".
    Awk tiene instrucciones de imprimir la primera línea que coincida con estos patrones y luego detener inmediatamente el procesamiento.
     awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}' 
  3. Un bloque de código que se lee en los campos delimitados por espacios en blanco en cinco variables. La quinta variable ARCHIVO obtiene el resto de la línea. Finalmente, un último eco imprime el contenido de la variable ${FILE} .
     { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }. 
  4. Como los pasos del 1 al 3 están encerrados en una subshell, la salida de $FILE terminará en la variable VCL_FILE .

Como sugiere el comentario en la línea 119, esta forma de hacer las cosas tiene un único propósito: manejar de manera confiable el caso donde VCL estaría haciendo referencia a nombres de archivos con espacios.


${VCL_FILE} la lógica de procesamiento original para ${VCL_FILE} e intenté ajustar la cadena de comandos, pero sin un final razonable. Todo funcionó en mi shell, pero nunca cuando se ejecuta como un servicio.


Parece que el error no es replicable cuando lo ejecuto yo, mientras que los 30 minutos estimados pasaron seis veces y una nueva tarea de alta prioridad dejó todo a un lado. El resto de la semana estuvo bastante lleno de tareas diferentes, las dos excepciones fueron una charla interna que nuestro equipo tuvo sobre el uso de sed y una entrevista con un candidato prometedor. El problema de hacer desaparecer el error de varnishreload se perdió por completo en las arenas del tiempo.


Tu llamado sed-fu ... es realmente ... bastante patético


Uno de los días de la semana que siguió fue bastante libre, así que retomé la tarea nuevamente. Tenía la esperanza de que tal vez algún proceso de fondo en mi cerebro todavía estaba eliminando el problema y finalmente podría resolverlo.


Dado que doblar el código la última vez no ayudó, simplemente opté por una reescritura de la línea 116. De todos modos, el código existente era una locura. No hay absolutamente ninguna necesidad de usar read aquí.


Mirando el error nuevamente:
sh: echo: broken pipe : echo está en dos lugares en ese comando, pero sospecho que el primero es un culpable más probable (o un cómplice). Awk tampoco inspira confianza. Bueno, en caso de que realmente sea el awk | {read; echo} awk | {read; echo} awk | {read; echo} construir causando todos estos problemas, ¿por qué no usar otra cosa? Awk no está realmente acostumbrado a todas sus capacidades en esa línea y luego está esta read excedente.


Como tuvimos una charla interna sobre sed la otra semana, quise probar mis habilidades recién adquiridas y optimizar el echo | awk | { read; echo } echo | awk | { read; echo } echo | awk | { read; echo } en un echo | sed más simple echo | sed echo | sed . Aunque definitivamente esa no es la forma correcta de abordar la depuración, pensé que al menos probaría mi sed-fu y tal vez aprendería algo nuevo sobre el problema en el proceso. En el proceso, le pedí a mi colega, el autor de la charla sed, que me ayudara a encontrar un comando sed más eficiente.


He descargado el varnishadm vcl.show -v "$VCL_NAME" en un archivo, por lo que podría concentrarme en escribir sed sin la molestia de recargar el servicio.


Una breve introducción sobre cómo exactamente la información de los procesos sed se puede encontrar en su manual GNU . En las fuentes sed, el carácter \n se especifica explícitamente como el separador de línea.


Después de varias iteraciones y aportes de mi colega, hemos creado una expresión sed que produjo exactamente el mismo resultado que la línea original 116.


Creemos un archivo de entrada de muestra aquí,


 > 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 

Puede que no sea aparente a partir de la descripción anterior, pero solo estamos interesados ​​en el primer comentario // VCL.SHOW , y puede haber varios en la entrada. Eso es exactamente por qué awk se retira después del primer partido.


 # step 1, capture just the comment lines # using sed capability to specify delimiter character with '\#' instead of the commonly used '/' so there is no need to escape slashes themselves # and the “address” capability defined as regex “// VCL.SHOW” to search for lines with specific pattern # -n flag makes sure that the sed does not print all as it does by default (see above link) # -E switches to the extended regex > 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 # step 2, only print out the file name # using the “substitute” command with regex capture groups to print just that group # and this is done only for the matches of the previous search > 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 # step 3, make sure to only get the first result # same as with the awk before, add an immediate exit after the first processed match is printed > 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 # step 4, wrap it up into a one-liner using the colon to separate commands > sed -En -e '\#// VCL.SHOW#{s#.* [0-9]+ [0-9]+ (.*)$#\1#p;q;}' vcl-example.vcl file with 3 spaces.vcl 

Entonces, el contenido de la secuencia de comandos varnishreload se vería así:


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

La lógica anterior se puede expresar sucintamente por:
si una línea coincide con la expresión regular // VCL.SHOW , entonces con avidez coincida con el texto incluyendo los dos números en esa línea y capture lo que venga después. Emitir la captura y salir.


Simple, ¿no es así?


Estábamos contentos con el script sed y el hecho de que el código original reemplaza, todas las ejecuciones de prueba que he realizado produjeron los resultados deseados, por lo que modifiqué la varnishreload de varnishreload en el servidor y systemctl reload varnish una vez más. El echo: write error: Broken pipe temido echo: write error: Broken pipe estaba sonriendo en nuestras caras. El cursor parpadeante esperaba una nueva entrada de comando en el oscuro vacío del terminal ...

Source: https://habr.com/ru/post/475698/


All Articles