パッケージでインストールしていたCDH4.4から,新たにCloudera Manager Standard(以下CM)管理のクラスタ(CDH4.5)に切り替え,以前同様fluentdのwebhdfsプラグインからHDFSヘログをappendしたところ,予期せぬ現象が・・・。以前も出ていたのだろうか。。
WebHDFSの有効化
CDH4.5でwebhdfsを利用可能にするため,以下のように設定した。dfs.support.append
については,デフォルトでtrue
となっているようだった。CM経由では,hdfsサービス > サービス全体 >
WebHDFS の有効化
にチェックがついていることを確認する。CMの場合,実際の設定ファイルを確認するには,/var/run/cloudera-scm-agent/process
下のxxx-hdfs-(NAME|DATA)NODE/hdfs-site.xml
で確認できる。
1 2 3 4 |
<property> <name>dfs.webhdfs.enabled</name> <value>true</value> </property> |
その後,fluentdのwebhdfsプラグインを使ってWebHDFS API経由でHDFSへappendしたが,以下のようなINFO
レベルのログが大量に出力されてしまう事態に遭遇。初めは,許容範囲かと思う程度だったけれど,段々と高頻度でメッセージが出力され,最終的にはtailでコンソールがログで埋め尽くされたしまう状態だった。INFO
なので基本的には関与せずで問題ないかと思っていたが,ここまでくるとさすがに目をつぶってはいられない。しかも同じブロックIDっぽい。終了条件が満足されず無限ループから脱することができなくなっているように見える。
1 2 3 4 5 6 |
2013-12-14 19:43:27,315 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification failed for BP-1884185756-192.168.56.61-1386868289000:blk_6767085826644652312_3227 - may be due to race with write 2013-12-14 19:43:27,315 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification failed for BP-1884185756-192.168.56.61-1386868289000:blk_6767085826644652312_3227 - may be due to race with write 2013-12-14 19:43:27,315 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification failed for BP-1884185756-192.168.56.61-1386868289000:blk_6767085826644652312_3227 - may be due to race with write 2013-12-14 19:43:27,315 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification failed for BP-1884185756-192.168.56.61-1386868289000:blk_6767085826644652312_3227 - may be due to race with write 2013-12-14 19:43:27,315 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification failed for BP-1884185756-192.168.56.61-1386868289000:blk_6767085826644652312_3227 - may be due to race with write ...endless |
HDFSサービスを再起動すると,
1 2 3 4 5 6 7 8 9 10 11 |
2013-12-14 19:47:48,196 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_-3356347841025830775_3014 2013-12-14 19:47:48,197 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_4628874247189544628_2090 2013-12-14 19:47:48,198 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_-4604910670704378034_2410 2013-12-14 19:47:48,198 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_-7109164516120744359_1972 2013-12-14 19:47:48,199 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_8643939950933092824_2738 2013-12-14 19:47:48,199 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_6253862976873385023_2476 2013-12-14 19:47:48,390 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_3109528374396350160_1968 2013-12-14 19:47:48,391 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_5513034803968839722_2388 2013-12-14 19:47:48,391 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_8992144293701346152_2344 2013-12-14 19:47:48,391 INFO org.apache.hadoop.hdfs.server.datanode.BlockPoolSliceScanner: Verification succeeded for BP-1884185756-192.168.56.61-1386868289000:blk_5242944229150517124_2678 ... |
のようなメッセージがつらつらと出力される。念のためブロック状態を確認するためhdfs fsck
を実行したところHEALTHY
と表示され,不良ブロックらしきも報告されない。それから,ファイルのappend自体は成功しているように見える。
なんとくWebHDFS経由でのファイルappendに関連していると思われるので,fluentd側を1 collector,1 webhdfsで設定しHDFSへの書き込みの状況を観察する。
まず,appendをすべてcreateのみにしてみる。fluentdのwebhdfsプラグインの設定で,append no
にしてみたところ,Verification failed for xxxx
のようなメッセージは確認されなかった(テスト条件にもよると思うので一概には言えないかもしれないが)ので,appendに起因すると推測する。append no
なので,毎回新しいファイルが作成される。ここでは,chunk_id
ごとに一意なファイルとなる。
次に,単一のcollectorからのappendでのHDFSへの書き込みを行ない様子を見る。flush_intervalを20sで設定してみたところ,上記ほどのレベルでないが同メッセージの出力が確認されることがある。flush_interval
を短くするとその頻度は高くなるようだった。
CDH4.4でも同様だったかダウングレードして同様な条件で試してみたところ,少なくともINFO
レベルでの上記のようなメッセージが見られなかったので,CDH4.5へのアップグレードによるものか?ソースを見てみたが,さすがに簡単に特定はできなさそうだ。。
結局,今回はCDH4.4にダウングレードして様子を見ることとしたが,メッセージが出力されないだけで根本的な解決には至っていない気がするが。。
参考
- http://rc.cloudera.com/cdh4.5.0-rc8/cdh/4/hadoop/hadoop-project-dist/hadoop-hdfs/hdfs-default.xml
- http://d.hatena.ne.jp/tagomoris/20120102/1325466102
- http://shun0102.net/?p=454
- http://www.slideshare.net/shun0102/hdfs-6207937
- http://blog.father.gedow.net/2012/07/13/fluentd-webhdfs-writing-problem/
コメント