HadoopによるApacheのログ解析・実例

スキル | 技術動向

» 2011/02/15

　こんにちは、ミツバチワークス stoneです。

　今日は、DECOLOGで行っているApacheのログ解析について、ご紹介してみようかと思います。

　現在、DECOLOGでは、リバースプロキシが8台あって、その8台の1日のApacheのログは、全部で、200Gバイト以上になっています。

　これを、13台のHadoopのスレーブノードで解析を行っています。

※別館注：本記事は2010年10月時点の内容です。この後CDNを導入し、解析対象ログは80GB、解析時間は1時間半程度に圧縮されました。Hadoopのノードも11台に減らしています

　全体の流れとしては、

リバースプロキシからHDFSにログを転送
解析用のサーバで、HDFSにログの転送が終わるのを監視
ログの転送が終わったら、Hadoopを起動、解析
Hadoopの解析結果をデータベースに保存

　以下では、各ステップを個別に見ていくことにしますね。

1. リバースプロキシからHDFSにログを転送

　当初、Hadoopのプロセスが立ち上がっていないと、HDFSにはアクセスできないと思い込んでいたので、解析用のサーバが、

各リバースプロキシからのログをscpで収集
収集したログをHDFSへ

というステップを踏んでいたのですが、このステップだけで、昼過ぎまでかかるようになったため、現在では、リバースプロキシから直接HDFSへ展開するように変更しました。

　Apacheログは、cron.dailyで起動されるlogroateでローテーションがかかるので、そのcron.dailyの最後にHDFSへの展開するスクリプトが起動するようになっています。

/etc/cron.daily/zzlogto_hdfs.sh

#! /bin/sh

HOST=`hostname -s`
TODAY=`date +%Y%m%d`

HADOOP='/path/to/hadoop/bin/hadoop dfs'

HDFS_BASE='hdfs://hadoop-master:9000/accesslog'
LOG_FILE="$HDFS_BASE/$TODAY/$HOST"
SIGNUP_FILE="$HDFS_BASE/signup/$HOST"

LOCAL_SRC="/path/to/log/access_log.1"

$HADOOP -copyFromLocal $LOCAL_SRC $LOG_FILE
$HADOOP -chmod 777 $LOG_FILE
$HADOOP -touchz $SIGNUP_FILE
$HADOOP -chmod 777 $SIGNUP_FILE

2. 解析用サーバで、HDFSにログの転送が終わるのを監視

　各リバースプロキシから直接HDFSへ展開することで、時間は大幅に短縮できたのですが、1点、問題がありました。それは、

　リバースプロキシからのログの転送がいつ終わったのか、分からない

という問題です。

　そのため、ちょっと、工夫をして、HDFS上にsignupディレクトリというモノを作りました。

　各リバースプロキシは、ログの転送が終わったタイミングで、このsignupディレクトリにホスト名のファイルをtouchします。前出のスクリプトの下から2行目でそのtouchをしています。

$HADOOP -touchz $SIGNUP_FILE

　解析用のサーバは、適当な時間に起動した後、このsignupディレクトリを監視して、すべてのサーバが出そろった段階で、次のHadoopでの解析のステップに進みます（signupディレクトリは、転送が始まる前に事前に空にしています）。

3. Hadoopでの解析

3.1 Key-Valueのマッピング

　ご存じのように、Hadoopでは、mapのステップで、あるデータを「key => value」の形にマッピングして、reduceのステップで、同一のkeyの値を取りまとめてくれます。

　DECOLOGでは、以下のような切り口でログ解析をしています。

1時間ごとのHit数、PV数
ページグループ毎のPV数
携帯キャリアごとのHit数

　具体的なキーは、こんな感じです。

YYMMDD-hourly_hit-HH （時間ごとのヒット数）
YYMMDD-hourly_page-HH （時間ごとのPV数）
YYMMDD-page_group-PAGE （ページグループごとのHit数）
YYMMDD-page_group_pv-PAGE （ページグループごとのPV数）
YYMMDD-user_agent-CARRIER （携帯キャリアごとのHit数）

　アクセスされたURLから、

ページビューなのか画像なのか？
ページビューの場合、HTTPステータスが200か？
どのページグループに属するURLか？

を判別しています。なので、例えば記事ページへのアクセスがあった場合、

aaa.bbb.ccc.ddd - - [13/Oct/2010:11:05:09 +0900] "GET /en/00000/00000 HTTP/1.1" 200 999 "-" "DoCoMo/2.0 D905i(c100;TB;W24H17)" "-"

という感じのログになるのですが、これをmapperに通すと、

20101013-hourly_hit-11    1
20101013-hourly_page-11    1
20101013-page_group-Entry    1
20101013-page_group_pv-Entry    1
20101013-user_agent-docomo    1

という結果が出力されることになります。

3.2 mapper/reducerの記述

　実際のmapperとreducerは、Javaではなく、Perlで記述しています。Perlで記述したスクリプトをHadoop Streamingを利用して、mapper/reducerとして、稼働させています。

　Hadoop Streamingは、データの入出力に標準入力／標準出力を使用するため、動作の検証は実際のログデータをmapperに標準入力から流し込んだときに、想定どおりの出力が得られるか？で行えます（reducerは、そのmapperの出力を流しこめばOKです）。

4.解析結果をDBに保存

　Hadoopの解析結果は、「part-0001」みたいなファイル名でHDFS上に出力されているのですが、これをうまい具合に取り出す方法がよく分かっていなくて、現状、以下のようにして、ローカルに取り出しています。

$HADOOP dfs -cat "$OUTPUT_DIR/part-*" | grep $YESTERDAY > $TMP_FILE

保存するデータベースは、以下のようなテーブル定義になってます（データベースは、MySQLです）。

カラム名	データタイプ
log_date	char(8)
section	enum("hourly_hit", "houly_page" ...)
section_key	varchar(255)
log_count	int unsigned

解析結果は、上記のmapperの出力に準じた形になっているので、

20101013-hourly_hit-11    999

と出力されていて、これを、

log_date: 20101013 section: houry_hit section_key: 11 log_count: 999

と保存しています。

　ごく初期の段階では、Webalizerを使って、サーバ1台で解析をしていたですが、解析が夜までかかるようになったため、Hadoopによる解析に切り替えました。

　当時（2009年4月ごろ）は、サーバの負荷対策で、ほぼ毎日のようにサーバの増設や役割の変更、それに伴うプログラムの修正を行っていました。

　その際、対策の根拠となるのが、前日のZABBIXのグラフとアクセス解析の結果でした。

　なので、アクセス解析が夜までかかると、負荷対策の立案にとても困った記憶があります。参考までに、切り替えを行ったタイミングでは1日あたりだいたい4700万PV／2億6000万Hitでした（ログのサイズは、データが残っていませんでした）。

　現在は、１日あたり、だいたい2億PV／15億Hitなのですが、お昼までには解析が終了しています。

■蛇足ですが……

　ウチでは、このシステムを「HAL」と読んでます。

　「Hadoop for Apache Log」の頭文字をとって「HAL」としていますが、本当は、HAL9000からパクって、「Hadoop for なんちゃら」は、後からこじつけました。が、他の年下のエンジニアからは、「何スか？ HAL9000って？」と言われ、ジェネレーションギャップを感じました
（え？知らない方が多数派ですかね、これって？）。

　では、また次回に♪

DECOLOG TECH 2011/02/15 12:00:00 Comment(0)

次の投稿へ

前の投稿へ