fluentdのin_monitor_agent
fluentdにはin_monitor_agentというプラグインが標準で入っていてこれを使うとバッファの状態、具体的な項目としてはretry_count, buffer_total_queued_size, buffer_queue_lengthをモニタリングすることができます。
参考にしたもの：
設定は簡単でこんな感じにします。
<source> type monitor_agent bind 0.0.0.0 port 24220 </source>
ただしfluentdをマルチプロセスで動かしている場合はmonitor_agentのポートもバッティングしないようにする必要があります。そうしないとAddress already in useとか言われてfluendtが起動しません。
僕は4プロセスで動かしている環境でこれにはまって1プロセスだけしかfluentdが起動しない状態になりましたのでご注意を。
僕の環境ではGitHub - fluent/fluent-plugin-webhdfs: Hadoop WebHDFS output plugin for Fluentdを使ってwebhdfs経由でHDFSに格納しています。
in_monitor_agentを入れて2日ほどretry_count, buffer_total_queued_size, buffer_queue_lengthをモニタリングしましたが、retry_countが1日に1回ほど7,8になることがありました。それ以外はほぼ0です。ちなみにピーク時間では無いですね。
ちなみにマシン単位でモニタリングしていて、fluentd個々のプロセスのメトリクスを合計しています。だからretry_countが7,8回というのは4プロセス合計の値になります。ただしログを確認したかぎりでは1つのfluentdプロセスのretry_countが大きくて占有している結果になっていました。
fluend側のログはこんな感じ
2013-12-20 01:14:35 +0900 [warn]: failed to communicate hdfs cluster, path: ...
2013-12-20 01:14:35 +0900 [warn]: temporarily failed to flush the buffer. next_retry=2013-12-20 01:13:36 +0900 error_class="WebHDFS::IOError" error="{\"RemoteException\":{\"exception\":\"AlreadyBeingCreatedException\",\"javaClassName\":\"org.apache.hadoop.hdfs.protocol.AlreadyBeingCreatedException\",\"message\":\"org.apache.hadoop.hdfs.protocol.AlreadyBeingCreatedException: failed to create file … \"}}" instance=...
2013-12-20 01:14:35 +0900 [warn]: /usr/local/ruby-1.9.3-p484/lib/ruby/gems/1.9.1/gems/webhdfs-0.5.5/lib/webhdfs/client_v1.rb:317:in `request'
2013-12-20 01:14:35 +0900 [warn]: /usr/local/ruby-1.9.3-p484/lib/ruby/gems/1.9.1/gems/webhdfs-0.5.5/lib/webhdfs/client_v1.rb:242:in `operate_requests'
2013-12-20 01:14:35 +0900 [warn]: /usr/local/ruby-1.9.3-p484/lib/ruby/gems/1.9.1/gems/webhdfs-0.5.5/lib/webhdfs/client_v1.rb:56:in `append'
2013-12-20 01:14:35 +0900 [warn]: /usr/local/ruby-1.9.3-p484/lib/ruby/gems/1.9.1/gems/fluent-plugin-webhdfs-0.2.1/lib/fluent/plugin/out_webhdfs.rb:182:in `send_data'
2013-12-20 01:14:35 +0900 [warn]: /usr/local/ruby-1.9.3-p484/lib/ruby/gems/1.9.1/gems/fluent-plugin-webhdfs-0.2.1/lib/fluent/plugin/out_webhdfs.rb:200:in `write'
2013-12-20 01:14:35 +0900 [warn]: /usr/local/ruby-1.9.3-p484/lib/ruby/gems/1.9.1/gems/fluentd-0.10.41/lib/fluent/buffer.rb:292:in `write_chunk'
2013-12-20 01:14:35 +0900 [warn]: /usr/local/ruby-1.9.3-p484/lib/ruby/gems/1.9.1/gems/fluentd-0.10.41/lib/fluent/buffer.rb:272:in `pop'
2013-12-20 01:14:35 +0900 [warn]: /usr/local/ruby-1.9.3-p484/lib/ruby/gems/1.9.1/gems/fluentd-0.10.41/lib/fluent/output.rb:305:in `try_flush'
2013-12-20 01:14:35 +0900 [warn]: /usr/local/ruby-1.9.3-p484/lib/ruby/gems/1.9.1/gems/fluentd-0.10.41/lib/fluent/output.rb:131:in `run'
NameNode側のエラーはこんな感じ
2013-12-20 01:14:35,372 ERROR org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException as:www cause:org.apache.hadoop.hdfs.protocol.AlreadyBeingCreatedException: failed to create file …
2013-12-20 01:14:35,372 INFO org.apache.hadoop.ipc.Server: IPC Server handler ...
at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.recoverLeaseInternal(FSNamesystem.java:1764)
at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.startFileInternal(FSNamesystem.java:1586)
at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.appendFile(FSNamesystem.java:1784)
at org.apache.hadoop.hdfs.server.namenode.NameNode.append(NameNode.java:725)
at sun.reflect.GeneratedMethodAccessor41.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:587)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1432)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1428)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:415)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1190)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1426)buffer_total_queued_sizeは4プロセス合計で一番多い時で300M程度でした。ただしこの時はretry_countは0でした。こちらは比較的トラフィックが多い時間でしたね。
まあ、そんな感じです。
