大規模ブログサイト「DECOLOG」の開発・運用ノウハウを公開します。

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

»

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

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

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

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

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

 全体の流れとしては、

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

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

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

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

  1. 各リバースプロキシからのログをscpで収集
  2. 収集したログを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_datechar(8)
sectionenum("hourly_hit", "houly_page" ...)
section_keyvarchar(255)
log_countint 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でした(ログのサイズは、データが残っていませんでした)。

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

■蛇足ですが……

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

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

 では、また次回に♪

Comment(0)