Down the Rabbit Hole: A Story of One varnishreload Error - bagian 1

Setelah menekan tombol keyboard selama 20 menit terakhir, seolah-olah dia sedang mengetik seumur hidupnya, ghostinushanka menoleh padaku dengan tatapan setengah gila di matanya dan senyum licik, “Bung, kurasa aku mengerti.


Lihat ini "- saat ia menunjuk ke salah satu karakter di layar -" Saya bertaruh topi merah saya bahwa jika kita menambahkan apa yang saya baru saja mengirim Anda ke sini "- saat ia menunjuk ke tempat lain dalam kode -" akan ada tidak ada kesalahan lagi. "
Sedikit bingung dan lelah, saya memodifikasi ekspresi sed yang telah kami systemctl varnish reload selama beberapa waktu sekarang, menyimpan file dan menjalankan systemctl varnish reload . Pesan kesalahan hilang ...


"Email-email yang telah kutukar dengan kandidat," kolegaku melanjutkan, ketika senyumnya berubah menjadi senyum lebar dan tulus, "Tiba-tiba aku tersadar bahwa ini adalah masalah yang persis sama!"


Bagaimana semuanya dimulai


Artikel ini mengasumsikan beberapa keakraban dengan bash, awk dan systemd. Pengetahuan Varnish memang bermanfaat, tetapi tidak diperlukan.
Stempel waktu misalnya, cuplikan telah dihapus.
Ditulis bersama dengan ghostinushanka .


Sun bersinar melalui jendela seukuran dinding pada pagi musim gugur yang hangat lagi, secangkir cairan berkafein yang baru diseduh duduk di sisi keyboard, headphone menyuarakan simfoni kesayangan suara yang meliputi desiran keyboard mekanis di sekitarnya dan entri pertama di backlog pada papan kanban dengan main-main menampilkan judul tiket yang ditakdirkan "Selidiki varnishreload sh: echo: I/O error dalam pementasan". Setiap kali Varnish prihatin, tidak ada ruang untuk kesalahan, meskipun yang satu ini tampaknya tidak menyebabkan masalah aktual.


Bagi Anda yang tidak mengenal varnishreload , ini hanyalah skrip shell yang digunakan untuk memuat ulang konfigurasi - juga disebut VCL - dari server caching Varnish .


Seperti judul tiket mengisyaratkan, kesalahan telah ditemukan pada salah satu mesin pementasan dan saya cukup yakin routing Varnish bekerja di lingkungan pementasan, jadi asumsi saya adalah bahwa ini harus menjadi masalah kecil. Hanya pesan keluaran yang ramah pengguna yang ditulis ke aliran tertutup. Saya mengambil tiket, dengan yakin saya akan dapat menandainya diselesaikan dalam waktu kurang dari 30 menit, menepuk punggung saya untuk menyelesaikan tugas duniawi lainnya dan kembali ke hal-hal yang lebih penting.


Memukul tembok dengan kecepatan 200 km / jam


Membuka file varnishreload di salah satu server yang terpengaruh yang berjalan di Debian Stretch, saya menemukan skrip shell kurang dari 200 baris. Secara singkat membacanya, saya melihat tidak ada yang berbahaya yang akan mencegah saya menjalankan skrip dari terminal berulang-ulang. Bagaimanapun, ini adalah pementasan, bahkan jika itu rusak, tidak ada yang akan mengeluh, yah ... tidak terlalu banyak, itu. Saya menjalankan skrip dan mengamati, hanya untuk mengetahui bahwa tidak ada kesalahan yang terlihat. Sepasang lagi berjalan berulang untuk memastikan bahwa saya tidak dapat mereproduksi kesalahan tanpa usaha ekstra dan saya mulai menyusun rencana untuk mengubah dan menekuk lingkungan skrip. Apakah menutup STDOUT untuk skrip sama sekali (dengan > &- ) membantu? Atau stderr? Tidak juga.


Jelas systemd merusak lingkungan dengan cara tertentu, tetapi bagaimana, dan ... mengapa? Saya menjalankan vim dan mengedit varnishreload sistem, menambahkan set -x tepat di bawah shebang, berharap bahwa skrip run output yang rinci akan memberi sedikit cahaya.


File ditambal, jadi saya memuat ulang pernis, hanya untuk melihat bahwa perubahan telah benar-benar merusak skrip ... Output adalah kekacauan lengkap yang menampilkan banyak kode gaya C dan buffer scrollback default tidak cukup untuk menemukan dari mana asalnya. Saya merasa bingung. Bisakah pengaturan opsi debug untuk skrip shell merusak program yang disebutnya? Tidak bisa. Bug di shell? Beberapa skenario yang mungkin berjalan liar ke arah yang berbeda dalam pikiran saya. Secangkir minuman berkafein selesai secara instan, perjalanan cepat ke dapur untuk diisi ulang dan kita mulai lagi. Saya membuka file dan melihat dekat shebang: #!/bin/sh .


Tapi /bin/sh tentu saja hanya sebuah symlink ke bash, sehingga skrip diinterpretasikan dalam mode yang sesuai dengan POSIX, kan? Salah! Shell non-interaktif default pada Debian adalah dash, dan itulah yang ditunjuk /bin/sh .


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

Jika hanya untuk debugging, saya mengubah shebang ke #!/bin/bash , menghapus set -x dan mencoba lagi. Akhirnya, output kesalahan yang wajar dari ulang pernis berikutnya:


 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 

Line 124, sekarang kita bicara!


 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 } 

Tapi ternyata, saluran 124 cukup lancar. Saya hanya bisa menduga bahwa kesalahan itu dihasilkan sebagai bagian dari perintah multiline yang mengeksekusi di baris 116.


Jadi apa yang dihasilkan oleh subkulit di atas untuk disimpan dalam variabel VCL_FILE ? Pada bagian pertama mengirimkan konten variabel VCL_SHOW dibuat pada baris 115 ke dalam pipa. Apa yang terjadi di sana?


Pertama, ia menggunakan varnishadm , yang merupakan bagian standar dari instalasi Varnish yang digunakan untuk mengkonfigurasi Varnish tanpa harus me-restart itu. vcl.show -v digunakan untuk mencetak seluruh konfigurasi VCL yang ditentukan oleh ${VCL_NAME} ke STDOUT.


Untuk menampilkan konfigurasi VCL aktif saat ini serta beberapa versi perutean pernis sebelumnya yang masih ada dalam memori, Anda dapat menggunakan perintah lain varnishadm vcl.list , yang hasilnya akan sama dengan yang di bawah ini:


 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 

Variabel ${VCL_NAME} disetel di tempat lain dalam skrip varnishreload dengan nama VCL yang saat ini aktif, jika ada. Dalam hal ini, itu akan menjadi "reload_20190101_120000_12397".


Hebat, jadi ${VCL_SHOW} sekarang berisi konfigurasi lengkap untuk Varnish, cukup mudah sejauh ini. Sekarang saya akhirnya mengerti mengapa output dasbor dengan set -x tampaknya sangat rusak - itu termasuk isi dari konfigurasi pernis yang dihasilkan.


Yang penting di sini adalah bahwa konfigurasi penuh VCL mungkin sering disatukan dari beberapa file. Komentar gaya-C digunakan untuk menggambarkan di mana file config dimasukkan ke dalam file config lainnya, yang merupakan inti dari potongan kode selanjutnya.


Sintaks komentar yang menunjukkan file memiliki format berikut


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

Angka-angka tidak penting di sini, yang kami minati adalah nama file.


Jadi, apa yang terjadi dalam banyak perintah yang dimulai pada baris 116?
Mari kita memisahkannya.
Ada empat bagian dari perintah:


  1. echo sederhana yang mencetak nilai ${VCL_SHOW}
     echo "$VCL_SHOW" 
  2. awk yang mencari garis (catatan) di mana bidang pertama adalah '//' dan yang kedua adalah "VCL.SHOW".
    Awk diinstruksikan untuk mencetak baris pertama yang cocok dengan pola-pola ini dan kemudian segera berhenti memproses.
     awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}' 
  3. Blok kode yang bertuliskan bidang-bidang yang dibatasi-spasi menjadi lima variabel. Variabel kelima FILE mendapatkan sisa baris. Akhirnya, satu gema terakhir mencetak isi dari variabel ${FILE} .
     { read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }. 
  4. Karena langkah 1 hingga 3 semuanya terbungkus dalam subkulit, output $FILE akan berakhir di variabel VCL_FILE .

Seperti komentar pada baris 119 menyarankan, cara melakukan hal-hal ini melayani satu tujuan: untuk andal menangani kasus di mana VCL akan merujuk nama file dengan spasi.


Saya berkomentar logika pemrosesan asli untuk ${VCL_FILE} dan mencoba untuk mengubah rantai perintah tetapi tidak ada ${VCL_FILE} . Semuanya bekerja di shell saya tetapi tidak pernah dijalankan sebagai layanan.


Tampaknya kesalahan sama sekali tidak dapat ditiru ketika dijalankan oleh saya - sementara itu diperkirakan 30 menit berlalu enam kali dan tugas prioritas tinggi baru mengesampingkan semuanya. Sisa minggu ini cukup penuh dengan tugas yang berbeda, dua pengecualian menjadi pembicaraan internal tim kami tentang penggunaan sed dan wawancara dengan kandidat yang menjanjikan. Masalah dengan membuat kesalahan varnishreload hilang benar-benar hilang ke pasir waktu.


Yang kau sebut sed-fu ... benar-benar ... cukup menyedihkan


Salah satu hari dalam minggu berikutnya cukup bebas, jadi saya mengambil tugas lagi. Saya berharap bahwa mungkin beberapa proses latar belakang di otak saya masih memecah masalah dan akhirnya saya bisa memecahkannya.


Karena menekuk kode terakhir kali tidak membantu, saya hanya memilih untuk menulis ulang baris 116. Kode yang ada sudah gila. Sama sekali tidak perlu menggunakan read sini.


Melihat kesalahan lagi:
sh: echo: broken pipe - echo ada di dua tempat dalam perintah itu, tapi saya curiga yang pertama menjadi pelakunya yang lebih mirip (atau kaki tangan). Awk juga tidak menginspirasi kepercayaan diri. Nah, kalau-kalau itu adalah awk | {read; echo} awk | {read; echo} awk | {read; echo} konstruk yang menyebabkan semua masalah ini, mengapa tidak menggunakan yang lain? Awk tidak benar-benar terbiasa dengan kemampuan penuhnya pada one-liner itu dan kemudian ada kelebihan ini read .


Melihat kami melakukan pembicaraan internal tentang sed minggu lalu, saya ingin mencoba keterampilan yang baru saya peroleh dan mengoptimalkan echo | awk | { read; echo } echo | awk | { read; echo } echo | awk | { read; echo } menjadi echo | sed lebih sederhana echo | sed echo | sed . Walaupun itu jelas bukan cara yang tepat untuk mendekati debugging, saya pikir saya setidaknya akan mencoba sed-fu saya dan mungkin belajar sesuatu yang baru tentang masalah dalam proses. Dalam prosesnya, saya telah meminta kolega saya - penulis sed sed - untuk membantu saya menghasilkan perintah sed yang lebih efisien.


Saya telah membuang varnishadm vcl.show -v "$VCL_NAME" ke dalam file, jadi saya bisa fokus pada penulisan sed tanpa semua kerumitan seputar reload layanan.


Sebuah primer pendek tentang bagaimana tepatnya memproses input dapat ditemukan dalam manual GNU-nya . Dalam sed source karakter \n secara eksplisit ditentukan sebagai pemisah baris.


Setelah beberapa iterasi dan masukan dari kolega saya, kami telah membuat ekspresi sed yang memang menghasilkan hasil yang persis sama dengan garis asli 116.


Mari kita buat file input sampel di sini,


 > 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 

Mungkin tidak terlihat dari uraian di atas, tetapi kami hanya tertarik pada komentar // VCL.SHOW pertama, dan mungkin ada beberapa masukan. Itulah sebabnya awk berhenti setelah pertandingan pertama.


 # 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 

Jadi, isi skrip varnishreload akan terlihat seperti ini:


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

Logika di atas dapat secara ringkas diungkapkan oleh:
jika suatu baris cocok dengan regex // VCL.SHOW , maka dengan rakus mencocokkan teks termasuk dua angka pada baris itu dan menangkap apa pun yang muncul setelahnya. Keluarkan tangkapan dan keluar.


Sederhana bukan?


Kami senang dengan skrip sed dan fakta apa kode asli yang diganti, semua uji coba yang saya lakukan menghasilkan hasil yang diinginkan, jadi saya telah memodifikasi varnishreload di server dan memecat systemctl reload varnish sekali lagi. Kesalahan echo: write error: Broken pipe ditakuti echo: write error: Broken pipe tersenyum di wajah kami. Kursor yang berkedip menunggu entri perintah baru di kekosongan terminal ...

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


All Articles