EMRのログ周りについて

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

https://dev.classmethod.jp/cloud/aws/cancel-emr-step/

ログ周りの機能の紹介

ログファイル

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

• デフォルトログファイル - Amazon EMR : ログファイルの概要について記述しています。
• マスターノードでログファイルを表示するには - Amazon EMR : 各種ログのパスについて記述しています。
• ステップ 3: ログファイルの検証 - Amazon EMR : トラブルシューティングの観点で各種ログについて説明しています。

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

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

• Amazon S3 にログファイルをアーカイブする - Amazon EMR : アーカイブ機能について記述しています。
• Amazon S3 にアーカイブされたログファイルを表示する - Amazon EMR : 各種ログのS3上でのパスについて記述しています。

デバッグツール

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

• デバッグツールを有効にする - Amazon EMR : デバッグツールを有効化する手順について記述しています。
• デバッグツールでログファイルを表示する - Amazon EMR : デバッグツールを利用してマネジメントコンソール上でログファイルを参照する手順について記述しています。

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

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

ステップのログファイル

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

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

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の[ジョブを表示]のリンクをクリックして下さい。

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

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

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

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

最後に

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

参考になれば幸いです。