Falling Down the Rabbit Hole: הסיפור של שגיאת אתחול מחדש של לכה - חלק 1

גוסטינושנקה, אחרי שחבט על הכפתורים ב-20 הדקות הקודמות כאילו חייו תלויים בזה, פונה אליי עם הבעה חצי פרועה בעיניו וחיוך ערמומי - "אחי, אני חושב שאני מבין".

"תסתכל כאן," הוא אומר, מצביע על אחת הדמויות על המסך, "אני מתערב על הכובע האדום שלי שאם נוסיף לכאן את מה ששלחתי לך עכשיו" - מצביע על קטע אחר בקוד - "השגיאה כבר לא תהיה להיות מוצג."

קצת מבולבל ועייף, אני משנה את הצהרת sed שעבדנו עליה זמן מה, שומר את הקובץ ורץ systemctl varnish reload. הודעת השגיאה נעלמה...

"המיילים שהחלפתי עם המועמד", המשיך עמיתי, כשהחיוך שלו הופך לחיוך אמיתי ומלא שמחה, "פתאום התברר לי שזו בדיוק אותה בעיה!"

איך הכל התחיל

המאמר מניח הבנה של איך bash, awk, sed ו-systemd עובדים. עדיפות לידע בלכה אך לא חובה.
חותמות הזמן בקטעים שונו.
נכתב עם גוסטינושנקה.
טקסט זה הוא תרגום של המקור שפורסם באנגלית לפני שבועיים; תִרגוּם boyikoden.

השמש זורחת מבעד לחלונות הפנורמיים בבוקר סתווי חמים נוסף, כוס משקה טרי שנרקח עם קפאין מונחת לצד המקלדת, סימפוניה אהובה של צלילים מתנגנת באוזניות מעל רשרוש מקלדות מכניות, והכניסה הראשונה ב- רשימת כרטיסי ה-backlog בלוח הקאנבן זוהרת בשובבות עם הכותרת הגורלית "חקר את varnishreload sh: echo: I/O error in staging" (חקר את "varnishreload sh: echo: I/O error" ב-Staging). כשמדובר בלכה, אין ולא יכולות להיות טעויות, גם אם הן לא גורמות לבעיות, כמו במקרה הזה.

למי שלא מכיר טעינת לכה, זהו סקריפט מעטפת פשוט המשמש לטעינה מחדש של התצורה לַכָּה - נקרא גם VCL.

כפי שמרמזת הכותרת של הכרטיס, השגיאה אירעה באחד השרתים בשלב, ומכיוון שהייתי בטוח שהניתוב של לכה בשלב עובד כמו שצריך, הנחתי שזו תהיה טעות קלה. אז, רק הודעה שנכנסה לזרם פלט שכבר סגור. אני לוקח לעצמי כרטיס, בביטחון מלא שאסמן אותו מוכן תוך פחות מ-30 דקות, טופח לעצמי על השכם על פינוי הלוח מהג'אנק הבא וחוזר לדברים חשובים יותר.

התנגשות בקיר במהירות של 200 קמ"ש

פתיחת קובץ varnishreload, באחד השרתים שבהם פועל Debian Stretch, ראיתי סקריפט מעטפת באורך של פחות מ-200 שורות.

בהרצת הסקריפט, לא ראיתי שום דבר שיכול לגרום לבעיות בעת הפעלתו מספר פעמים ישירות מהמסוף.

הרי זה שלב, גם אם יישבר אף אחד לא יתלונן, נו...לא יותר מדי. אני מריץ את הסקריפט ורואה מה ייכתב למסוף, אבל השגיאות כבר לא נראות.

עוד כמה ריצות כדי לוודא שאני לא יכול לשחזר את השגיאה בלי קצת מאמץ נוסף, ואני מתחיל להבין איך לשנות את הסקריפט הזה ולגרום לו עדיין לזרוק שגיאה.

האם הסקריפט יכול לחסום STDOUT (באמצעות > &-)? או STDERR? שניהם לא עבדו בסופו של דבר.

ברור שהמערכת משנה את סביבת הריצה בדרך כלשהי, אבל איך ולמה?
אני מפעיל את vim ועורך varnishreload, מוסיף set -x ממש מתחת לשבאנג, בתקווה שאיתור באגים בפלט של התסריט ישפוך קצת אור.

הקובץ קבוע, אז אני טוען לכה מחדש ורואה שהשינוי שבר לגמרי את הכל... האגזוז הוא בלגן מוחלט, עם טונות של קוד דמוי C בתוכו. אפילו גלילה בטרמינל לא מספיקה כדי למצוא היכן היא מתחילה. אני מבולבל לגמרי. האם מצב ניפוי באגים יכול להשפיע על העבודה של תוכניות המופעלות בסקריפט? בלי שטויות. באג בקליפה? כמה תרחישים אפשריים עפים לי בראש כמו ג'וקים לכיוונים שונים. כוס משקה מלא קפאין מתרוקנת מיידית, נסיעה מהירה למטבח לאספקה ​​מחדש ו... בוא נלך. אני פותח את התסריט ומסתכל מקרוב על השבאנג: #!/bin/sh.

/bin/sh - זה רק קישור סימבולי של bash, אז התסריט מתפרש במצב תואם POSIX, נכון? זה לא היה שם! מעטפת ברירת המחדל בדביאן היא מקף, וזה בדיוק מה מתייחס /bin/sh.

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

למען המשפט, שיניתי את השבאנג ל #!/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 כתוצאה מביצוע תת-המעטפת הנ"ל?

בהתחלה, הוא שולח את תוכן המשתנה 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} מכיל את התצורה המלאה עבור לכה, עד כה ברורה. עכשיו אני סוף סוף מבין למה פלט מקף עם set -x התברר כל כך שבור - זה כלל את התוכן של התצורה שהתקבלה.

חשוב להבין שלעתים קרובות ניתן לחבר תצורת VCL שלמה ממספר קבצים. הערות בסגנון C משמשות כדי להגדיר היכן נכלל קובץ תצורה אחד באחר, ובדיוק על זה שורת קטע הקוד הבאה.
התחביר להערות המתארות קבצים כלולים בפורמט הבא:

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

המספרים בהקשר זה אינם חשובים, אנו מעוניינים בשם הקובץ.

אז מה קורה בביצת הפקודות שמתחילה בקו 116?
בואו נודה בזה.
הפקודה מורכבת מארבעה חלקים:

1. פשוט echo, המציג את הערך של המשתנה ${VCL_SHOW}

   echo "$VCL_SHOW"

2. awk, שמחפש שורה (רשומה), שבה השדה הראשון, לאחר פיצול הטקסט, יהיה "//", והשני יהיה "VCL.SHOW".
   Awk ירשום את השורה הראשונה התואמת לדפוסים אלה ולאחר מכן תפסיק את העיבוד מיד.

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

3. גוש קוד המאחסן את ערכי השדה בחמישה משתנים, מופרדים על ידי רווחים. המשתנה החמישי FILE מקבל את שאר השורה. לבסוף, ההד האחרון כותב את תוכן המשתנה ${FILE}.

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

4. מכיוון שכל השלבים 1 עד 3 סגורים בתת-מעטפת, הפלט של הערך $FILE ייכתב למשתנה VCL_FILE.

כפי שמציעה ההערה בשורה 119, זה משרת את המטרה היחידה של טיפול אמין במקרים שבהם ה-VCL יפנה לקבצים עם תווי רווח לבן בשמם.

הערתי את ההיגיון המקורי של העיבוד ${VCL_FILE} וניסה לשנות את רצף הפקודות, אבל זה לא הוביל לכלום. הכל עבד לי בצורה נקייה, ובמקרה של הפעלת השירות, זה נתן שגיאה.

נראה שהשגיאה פשוט לא ניתנת לשחזור בעת הפעלת הסקריפט באופן ידני, בעוד ש-30 הדקות המשוערות כבר הסתיימו שש פעמים ובנוסף, הופיעה משימה בעדיפות גבוהה יותר, שדחקה את שאר התיקים הצידה. שאר השבוע היה עמוס במגוון משימות ודילל רק מעט בשיחה על סד וראיון עם המועמד. בעיית שגיאה ב varnishreload אבוד בלתי הפיך בחול המועד.

מה שנקרא sed-fu שלך... בעצם... זבל

בשבוע שלאחר מכן היה יום אחד די פנוי, אז החלטתי לקחת את הכרטיס הזה שוב. קיוויתי שבמוח שלי, תהליך רקע כלשהו כל הזמן הזה חיפש פתרון לבעיה הזו, והפעם אני בהחלט אבין מה לא בסדר.

מכיוון שבפעם האחרונה רק שינוי הקוד לא עזר, פשוט החלטתי לשכתב אותו החל מהשורה ה-116. בכל מקרה, הקוד הקיים היה טיפשי. ואין ממש צורך להשתמש read.

מסתכל שוב על השגיאה:
sh: echo: broken pipe - בפקודה הזו, הד נמצא בשני מקומות, אבל אני חושד שהראשון הוא האשם הסביר יותר (טוב, או לפחות שותף). גם Awk לא מעורר ביטחון. ולמקרה שזה באמת כך awk | {read; echo} העיצוב מוביל לכל הבעיות האלה, למה לא להחליף אותו? הפקודה בת שורה אחת לא משתמשת בכל התכונות של awk, ואפילו בתוספת הזו read בתוספת.

מאז שבוע שעבר היה דיווח על sedרציתי לנסות את הכישורים החדשים שרכשתי ולפשט echo | awk | { read; echo} לתוך מובן יותר echo | sed. למרות שזו בהחלט לא הגישה הטובה ביותר לתפוס את הבאג, חשבתי שלפחות אנסה את ה-sed-fu שלי ואולי ללמוד משהו חדש על הבעיה. לאורך הדרך, ביקשתי מעמיתי, כותב הרצאות הסעד, לעזור לי להמציא תסריט סד יעיל יותר.

הורדתי את התוכן varnishadm vcl.show -v "$VCL_NAME" לקובץ כדי שאוכל להתמקד בכתיבת סקריפט ה-sed ללא כל הטרחה של הפעלה מחדש של השירות.

ניתן למצוא תיאור קצר של האופן שבו sed מטפל בקלט מדריך הגנו שלו. במקורות הסד, הסמל n צוין במפורש כמפריד שורות.

בכמה מעברים, ובעצת עמיתי, כתבנו תסריט סד שנתן את אותה תוצאה כמו כל שורה 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 ומהעובדה שהוא מחליף את כל הקוד המקורי. כל הבדיקות שלי נתנו את התוצאות הרצויות, אז שיניתי את ה-"varnishreload" בשרת ורצתי שוב systemctl reload varnish. טעות מטונפת echo: write error: Broken pipe שוב צחק בפנינו. סמן קורץ חיכה להזנת פקודה חדשה בריק האפל של הטרמינל...

מקור: www.habr.com