12. デバッグと性能の問題
HAProxyを"-d"オプションで起動すると、フォアグラウンドで動作し、着信接続や接続の終了などのイベントごと、および受信したリクエスト・レスポンスのヘッダー行ごとに1行を出力します。このデバッグ出力は内容を処理する前に生成されるため、ローカルでの変更は反映されません。主な用途は、ネットワークスニファーを使わずにリクエストとレスポンスを表示することです。複数の接続を並列に処理すると出力は読みにくくなりますが、examples/ディレクトリにある"debug2ansi"と"debug2html"スクリプトで色分けすると、かなり読みやすくなります。
HAProxyがHTTP/1.xのリクエストやレスポンスを不正な形式と判断して拒否した場合は、CLIに接続して"show errors"を実行するのが最適です。フロントエンドとバックエンドごとに、最後に取得された不正なHTTP/1.xリクエストとレスポンス、および入力ストリームで最初に拒否された文字を正確に特定するための情報がすべて表示されます。顧客や開発者のコードにバグがあることを証明するため、これが必要になる場合があります。この場合、“option accept-unsafe-violations-in-http-request”、またはサーバーからのレスポンスに対する同等の"option accept-unsafe-violations-in-http-response"を使うと、取得は続けたままチェックを緩和できることがよくあります。詳細は設定マニュアルを参照してください。
例:
CLIの"show info"の出力には、これまでの最大接続レート、最大SSL鍵処理レートなど、CPUやメモリ使用量に関する一時的な問題の説明に役立つさまざまな情報が含まれます。例:
新しいHAProxyバージョンで問題が不規則に発生するように見える場合(リクエストが1つおきに中断される、時折クラッシュするなど)は、メモリポイズニングを有効にしてみる価値があります。malloc()を呼ぶたびに、直後にメモリ領域を設定可能なバイトで埋める機能です。デフォルトのバイトは0x50(ASCIIの’P’)ですが、ゼロを含む任意のバイトを使えます。ゼロの場合はcalloc()と同じ効果になり、問題が消えることがあります。メモリポイズニングは、コマンドラインの"-dM"オプションで有効にします。性能にわずかな影響があるため、本番環境での使用は推奨しません。有効にすると必ず問題が起きる場合や、ゼロでポイズニングすると一切起きなくなる場合は、明らかにバグを発見したことを意味するため、必ず報告してください。明確な変化がなければ、その問題はこれとは関係ありません。
レイテンシーの問題をデバッグする際は、ローカルマシンでstraceとtcpdumpの両方を使い、リモートシステムでも別のtcpdumpを使うことが重要です。処理の各段階に遅延があり、どこで対処するべきかを判断するには、どの遅延が原因かを知る必要があるためです。実際には、ローカルのtcpdumpで入力データの到着時刻を確認し、straceでhaproxyがそのデータを受け取る時刻(recv/recvfrom)を確認します。opensslはrecv()/send()ではなくread()/write()システムコールを使う点に注意してください。straceはhaproxyのデータ送信時刻も表示し、tcpdumpはシステムがそのデータをインターフェースへ送る時刻を表示します。次に、外部のtcpdumpで、送信されたデータが実際に受信された時刻を確認します。ローカルのtcpdumpで分かるのは、パケットがキューに入った時刻だけだからです。ローカルシステムで取得する利点は、straceとtcpdumpが同じ基準時計を使うことです。straceは"-tts200"を指定して使うことを推奨します。完全なタイムスタンプと、内容を読めるだけの大きさのデータを表示できます。tcpdumpは"-nvvttSs0"を指定し、完全なパケット、実際のシーケンス番号、完全なタイムスタンプを表示することを推奨します。
実際には、マシンのCPUが飽和している場合や、データが不正で配送されない場合を除き、受信データはほぼ常に直ちにhaproxyへ渡されます。受信されても送信されない場合は、通常、出力バッファーが満杯であることが原因です。つまり、受信側が十分な速さでデータを消費していません。出力ファイル記述子への書き込み可能通知がポーリングでしばらく届かないことから確認できます。strace出力でデータが最終的に送出される箇所を見つけ、さかのぼって書き込みイベントの通知時刻を調べると分かりやすいことがよくあります。通常、tcpdumpで検出される受信側からのACKと一致します。送信後も、データがシステム内でしばらく待機することがあります。ここでも、TCPの輻輳ウィンドウの制限によってデータを送出できず、ウィンドウを広げるACKを待っている可能性があります。トラフィックがないのにデータの送出まで40 msや200 msかかる場合は、別の現象です(問題ではありません)。Nagleアルゴリズムが、後続データとの結合を期待して、空のパケットの即時送出を防いでいるためです。HAProxyは純粋なTCPモードとトンネルではNagleを自動的に無効にします。ただし、HTTPボディーの転送時には有効なままであり、パケット数を減らすことで性能向上に寄与します。HTTPに準拠していない一部のアプリケーションは、不完全なHTTPレスポンスメッセージの配送時のレイテンシーに影響を受ける場合があります。その設計に対処するには、“option http-no-delay"を有効にしてNagleを無効にする必要があります。その際、経路上のほかのプロキシも同様の影響を受ける可能性があることを念頭に置いてください。tcpdumpでは即座にデータが送出されているのに、相手側ですぐに受信できない場合は、WANリンクの輻輳、フロー制御が有効なLANの輻輳による送出の抑止、または、より一般的には、HAProxyが実際には仮想マシンで動作し、ハイパーバイザーが何らかの理由で即時送信は不要と判断したことが考えられます。仮想化環境のレイテンシー問題は、ほぼ常に仮想化層が原因です。時間を節約するには、まずVM内と外部コンポーネントのtcpdumpを比較する価値があります。差があれば、その原因はハイパーバイザーと付随するドライバーにあります。
tcpdumpのトレース(-vvを使用)にTCP SACKセグメントが見られる場合、それを送った側はパケット損失の証拠を得ています。SACKが見えなくても損失がないとは限りませんが、見えた場合は確実にネットワークで損失が発生しています。ネットワークでの損失は正常な現象ですが、通常はSACKが目視で目立たない程度の頻度です。トレースに大量に現れる場合は、何が起きているのか、どこでパケットが失われているのかを詳しく調べる価値があります。HTTPはTCPの損失にうまく対処できず、大きなレイテンシーが生じます。
“netstat -i"コマンドは、インターフェースごとの統計を表示します。Rx-Ovrカウンターが増えているインターフェースでは、すべての受信パケットを受け取るためのシステムリソースが足りず、ネットワークドライバーで処理される前にパケットが失われています。Rx-Drpは、アプリケーションの処理が遅いために、受信済みのパケットがネットワークスタック内で失われたことを示します。これは攻撃中にも起こり得ます。Tx-Drpは、出力キューが満杯で、パケットを破棄する必要があったことを示します。TCP使用時には極めてまれなはずですが、送信リンクが飽和している可能性を示します。