ウサギの穴に落ちる: ワニスの再起動エラーの物語 - パート 1

ゴスティヌシャンカ、まるで自分の命がかかっているかのように、前の20分間ボタンを連打した後、彼の目に半野生の表情と陰険な笑みを浮かべて私に向き直った - 「おい、わかったような気がする」。

「ここを見てください」と彼は画面上の記号の XNUMX つを指して言い、「きっとあなたは赤い帽子をかぶっているでしょう。私がここに送った内容を追加すれば、エラーは表示されなくなります」とコードの別のセクションを指さします。

少し当惑して疲れたので、しばらく作業してきた sed ステートメントを変更し、ファイルを保存して実行します。 systemctl varnish reload。 エラーメッセージが消えてしまいました…

「候補者とやり取りしたメールです」と同僚は続け、笑い声​​が喜びに満ちた本物の笑顔に変わりました。「これがまさに同じ問題であることに突然気づきました！」

すべてはどのように始まったのか

この記事は、bash、awk、sed、systemd の仕組みを理解していることを前提としています。 ワニスの知識があることが望ましいですが、必須ではありません。
スニペットのタイムスタンプが変更されました。
で書いた ゴスティヌシャンカ.
この文章は XNUMX 週間前に英語で出版された原文の翻訳です。 翻訳 少年行伝.

別の暖かい秋の朝、パノラマの窓から太陽が輝き、淹れたてのカフェイン入りドリンクがキーボードから離れ、お気に入りの音のシンフォニーがヘッドフォンのメカニカルキーボードのカサカサ音に乗って流れ、カンバンボード上のバックログチケットリストの最初のエントリが、ふざけて運命的なタイトル「Investigate varnishreload sh: echo: I/O error in staging」で輝きます（「Investigate varnishreload sh : echo: I/O error in staging」）。 』の舞台）。 ワニスに関しては、今回のように問題が生じなかったとしても、間違いはありませんし、あってはならないのです。

なじみのない人のために ワニスリロード、これは構成を再ロードするために使用される単純なシェル スクリプトです。 ワニス - VCLとも呼ばれます。

チケットのタイトルが示すように、ステージ内のサーバーの 30 つでエラーが発生しました。ステージ内での varnish のルーティングが正しく機能していると確信していたので、これは軽微なミスだろうと想定していました。 したがって、すでに閉じられた出力ストリームに入ったメッセージだけです。 私は自分のためにチケットを受け取り、XNUMX 分以内に準備完了のマークを付け、次のジャンクをボードから片付けて、より重要な作業に戻るために自分の肩をたたいて自信を持っています。

時速200kmで壁に衝突

ファイルを開く varnishreload、Debian Stretch を実行しているサーバーの 200 つで、長さが XNUMX 行未満のシェル スクリプトを見つけました。

スクリプトを実行したところ、ターミナルから直接複数回実行したときに問題を引き起こす可能性のあるものは何も見つかりませんでした。

結局のところ、これは舞台です、たとえ壊れたとしても誰も文句を言いません、まあ...あまりにも多くはありません。 スクリプトを実行して端末に何が書き出されるかを確認しますが、エラーは表示されなくなりました。

さらに数回実行して、特別な努力をしないとエラーを再現できないことを確認し、このスクリプトを変更して引き続きエラーをスローさせる方法を考え始めます。

スクリプトは STDOUT をブロックできますか (使用 > &-）？ それとも標準エラー? 結局どちらも機能しませんでした。

systemd が何らかの方法で実行環境を変更するのは明らかですが、どのように、そしてなぜなのでしょうか?
vimを起動して編集します varnishreload、追加 set -x スクリプトの出力をデバッグすることで何らかの光が当たることを期待して、シバンのすぐ下にあります。

ファイルは修正されたので、ワニスをリロードすると、変更によってすべてが完全に壊れていることがわかります...排気は完全に混乱しており、C のようなコードが大量に含まれています。 ターミナル内をスクロールしても、どこから始まるのかを見つけるのに十分ではありません。 私は完全に混乱しています。 デバッグ モードは、スクリプトで実行されるプログラムの動作に影響を与える可能性がありますか? いや、でたらめだ。 シェルのバグ? 考えられるいくつかのシナリオが、ゴキブリのように頭の中でさまざまな方向に飛び交っています。 カフェインたっぷりの飲み物はすぐに空になり、すぐにキッチンに行ってカフェインを補給して…さあ、出発です。 スクリプトを開いてシバンを詳しく見てみましょう。 #!/bin/sh.

/bin/sh - これは単なる bash シンボリックリンクなので、スクリプトは POSIX 互換モードで解釈されますね。 そこにはなかったのです！ Debian のデフォルトのシェルはダッシュです。これはまさにそれです。 言及する /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_SHOW115 行目で作成された、パイプを介して次のコマンドに送信されます。 そしてそこで何が起こるのでしょうか？

まず、使用するのは、 varnishadmvarnish インストール パッケージの一部であり、再起動せずに varnish を構成します。

サブコマンド vcl.show -v で指定された VCL 設定全体を出力するために使用されます。 ${VCL_NAME}、STDOUTに。

現在アクティブな VCL 設定と、メモリ内にまだ残っているいくつかの以前のバージョンの varnish のルーティング設定を表示するには、次のコマンドを使用できます。 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 行目から始まる大量のコマンドでは何が起こるのでしょうか?
それに直面してみましょう。
コマンドは XNUMX つの部分で構成されます。

1. 単純な echo、変数の値を表示します ${VCL_SHOW}

   echo "$VCL_SHOW"

2. awk、行 (レコード) を検索します。テキストを分割した後の最初のフィールドは「//」、XNUMX 番目のフィールドは「VCL.SHOW」になります。
   awk は、これらのパターンに一致する最初の行を書き出して、すぐに処理を停止します。

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

3. スペースで区切られた XNUMX つの変数にフィールド値を格納するコードのブロック。 XNUMX 番目の変数 FILE は行の残りを受け取ります。 最後に、最後のエコーは変数の内容を書き込みます。 ${FILE}.

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

4. ステップ 1 ～ 3 はすべてサブシェルで囲まれているため、値の出力は $FILE 変数に書き込まれます VCL_FILE.

119 行目のコメントが示すように、これは、VCL が名前に空白文字を含むファイルを参照する場合を確実に処理するという唯一の目的を果たします。

元の処理ロジックをコメントアウトしました。 ${VCL_FILE} コマンドの順序を変更しようとしましたが、何も起こりませんでした。 私にとってはすべて問題なく動作しましたが、サービスを開始する場合にはエラーが発生しました。

スクリプトを手動で実行するとエラーが単純に再現できないようですが、推定 30 分がすでに XNUMX 回終了しており、さらに優先度の高いタスクが表示され、残りのケースが脇に追いやられています。 週の残りの時間はさまざまなタスクでいっぱいでしたが、SED に関する講演と候補者との面接で少し薄められただけでした。 エラーの問題 varnishreload 時間の砂の中に取り返しのつかないほど失われた。

あなたのいわゆるセフ...実際...ゴミ

翌週はかなり空いていた日があったので、再度このチケットを利用することにしました。 私の脳内では、バックグラウンドのプロセスがずっとこの問題の解決策を探していたので、今回は間違いなく何が問題なのかを理解できるだろうと期待していました。

前回はコードを変更しただけではダメだったので、116行目から書き直すことにしました。 いずれにせよ、既存のコードは愚かでした。 そして、使用する必要はまったくありません read.

もう一度エラーを見てみましょう:
sh: echo: broken pipe - このコマンドでは、エコーは XNUMX か所にありますが、最初のほうが犯人 (少なくとも共犯者) である可能性が高いと思われます。 Awk も自信を呼び起こしません。 そして、それが本当にそうな場合に備えて、 awk | {read; echo} この設計がこれらすべての問題を引き起こすのであれば、なぜ交換しないのでしょうか? この XNUMX 行のコマンドは、awk のすべての機能を使用するわけではありません。 read 付属品で。

先週から報道がありましたので、 sed新しく習得したスキルを試して簡素化したいと思った echo | awk | { read; echo} より分かりやすく echo | sed。 これは間違いなくバグを発見するための最良のアプローチではありませんが、少なくとも自分の sed-fu を試して、問題について何か新しいことを学ぼうと考えました。 その過程で、私は同僚である sed トーク ライターに、より効率的な sed スクリプトを考え出すのを手伝ってくれるよう頼みました。

内容を落としてしまいました varnishadm vcl.show -v "$VCL_NAME" これにより、サービスを再起動する手間をかけずに sed スクリプトの作成に集中できます。

sed が入力を処理する正確な方法の簡単な説明は、次の場所にあります。 彼のGNUマニュアル。 sed ソースのシンボル n 行区切り文字として明示的に指定されます。

同僚のアドバイスを受けて、数回のパスを経て、元の 116 行目全体と同じ結果が得られる sed スクリプトを作成しました。

以下は入力データを含むサンプル ファイルです。

> 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 また私たちの顔に向かって笑った。 ターミナルの暗い空間で、ウィンクするカーソルが新しいコマンドの入力を待っていました...

出所： habr.com