Hadoop MapReduceのジョブは各スレーブノード上で1タスクごとにJVMが1プロセス起動する形で実行される。
で、それらのアプリケーションのプロファイルをとりたい場合、各々のJVMごとにとることになる。これにはhprofを使う。
Apache Hadoop 2.7.0 – MapReduce Tutorial
この記述に従って以下のプロパティをセットする。ジョブ起動時に指定すれば有効にできる。プロファイラのパラメータはデフォルトがあるという話だったけど、やってみたら指定しないとエラーになった。以下の指定は自分が試したとき用にいじってある。
mapreduce.task.profile=true mapreduce.task.profile.params=-agentlib:hprof=depth=4,interval=100,cutoff=0.001,cpu=samples,heap=sites,force=n,thread=n,verbose=n,file=%s # MRv1の場合は mapred.task.profile などとする
プロファイラのオプション指定についてはOracle Java SE doucumentを見ればいいのかなと思うけど、なんかいまいち詳しくない。自分が設定する分にはIBMのサイトの日本語解説が役にたった。IBMのやつとOracleので違いがあるかもしれないけど、特に気付かなかった。
HPROF: A Heap/CPU Profiling Tool
IBM Knowledge Center HPROF プロファイラーの使用
このオプションを有効にしてジョブを実行すると、ジョブ終了時(正確にはプロファイラを有効にしたtaskの終了時)に profile.out が生成され、そこにプロファイル結果が出力される。これはJobHistoryServerもしくはJobTrackerのWeb UIから該当のattempt(もしくはtask)を選んで*1、そのログを見れば見られる。いちいちHDFSやローカルファイルシステムに見にいかなくてもいいのは便利。
YARN MRv2での問題
MRv1ならこれだけで一発で結果が得られるんだけど、YARN + MRv2で実行しているとこの結果がちゃんと出てこない。起動時のバナーだけ見られたり、あるいはプロファイル結果の出力が途中でブチ切れた状態になっていたりする。
これはhprofの結果出力がJVMがTERMシグナルを受け取って働く終了処理の中で行われるからだ。んでYARNはTERMを送ったら250msだけ待って終了していないとすぐKILLを送る。ので、プロファイラの結果出力の最中でJVMがKILLられて結果出力がちゃんと得られない、ということになる。
この問題についてはApache JIRAにissueがある。Resolvedになっているが該当バージョンは 2.8.0 だ!
[MAPREDUCE-5465] Tasks are often killed before they exit on their own - ASF JIRA
2.8.0 を待っているわけにはいかないので、どうにか設定をいじってattemptのコンテナがKILLられてしまうまで猶予を作ってみる。これは各スレーブノードで設定して NodeManager を再起動する。
<property> <name>yarn.nodemanager.process-kill-wait.ms</name> <value>30000</value> </property> <property> <name>yarn.nodemanager.sleep-delay-before-sigkill.ms</name> <value>30000</value> </property>
ジョブのConfigurationを見てもこの変更が反映されていなくてアレっと思ったが、試してみた限りでは想定通りに動いているようだ。ちゃんとプロファイル結果が最後まで出力されるようになった。
何か副作用があるかどうかというと、もしかして特定の条件で30秒間だけ長く生き残ってしまうattempt containerが出てしまうかもしれないけど……まあ、特に問題でもないでしょう。
めでたしめでたし。
まとめ
Enjoy profiling!
*1:プロファイラが有効になっているものは明らかに実行時間が長くなるからすぐにわかる
