🥇ตกหลุมกระต่าย: เรื่องราวของข้อผิดพลาดในการรีบูตเครื่องวานิช - ตอนที่ 1

โกสตินูชานกาหลังจากกดปุ่มไป 20 นาทีก่อนหน้านี้ราวกับว่าชีวิตของเขาขึ้นอยู่กับมัน หันมาหาฉันด้วยสีหน้ากึ่งดุร้ายในดวงตาของเขาและยิ้มเจ้าเล่ห์ - "เพื่อน ฉันคิดว่าฉันเข้าใจ"

“ดูนี่สิ” เขาพูด ชี้ไปที่อักขระตัวใดตัวหนึ่งบนหน้าจอ “ฉันพนันได้เลยว่าหมวกสีแดงของฉันถ้าเราเพิ่มสิ่งที่ฉันเพิ่งส่งให้คุณที่นี่” - ชี้ไปที่ส่วนอื่นของรหัส - "ข้อผิดพลาดจะไม่เกิดขึ้นอีกต่อไป มาแสดง”

ฉันงงและเหนื่อยเล็กน้อย ฉันเปลี่ยนคำสั่ง sed ที่เราทำมาระยะหนึ่ง บันทึกไฟล์และเรียกใช้ systemctl varnish reload. ข้อความแสดงข้อผิดพลาดหายไป...

“อีเมลที่ฉันแลกเปลี่ยนกับผู้สมัคร” เพื่อนร่วมงานของฉันพูดต่อ ในขณะที่รอยยิ้มของเขาเปลี่ยนเป็นรอยยิ้มที่จริงใจและเต็มไปด้วยความสุข “ทันใดนั้นฉันก็นึกขึ้นได้ว่านี่เป็นปัญหาเดียวกันทุกประการ!”

มันเริ่มต้นอย่างไร

บทความนี้สันนิษฐานว่าเข้าใจว่า bash, awk, sed และ systemd ทำงานอย่างไร มีความรู้เรื่องการเคลือบเงาเป็นที่ต้องการ แต่ไม่จำเป็น
มีการเปลี่ยนแปลงการประทับเวลาในตัวอย่างข้อมูล
เขียนด้วย โกสตินูชานกา.
ข้อความนี้เป็นการแปลจากต้นฉบับที่เผยแพร่เป็นภาษาอังกฤษเมื่อสองสัปดาห์ก่อน การแปล โบอิโคเด็น.

แสงแดดส่องผ่านหน้าต่างแบบพาโนรามาในเช้าวันใหม่อันอบอุ่นของฤดูใบไม้ร่วง เครื่องดื่มคาเฟอีนที่เพิ่งชงเสร็จหนึ่งถ้วยวางอยู่ข้างคีย์บอร์ด เสียงเพลงซิมโฟนีที่ชื่นชอบบรรเลงผ่านหูฟังเหนือเสียงกรอบแกรบของคีย์บอร์ดเชิงกล และเสียงแรกเริ่มใน รายการตั๋วงานค้างบนกระดานคัมบังเปล่งประกายอย่างสนุกสนานด้วยชื่อที่เป็นเวรเป็นกรรม “ตรวจสอบ varnishreload sh: echo: I/O error in staging” (ตรวจสอบ “varnishreload sh: echo: I/O error” in staging) ในเรื่องของการเคลือบเงา ไม่มีและไม่สามารถผิดพลาดได้ แม้ว่าจะไม่ก่อให้เกิดปัญหาก็ตาม ดังเช่นในกรณีนี้

สำหรับผู้ที่ไม่รู้จัก โหลดวานิชซึ่งเป็นเชลล์สคริปต์อย่างง่ายที่ใช้ในการรีโหลดการกำหนดค่า วานิช - เรียกอีกอย่างว่า VCL

ตามที่ชื่อตั๋วแนะนำ ข้อผิดพลาดเกิดขึ้นที่หนึ่งในเซิร์ฟเวอร์ในสเตจ และเนื่องจากฉันมั่นใจว่าการกำหนดเส้นทางของวานิชในสเตจนั้นทำงานได้อย่างถูกต้อง ฉันจึงสันนิษฐานว่านี่อาจเป็นข้อผิดพลาดเล็กน้อย ดังนั้นเพียงแค่ข้อความที่เข้าสู่สตรีมเอาต์พุตที่ปิดไปแล้ว ฉันรับตั๋วด้วยตัวเองด้วยความมั่นใจเต็มร้อยว่าฉันจะทำเครื่องหมายให้พร้อมภายในเวลาไม่ถึง 30 นาที ตบไหล่ตัวเองเพื่อล้างกระดานของขยะชิ้นต่อไป และกลับไปทำสิ่งที่สำคัญกว่า

พุ่งชนกำแพงด้วยความเร็ว 200 กม./ชม

กำลังเปิดไฟล์ varnishreloadบนหนึ่งในเซิร์ฟเวอร์ที่ใช้ Debian Stretch ฉันเห็นเชลล์สคริปต์ที่มีความยาวน้อยกว่า 200 บรรทัด

ฉันไม่เห็นสิ่งใดที่อาจทำให้เกิดปัญหาเมื่อเรียกใช้สคริปต์โดยตรงจากเทอร์มินัลหลายครั้ง

ท้ายที่สุดนี่คือเวทีแม้ว่ามันจะแตกก็ไม่มีใครบ่น แต่ ... ไม่มากเกินไป ฉันเรียกใช้สคริปต์และดูว่าจะเขียนอะไรไปยังเทอร์มินัล แต่ข้อผิดพลาดจะไม่ปรากฏอีกต่อไป

ทำงานอีกสองสามครั้งเพื่อให้แน่ใจว่าฉันไม่สามารถสร้างข้อผิดพลาดซ้ำได้โดยไม่ต้องใช้ความพยายามพิเศษ และฉันเริ่มหาวิธีเปลี่ยนสคริปต์นี้และทำให้ยังคงแสดงข้อผิดพลาดอยู่

สคริปต์สามารถบล็อก STDOUT (โดยใช้ > &-)? หรือ STDERR? สุดท้ายก็ไม่ได้ผล

เห็นได้ชัดว่า systemd เปลี่ยนสภาพแวดล้อมการทำงานไม่ทางใดก็ทางหนึ่ง แต่อย่างไรและทำไม
ฉันเปิดเสียงเรียกเข้าและแก้ไข varnishreload,เพิ่ม set -x อยู่ใต้ shebang โดยหวังว่าการดีบักผลลัพธ์ของสคริปต์จะทำให้กระจ่างขึ้น

ไฟล์ได้รับการแก้ไขแล้ว ดังนั้นฉันจึงโหลดวานิชใหม่และเห็นว่าการเปลี่ยนแปลงนั้นทำลายทุกอย่างโดยสิ้นเชิง ... ไอเสียนั้นเละเทะไปหมด โดยมีโค้ดคล้าย C อยู่ในนั้นมากมาย แม้แต่การเลื่อนในเทอร์มินัลก็ยังไม่เพียงพอที่จะค้นหาตำแหน่งเริ่มต้น ฉันสับสนไปหมด โหมดแก้ไขข้อบกพร่องสามารถส่งผลกระทบต่อการทำงานของโปรแกรมที่ทำงานในสคริปต์ได้หรือไม่ ไม่พล่าม แมลงในเปลือก? สถานการณ์ที่เป็นไปได้หลายอย่างกำลังบินอยู่ในหัวของฉันเหมือนแมลงสาบในทิศทางต่างๆ เครื่องดื่มที่มีคาเฟอีนเต็มถ้วยหมดลงทันที เดินไปที่ครัวอย่างรวดเร็วเพื่อเติมเสบียง และ... ไปกันเลย ฉันเปิดสคริปต์และดู shebang: #!/bin/sh.

/bin/sh - นี่เป็นเพียง bash symlink ดังนั้นสคริปต์จึงถูกตีความในโหมดที่เข้ากันได้กับ POSIX ใช่ไหม มันไม่ได้อยู่ที่นั่น! เชลล์เริ่มต้นบน Debian คือ dash ซึ่งเป็นสิ่งที่แน่นอน หมายถึง /bin/sh.

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

เพื่อประโยชน์ในการทดลอง ฉันเปลี่ยน shebang เป็น #!/bin/bashลบแล้ว set -x และลองอีกครั้ง ในที่สุดเมื่อโหลดวานิชซ้ำในภายหลังข้อผิดพลาดที่ยอมรับได้ปรากฏขึ้นในผลลัพธ์:

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

สาย 124 นี่แหละ!

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 }

แต่เมื่อปรากฎว่า สาย 124 ค่อนข้างว่างเปล่าและไม่มีความสนใจ ฉันสามารถสันนิษฐานได้ว่าข้อผิดพลาดเกิดขึ้นโดยเป็นส่วนหนึ่งของหลายบรรทัดที่เริ่มต้นที่บรรทัด 116
สิ่งที่เขียนลงในตัวแปร VCL_FILE อันเป็นผลมาจากการดำเนินการ sub-shell ข้างต้น?

ในตอนเริ่มต้นจะส่งเนื้อหาของตัวแปร VLC_SHOWสร้างขึ้นในบรรทัดที่ 115 ไปยังคำสั่งถัดไปผ่านไพพ์ แล้วเกิดอะไรขึ้นที่นั่น?

ประการแรกมันใช้ varnishadmซึ่งเป็นส่วนหนึ่งของแพ็คเกจการติดตั้งวานิช เพื่อกำหนดค่าการเคลือบเงาโดยไม่ต้องรีสตาร์ท

คำสั่งย่อย vcl.show -v ใช้เพื่อส่งออกการกำหนดค่า VCL ทั้งหมดที่ระบุใน ${VCL_NAME}ไปที่ STDOUT

หากต้องการแสดงการกำหนดค่า VCL ที่ใช้งานอยู่ในปัจจุบัน รวมถึงการกำหนดค่าการกำหนดเส้นทางของวานิชเวอร์ชันก่อนหน้าหลายเวอร์ชันที่ยังอยู่ในหน่วยความจำ คุณสามารถใช้คำสั่ง varnishadm vcl.listซึ่งผลลัพธ์ที่ได้จะคล้ายกับต่อไปนี้:

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

ค่าตัวแปร ${VCL_NAME} ตั้งค่าในส่วนอื่นของสคริปต์ varnishreload ไปยังชื่อของ VCL ที่ใช้งานอยู่ในปัจจุบัน ถ้ามี ในกรณีนี้จะเป็น “reload_20190101_120000_12397”

โอเค ตัวแปร ${VCL_SHOW} มีการกำหนดค่าที่สมบูรณ์สำหรับการเคลือบเงาเพื่อให้ชัดเจน ในที่สุดฉันก็เข้าใจว่าทำไม dash ออกด้วย set -x กลายเป็นว่าใช้งานไม่ได้ - มันรวมเนื้อหาของการกำหนดค่าที่เป็นผลลัพธ์

สิ่งสำคัญคือต้องเข้าใจว่าการกำหนดค่า VCL ที่สมบูรณ์มักจะถูกรวมเข้าด้วยกันจากไฟล์หลายไฟล์ ความคิดเห็นในรูปแบบ C ใช้เพื่อกำหนดตำแหน่งที่รวมไฟล์การกำหนดค่าหนึ่งไว้ในอีกไฟล์หนึ่ง และนั่นคือสิ่งที่บรรทัดของข้อมูลโค้ดต่อไปนี้เป็นข้อมูลเกี่ยวกับทั้งหมด
ไวยากรณ์สำหรับความคิดเห็นที่อธิบายถึงไฟล์ที่รวมอยู่มีรูปแบบดังต่อไปนี้:

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

ตัวเลขในบริบทนี้ไม่สำคัญ เราสนใจชื่อไฟล์

แล้วจะเกิดอะไรขึ้นในคำสั่งมากมายที่เริ่มต้นที่บรรทัด 116
ปล่อยให้หน้ามัน
คำสั่งประกอบด้วยสี่ส่วน:

ง่าย echoซึ่งแสดงค่าของตัวแปร ${VCL_SHOW}
```
echo "$VCL_SHOW"
```
awkซึ่งมองหาบรรทัด (บันทึก) โดยที่ฟิลด์แรกหลังจากแยกข้อความแล้วจะเป็น “//” และฟิลด์ที่สองจะเป็น “VCL.SHOW”
Awk จะเขียนบรรทัดแรกที่ตรงกับรูปแบบเหล่านี้แล้วหยุดการประมวลผลทันที
```
awk '$1 == "//" && $2 == "VCL.SHOW" {print; exit}'
```
บล็อกของโค้ดที่เก็บค่าฟิลด์ในตัวแปรห้าตัว โดยคั่นด้วยช่องว่าง FILE ตัวแปรที่ห้ารับส่วนที่เหลือของบรรทัด สุดท้าย เสียงสะท้อนสุดท้ายจะเขียนเนื้อหาของตัวแปร ${FILE}.
```
{ read -r DELIM VCL_SHOW INDEX SIZE FILE; echo "$FILE" }
```
เนื่องจากขั้นตอนที่ 1 ถึง 3 ทั้งหมดอยู่ใน sub-shell เอาต์พุตของค่า $FILE จะถูกเขียนลงในตัวแปร VCL_FILE.

ตามที่ความคิดเห็นในบรรทัดที่ 119 แนะนำไว้ การดำเนินการนี้มีจุดประสงค์เพียงอย่างเดียวในการจัดการกรณีที่น่าเชื่อถือ โดย VCL จะอ้างถึงไฟล์ที่มีอักขระช่องว่างในชื่อ

ฉันได้แสดงความคิดเห็นเกี่ยวกับตรรกะการประมวลผลดั้งเดิมสำหรับ ${VCL_FILE} และพยายามเปลี่ยนลำดับคำสั่ง แต่ก็ไม่เป็นผล ทุกอย่างทำงานได้อย่างสมบูรณ์สำหรับฉัน และในกรณีของการเริ่มต้นบริการ มันทำให้เกิดข้อผิดพลาด

ดูเหมือนว่าข้อผิดพลาดนั้นไม่สามารถทำซ้ำได้เมื่อเรียกใช้สคริปต์ด้วยตนเอง ในขณะที่เวลา 30 นาทีโดยประมาณได้สิ้นสุดลงไปแล้วหกครั้ง และนอกจากนี้ งานที่มีความสำคัญสูงกว่าได้ปรากฏขึ้น ทำให้กรณีที่เหลือถูกมองข้ามไป ส่วนที่เหลือของสัปดาห์เต็มไปด้วยงานที่หลากหลายและเจือจางเพียงเล็กน้อยด้วยการพูดคุยในหัวข้อและการสัมภาษณ์ผู้สมัคร ปัญหาข้อผิดพลาดใน varnishreload สูญหายไปในทรายแห่งกาลเวลาอย่างไม่อาจแก้ไขได้

สิ่งที่คุณเรียกว่า sed-fu... ที่จริง... ขยะ

สัปดาห์ต่อมามีวันว่างพอสมควร ฉันเลยตัดสินใจซื้อตั๋วนี้อีกครั้ง ฉันหวังว่าในสมองของฉัน กระบวนการเบื้องหลังบางอย่างกำลังมองหาวิธีแก้ไขปัญหาอยู่ตลอดเวลา และคราวนี้ฉันจะเข้าใจว่าอะไรผิดปกติ

เนื่องจากครั้งที่แล้วการเปลี่ยนโค้ดไม่ได้ผล ฉันจึงตัดสินใจเขียนใหม่โดยเริ่มจากบรรทัดที่ 116 ไม่ว่าในกรณีใด รหัสที่มีอยู่นั้นงี่เง่า และไม่มีความจำเป็นต้องใช้อย่างแน่นอน read.

ดูข้อผิดพลาดอีกครั้ง:
sh: echo: broken pipe - ในคำสั่งนี้ echo อยู่ในสองที่ แต่ฉันสงสัยว่าอันแรกเป็นผู้ร้ายที่มีโอกาสมากกว่า (หรืออย่างน้อยก็เป็นผู้สมรู้ร่วมคิด) Awk ไม่ได้สร้างความมั่นใจเช่นกัน และในกรณีที่เป็นเช่นนั้นจริงๆ awk | {read; echo} การออกแบบนำไปสู่ปัญหาเหล่านี้ ทำไมไม่เปลี่ยนใหม่ล่ะ คำสั่งบรรทัดเดียวนี้ไม่ได้ใช้คุณสมบัติทั้งหมดของ awk และแม้แต่ส่วนพิเศษนี้ read ในภาคผนวก

เนื่องจากสัปดาห์ที่ผ่านมามีรายงานเรื่อง sedฉันต้องการลองใช้ทักษะที่ได้มาใหม่และทำให้ง่ายขึ้น echo | awk | { read; echo} ให้เข้าใจมากยิ่งขึ้น echo | sed. แม้ว่าวิธีนี้จะไม่ใช่วิธีที่ดีที่สุดในการจับจุดบกพร่อง แต่ฉันคิดว่าอย่างน้อยฉันควรลองใช้ sed-fu และอาจเรียนรู้สิ่งใหม่ๆ เกี่ยวกับปัญหานี้ ระหว่างทาง ฉันขอให้เพื่อนร่วมงานของฉันซึ่งเป็นผู้เขียน sed talk ช่วยฉันคิดสคริปต์ sed ที่มีประสิทธิภาพมากขึ้น

ฉันตกหล่นเนื้อหา varnishadm vcl.show -v "$VCL_NAME" เป็นไฟล์เพื่อให้ฉันสามารถมุ่งเน้นไปที่การเขียนสคริปต์ sed โดยไม่ต้องรีสตาร์ทบริการให้ยุ่งยาก

คำอธิบายสั้น ๆ ของวิธีที่ sed จัดการกับอินพุตสามารถพบได้ใน คู่มือ GNU ของเขา. ในแหล่งที่มา sed สัญลักษณ์ n ระบุอย่างชัดเจนว่าเป็นเส้นคั่น

ในหลายๆ รอบ และด้วยคำแนะนำของเพื่อนร่วมงาน เราได้เขียนสคริปต์ sed ที่ให้ผลลัพธ์เหมือนกับบรรทัดเดิมทั้งหมด 116

ด้านล่างนี้คือไฟล์ตัวอย่างที่มีข้อมูลอินพุต:

> 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

อาจไม่ชัดเจนจากคำอธิบายด้านบน แต่เราสนใจเฉพาะความคิดเห็นแรกเท่านั้น // VCL.SHOWและอาจมีหลายรายการในข้อมูลอินพุต นี่คือสาเหตุที่ awk ดั้งเดิมยุติลงหลังจากนัดแรก

# шаг первый, вывести только строки с комментариями
# используя возможности 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

ดังนั้นเนื้อหาของสคริปต์ varnishreload จะมีลักษณะดังนี้:

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

ตรรกะข้างต้นสรุปได้ดังนี้
หากสตริงตรงกับนิพจน์ทั่วไป // VCL.SHOWจากนั้นกินข้อความที่มีทั้งตัวเลขในบรรทัดนั้นอย่างตะกละตะกราม และบันทึกสิ่งที่เหลืออยู่หลังจากการดำเนินการนี้ ออกค่าที่เก็บไว้และสิ้นสุดโปรแกรม

ง่ายใช่มั้ย

เราพอใจกับสคริปต์ sed และการแทนที่โค้ดเดิมทั้งหมด การทดสอบทั้งหมดของฉันให้ผลลัพธ์ตามที่ต้องการ ดังนั้นฉันจึงเปลี่ยน "การเติมน้ำมันเคลือบเงา" บนเซิร์ฟเวอร์และรันอีกครั้ง systemctl reload varnish. ความผิดพลาดที่สกปรก echo: write error: Broken pipe หัวเราะใส่หน้าเราอีกแล้ว เคอร์เซอร์ขยิบตากำลังรอให้ป้อนคำสั่งใหม่ในส่วนมืดของเทอร์มินัล...

ที่มา: will.com

Falling Down the Rabbit Hole: เรื่องราวของข้อผิดพลาดในการรีบูตเครื่องวานิช - ตอนที่ 1

มันเริ่มต้นอย่างไร

พุ่งชนกำแพงด้วยความเร็ว 200 กม./ชม

สิ่งที่คุณเรียกว่า sed-fu... ที่จริง... ขยะ

เพิ่มความคิดเห็น ยกเลิกการตอบ