まとめとく。out_forward プラグインのパラメータ一覧はオフィシャルドキュメント

detached forwarding server phi=xxx

ログメッセージの例

2014-03-11 00:53:34 +0900 [warn]: detached forwarding server 'host:22442' host="host" port=22442 phi=12.123

説明

heartbeat の結果、サーバが応答せず phi_threashold を超えてしまった場合に出るメッセージ。

なお、ここで言う heartbeat とは、out_forward プラグインが in_forward プラグインに対して 1s (デフォルト)毎に udp (デフォルト)パケットを送信し、さらに in_forward がそれに対して udp パケットを返却することで行っている死活監視。 

該当コード行

out_forward.rb#L407

よくある原因

受信側の Fluentd において、内部処理でブロックしている。

  • 結果、in_forward イベントループ内の heartbeat の受信/返却処理に入れていない。(heartbeat_interval はデフォルト 1s なので1秒以上かかっているような場合はアウト)

送信元の Fluentd において、内部処理でブロックしている。

  • 結果、out_forward イベントループ内の heartbeat の返却を待ち受ける処理に入れていない。 返却が来るまで時間がかかったと判断されてしまう

そもそも heartbeat パケットを送れていない

heartbeat_interval を変更したたために、適切な phi_threshold の値が変わってしまっている。

out_forward 関連パラメタ

  • heartbeat_type (デフォルト: udp)
  • heartbeat_interval (デフォルト: 1s)
  • phi_threshold (デフォルト: 8)

対応策

CPU使用率が高い場合(送信・受信いずれか、または両方)

  • 増設する
  • phi_threashold を増やして誤摩化す。エラーメッセージに出ている phi の値を見て、それより大きい値を phi_threshold に設定する。すぐに recovered な warn メッセージが出ているようであれば、phi_threshold を増やすという手はアリだろう。
  • heartbeat_interval の値を増やしてみる。udp heartbeat のパケットが減って cpu 使用率が減少する(筆者の環境では 1s を 10s にすることで 1/2 になった)。いじった場合、phi_threshold の調節も必要。また、recover_wait / heartbeat_interval の比率を保つように recover_wait の値も変更するとよい。

プラグインがブロックしている場合(送信・受信いずれか、または両方)

そもそも heartbeat パケットが届いていない

  • ネットワーク設定で udp をふさいでいないか確認。udp を空けたくないなら heartbeat_type で tcp へ変更も可能

heartbeat_interval を変更したら適切な phi_threshold の値が変わってしまった

  • エラーメッセージに出ている phi の値を見て、それより大きい値を phi_threshold に設定する

問答無用で detach したくない場合

  • とても大きな値にする

おまけ

そもそも phi ってなんぞ

detached forwarding server hard_timeout=true

ログメッセージの例

2014-03-11 00:53:34 +0900 [warn]: detached forwarding server 'host:22442' host="host" port=22442 hard_timeout=true

説明

hard_timeout (デフォルト 60s) の間、heartbeat への反応がなかった場合に出るメッセージ。 phi_threshold で detach されるよりも状況が逼迫していると思って良い。

該当コード行

out_forward.rb#L397

out_forward 関連パラメタ

  • heartbeat_type (デフォルト: udp)
  • heartbeat_interval (デフォルト: 1s)
  • phi_threshold (デフォルト: 8)
  • hard_timeout (デフォルト: 60s)
  • send_tiemout (デフォルト: 60s) heartbeat_type tcp の場合のみ有効

よくある原因

基本的には phi_threshold の場合と同様。

対応策

基本的には phi_threshold の場合と同様。hard_timeout を大きくして誤摩化したところで 60s 以上の遅延が発生しているのだから対策を打った方がよい。

ネットワーク設定も疑ったほうがよい。次の章にまとめて記述する。

temporarily failed to flush the buffer 

2014-03-11 12:37:37 +0900 [warn]: temporarily failed to flush the buffer. next_retry=2014-03-11 12:37:37 +0900 error_class="Errno::ECONNREFUSED" error="Connection refused - connect(2) for \"192.168.0.2\" port 22442" instance=70182894105380

説明

こちらは heartbeat ではなくメッセージ送信が失敗した場合に出るメッセージ。実際のエラーはログの error_class などを見てググると良い。

さらに retry 上限を超えると retry count exceeds limit の warn メッセージが出る 

該当コード行

output.rb#L343

out_forward 関連パラメタ

  • flush_interval (デフォルト: 60s) データを送信するインターバル。うちは 1s 運用。
  • retry_wait (デフォルト: 1.0s)
  • retry_limit (デフォルト: 17)
  • max_retry_wait (デフォルト: なし)
  • send_tiemout (デフォルト: 60s) データ送信のタイムアウト

よくある原因

受信側の Fluentd において、内部処理で時間がかかるなどしてブロックしている。

  • 結果、in_forward のイベントループ内のデータを受け取る処理に入れていない

開いているソケットの数が多くなりすぎて1プロセスが開けるファイルディスクリプタの数を超えてしまっている。

  • ログに Too many open files と出ている、など

受け付けられるTCP接続要求の上限値を超えている。

  • ECONNREFUSED がたくさん出ている、など
パケロスしている
  • ifconfig の errors, dropped, collisions などをチェック
  • ethtool -S で errors や discards などをチェック
  • /var/log/messages をチェック
  • dmesg をチェック
  • ルータやスイッチをチェック、などなど 

対応策

CPU使用率が高い場合(受信)

  • 増設する

プラグインがブロックしている場合(受信)

開いているソケットの数が多くなりすぎて1プロセスが開けるファイルディスクリプタの数を超えてしまっている(送信・受信いずれか、または両方)

受け付けられる接続要求の上限値を超えている(送信・受信いずれか、または両方)