EMRのログ周りについて

Amazon EMR

今回はEMRのログ周りについて紹介します。まずはログ周りの機能について紹介し、次に以下のエントリーを例にデバッグツールを利用してログファイルを参照する手順を紹介します。

EMRのステップのキャンセルについて

ログ周りの機能の紹介

ログファイル

EMRはデフォルトで各種ログファイルをクラスターのEC2インスタンス上に出力します。出力先のパスは/mnt/var/log/配下になっておりSSHでログインして参照します。ログにはEMRステップやHadoopなどのミドルウェア、ブートストラップアクションのログなどがあります。詳細については以下を参照して下さい。

S3へのログファイルアーカイブ

クラスター上で出力されたログファイルを定期的にS3にコピーする機能です。クラスターのEC2インスタンス上でHadoopなどのミドルウェアが出力するログファイルを5分間隔でS3にコピーします。ログがなければ障害発生時に調査が出来なくなるので有効化することを推奨します。詳細については以下を参照して下さい。

デバッグツール

デバッグツールはマネジメントコンソール上でログファイルを参照できる機能です。S3へのログファイルアーカイブによってS3上にコピーされたログをマネジメントコンソール上で直感的に探すことが出来ます。詳細については以下を参照して下さい。

デバッグツールによるログファイルの参照

EMRのステップのキャンセルについて | Developers.IOを例に実際にログファイルを参照しましょう。

ステップのログファイル

ステップのログファイルはマネジメントコンソール上の[ステップ]の[ログファイル]列で参照できます。最初は[ログの表示]というリンクになっているのでクリックして下さい。

emr-cluster-logging-functions_1

クリックすると[コントローラー]、[syslog]、[stderr]、[stdout]の4種類のログファイルを参照できるようになります。ステップによって出力されるログが異なり、リンクが有効なログファイルのみ参照可能です。また、WordCount2のようにキャンセルしてログファイルが存在しない場合は[まだログが作成されていません]と表示されます。

emr-cluster-logging-functions_2

WordCount1のsyslogの抜粋は以下の通りです。Hadoop StreamingジョブはMapReduceアプリケーションとして実行されるためMapタスクとReduceタスクの進捗状況のログが出力されていることが分かります。

2017-07-06 11:29:59,877 INFO org.apache.hadoop.mapreduce.Job (main): Running job: job_1499340358324_0001
2017-07-06 11:30:26,621 INFO org.apache.hadoop.mapreduce.Job (main): Job job_1499340358324_0001 running in uber mode : false
2017-07-06 11:30:26,623 INFO org.apache.hadoop.mapreduce.Job (main):  map 0% reduce 0%
2017-07-06 11:30:59,113 INFO org.apache.hadoop.mapreduce.Job (main):  map 6% reduce 0%
2017-07-06 11:31:02,136 INFO org.apache.hadoop.mapreduce.Job (main):  map 8% reduce 0%
2017-07-06 11:31:33,552 INFO org.apache.hadoop.mapreduce.Job (main):  map 14% reduce 0%
2017-07-06 11:31:34,561 INFO org.apache.hadoop.mapreduce.Job (main):  map 17% reduce 0%
2017-07-06 11:31:55,748 INFO org.apache.hadoop.mapreduce.Job (main):  map 25% reduce 0%
2017-07-06 11:32:19,947 INFO org.apache.hadoop.mapreduce.Job (main):  map 31% reduce 0%
2017-07-06 11:32:20,963 INFO org.apache.hadoop.mapreduce.Job (main):  map 33% reduce 0%
2017-07-06 11:32:44,153 INFO org.apache.hadoop.mapreduce.Job (main):  map 39% reduce 0%
2017-07-06 11:32:46,165 INFO org.apache.hadoop.mapreduce.Job (main):  map 42% reduce 0%
2017-07-06 11:33:05,288 INFO org.apache.hadoop.mapreduce.Job (main):  map 50% reduce 0%
2017-07-06 11:33:26,424 INFO org.apache.hadoop.mapreduce.Job (main):  map 58% reduce 0%
2017-07-06 11:33:46,592 INFO org.apache.hadoop.mapreduce.Job (main):  map 67% reduce 0%
2017-07-06 11:34:11,721 INFO org.apache.hadoop.mapreduce.Job (main):  map 72% reduce 0%
2017-07-06 11:34:12,726 INFO org.apache.hadoop.mapreduce.Job (main):  map 75% reduce 0%
2017-07-06 11:34:30,821 INFO org.apache.hadoop.mapreduce.Job (main):  map 83% reduce 0%
2017-07-06 11:34:46,923 INFO org.apache.hadoop.mapreduce.Job (main):  map 92% reduce 0%
2017-07-06 11:35:05,016 INFO org.apache.hadoop.mapreduce.Job (main):  map 100% reduce 0%
2017-07-06 11:35:31,283 INFO org.apache.hadoop.mapreduce.Job (main):  map 100% reduce 100%
2017-07-06 11:35:32,294 INFO org.apache.hadoop.mapreduce.Job (main): Job job_1499340358324_0001 completed successfully

WordCount3のsyslogの抜粋は以下の通りです。ジョブを直接killしたことが分かります。

2017-07-06 11:36:16,668 INFO org.apache.hadoop.mapreduce.Job (main): Job job_1499340358324_0002 running in uber mode : false
2017-07-06 11:36:16,674 INFO org.apache.hadoop.mapreduce.Job (main):  map 0% reduce 0%
2017-07-06 11:37:02,931 INFO org.apache.hadoop.mapreduce.Job (main):  map 8% reduce 0%
2017-07-06 11:37:26,143 INFO org.apache.hadoop.mapreduce.Job (main):  map 14% reduce 0%
2017-07-06 11:37:31,313 INFO org.apache.hadoop.mapreduce.Job (main):  map 0% reduce 0%
2017-07-06 11:37:31,325 INFO org.apache.hadoop.mapreduce.Job (main): Job job_1499340358324_0002 failed with state KILLED due to: Application killed by user.

タスクのログファイル

次にステップを構成するジョブとタスクのログファイルを参照しましょう。WordCount1の[ジョブを表示]のリンクをクリックして下さい。

emr-cluster-logging-functions_3

Hadoop Streamingジョブの場合はジョブは1行になるので[タスクの表示]をクリックして下さい。

emr-cluster-logging-functions_4

タスクの一覧が表示されます。MapタスクとReduceタスク毎に行が表示されます。MapタスクかReduceタスクであるかは[タイプ]列で判断できます。

emr-cluster-logging-functions_5

実際に個々のMapタスクとReduceタスクのログを参照する際は各行の[試行の表示]をクリックします。m_000008の[試行の表示]をクリックしてみましょう。

emr-cluster-logging-functions_6

Mapタスクm_000008のsyslogを参照できることが分かります。

最後に

実際にログを参照してエラーを解決する際はHadoopやHive、Sparkなどのミドルウェアの知識も必要になりますが、まずはログファイルの出力先が分からないと始まらないのでまとめてみました。よくあるトラブルシューティングについてはドキュメントにまとまっているのでそちらも参照することをおすすめします。
クラスターをトラブルシューティングする - Amazon EMR

参考になれば幸いです。