管理者のなぞなぞ：サーバーで3回の大量殺害が発生し、監視によると約2回だけでした。 なんで？

構成

すべてを監視するために、一連のganglia-shinken-logstash-elasticsearch-kibanaが構成されています。 完全な説明は非常に広範囲であるため、問題に関連する部分のみに限定します。



Logstashは、すべてのサーバーからログを送信します。 彼はelasticsearchでそれらを積み重ねます。 logstash構成は、問題を示すあらゆる種類の奇妙なメッセージに応答するように構成されています。 メッセージが表示されると、イベントモニタリング（shinken）に送信され、さまざまな方法で管理者を煩わせます。



ほとんどのアプリケーションからメッセージを送信するsyslogに加えて、すべてのコアからnetconsoleを送信するように構成しました。 テクノロジー自体は不可能です-dmesgに加えて、カーネルはUDPデータグラムの形式でメッセージを指定されたIPおよびMACアドレスに送信します。 ネットコンソールは非常に低レベルであり、IP（つまり、ARP）からMACを作成する方法を理解できないため、MACアドレスが必要です。 低レベルのメッセージのため、完全な大変動の状況でも通過します。 たとえば、ソフトウェアスイッチが動作を停止した場合（およびネットワークが利用できない場合）、メッセージは引き続き送信されます。 さらに、iptablesが-j drop_vsyo_nafigと言っても送信されます。 そして、最も重要で価値のあるこれらのメッセージは、ディスクサブシステムが完全に機能しない場合に正常に送信されます。 つまり、事後調査では、「ハングしているサーバーで正確に何が起こったのか」ということです。



「悪い」メッセージの明らかな候補は、oom-killerからのメッセージです。

 [517935.914380] ntpdがoom-killerを呼び出しました：gfp_mask = 0x201da、order = 0、oom_score_adj = 0
 [517935.914730]呼び出しトレース：
 [517935.914807] [<ffffffff816e14ce>] dump_header + 0x83 / 0xbb
 [517935.914877] [<ffffffff816e155b>] oom_kill_process.part.6 + 0x55 / 0x2cf
 ...
最後の勝利で： 
 [517935.951044]メモリー不足：プロセス4550（apache2）スコア247を強制終了するか、子を犠牲にします
 [517935.951203] Killed process 4550（apache2）total-vm：2610268kB、anon-rss：2012696kB、file-rss：3928kB

それでは、謎に戻りましょう。 突然、Apache（より正確にはwsgiアプリケーション）によってデータが不明瞭になり、「どこかで太ってしまう」という言葉でbeatられた場合、試運転、プリプロダクションがあります。 管理者はメッセージを受け取ります。 すべてが良いように見えました（管理者の意味で、「良い」）。 しかし...



3件のエラーが発生し、メッセージは2件発生しました。 監視は大丈夫、ネットコンソールは大丈夫です。 なぞなぞ？ 問題？ 神秘的な未知のゴミの症状？ タンバリンで宮廷シャーマンに電話しますか？

データ収集

最初の質問：これは「3番目」の問題でしたか？ サーバー上でローカルに再確認しました-そうでした。 私はペンで書きます-3つのプロセスが間違いなく殺されました。



2番目の質問：メール？ 私たちはチェックします-shinkenログによると-2つの操作、shinkenが生成したすべてが来ました。



3番目の質問：ネットコンソールは機能しませんか？



チェック： # echo "performing tests" > /dev/kmsg







メッセージがキバナに現れました。 したがって、送信と受信は機能します。



また、OOMメッセージはkibanaではどのように見えますか？ 単純な要求が「呼び出された」（ログの最も一般的な単語ではない）-3つのメッセージ。



3つはどうですか？ なぜ2つのアラートがあるのですか？ フィルターを見ると、フィルターは「呼び出されたoom-killer」行ではなく「Out of memory：Kill process。+（。+）」行で興奮しています。



見ます。 うわー、キバナの「メモリ不足：強制終了プロセス」の行は3行ではなく2行です。 3を呼び出し、2を殺します。



このOOMに関するnetconsoleの特定の出力のみが残されるように、kibanaでサンプリングを設定します。 [ネタバレ：kibanaで管理者を生き残る方法-次のエピソードで]。 見ます。 すべてがそこにあるようです。 ホスト上のdmesgの内容と1行ずつを比較し始めます。 トレースを見ることができ、空きメモリのかなり厄介なダンプを見ることができます（個別に送信されるため、logstashでは「5040」、「1 * 256kB（U）」などの一貫性のないメッセージのセットになります）、プロセスのリストがあります... 、プロセスのリストは完全ではなく、一般に、シートの下半分はありません。



以前の2つのOOM操作では、すべてが整っていますが、ここにはいくつかのメッセージがあります。



そのため、具体的な事実No. 1：完全なoomログはelasticsearchに記録されませんでした。 shinkenはメッセージを受信すると興奮するため、ログがフィルターに完全に到達しなかったと見なすことができます。つまり、今のところelasticsearchとlogstashとの相互作用はスキップできます。



手続の焦点を、ネットコンソールを取得する問題に絞ります。 なんで？ まあ、一方で、UDP、配信の保証などはありませんが、一方でローカルネットワークであり、ネットワーク負荷の増加に関する監視操作はありませんでした。スイッチからのsnmpは何も文句を言わず、ネットワークリンクの点滅もありませんでした。 ネットワーク負荷グラフもスムーズです-接続性の問題は観察されません。



直観の瞬間：そして、私たちはoom killからどんなサイズの記録を持っていますか？ ファイルwc -cに書き込みます。 結局のところ、12.5kb。 「UDPに到達しない」という仮説は、各メッセージが数百バイトという短いため、適切ではありません。 しかし、質問は次のとおりです。誰が高速です-カーネルスレッドで低レベルでUDPパケットを生成するカーネル、または受信したメッセージに対してフィルターと正規表現を実行し、データベースを書き込み、メッセージ用に他のサーバーにイベントを送信するJavaアプリケーションですか？ 明らかに、「 関連するソフトウェアアーキテクチャの設計原則を慎重に使用して実際の問題に対して特にカスタマイズ可能で拡張可能なソリューションを構築する特別な高品質のソフトウェア 」は、gotoワードが119287回出現するダーティCコードよりも高速に処理します（ 3.16-rc7）。



質問：エンタープライズグレードのソフトウェアで処理できるよりも速いパッケージはどうなりますか？ 優れたウィザードを使用すると、ヘッドショットを使用してネットワークインターフェイスの出口ですぐに眠りにつくことができます。



この問題に焦点を当てています。 突然、感覚、ドラマ、スキャンダル、logstashを備えたサーバーの1つのネットワークインターフェースが普遍的な不正を叫ぶが、誰も聞いていない。

 bond0リンクencap：イーサネットHWaddrなんとか何とか
           UP BROADCAST RUNNING MASTER MULTICAST MTU：1500メトリック：1
           RXパケット：455816267エラー：0ドロップ：130361オーバーラン：0フレーム：0
           TXパケット：73379669エラー：0ドロップ：0オーバーラン：0キャリア：0
          衝突：0 txqueuelen：0 

生きる、歓喜する、幸福をもたらす、ネットワークインターフェイス上でスリープするのではなく、13万パケット。



事実2を修正します。監視は、ネットワークインターフェイスのドロップ数を制御しません。 「これは修復できますか？」というさらなる手順に関係なく、貴重な観察結果が得られ、すぐにタスクトラッカーのタスクに変わります。「ネットワークインターフェイスのドロップ数の変化を監視する」。 Googleでの別の実行では、残念ながら、人道的な方法でインターフェイスのカウンターをリセットすることは不可能であるため、変更を修正しています。



フォレンジックシステムの管理はこの時点で終了します。 監視が失敗する理由は下から明らかです。OOMにより、非常に短い時間で大量のメッセージが送信され、Javaがそれに追いつかず、冗長パケットがドロップされます。 検討中のケースでは、アプリケーションが強制終了されたことを示すメッセージを含むパケットを含む-イベントはshinkenに送信されませんでした。

補修

第二部-これにどのように対処しますか？

Googleでの短い実行では、UDPデータグラムを読み取るときのソケットのバッファーサイズがアプリケーション（ man setsockopt 、SO_RCVBUF）によって制御されることが示されました。 Googleの障害物でスプリントを続行します-logstash configにはbuffer_sizeというオプションがあります。 常識に従って、1Mbに引き上げました。 Net.core.rmem_maxもgoogledです-デフォルトでは200 + kbです。 ほとんどの場合、これはこのケースには適用されませんが（12kbのみ）、2Mbに引き上げても問題はありません。

結果

0.監視が失敗した理由が明らかになりました。

1.現在、shinkenはすべてのネットワークインターフェイスでドロップを監視します。

2. logstashは、パケット損失なしでロギングの大幅な増加を受け入れる準備ができています。



PS「syslogのtcp」について話す人のため。 Netconsoleは非常に低レベルであり、「フィールドに入力してイーサネットフレームを送信する」方法でUDPを実行しても、何もできません。 そして、おそらく、TCP経由でログを記録することを考えたために速度が低下し始めた場合、カーネルは非常におかしく見えるでしょう...