fluentdのtailプラグインを使ってログを収集してみる

MongoDBのReplica SetsをUbuntuで試してみる | shinodogg.comで立てた
MongoDBにApacheのログを突っ込みたいわけなんですが、
何かとFluent(https://github.com/fluent/fluentd)がアツそうなので試してみます。
 
↓こちらのブログを参考にさせていただきました。
イベントログ収集ツール fluent を試しに使ってみる | 文字
 
■ fluentdのインストール
 
RubyGemsを使ったインストールをしてみます。
諸事情で自分のUbuntuはまっさらな状態になったので、Ruby入れて、RubyGems入れてから、

# apt-get install ruby1.8
# apt-get install rubygems

gem用にプロキシの設定を入れてやって

# vi ~/.gemrc
http_proxy: http://サーバー:ポート

gemでfluent入れようとしたら、、

# gem install fluentd
ERROR:  Could not find a valid gem 'fluentd' (>= 0) in any repository

またまたまた、、っていう。
 
アレやコレやしてたらmarshal data too shortとか言われて
なんだかなぁって思ってたら、そもそもRuby1.9じゃなきゃアレだとかみたいなのを目にしたので、
Ruby系はガッツリpurgeして↓を参考に、Ruby1.9.3のRubyGems1.8.11でやる事にしました。
[Debian(squeeze)][Ruby][fluent]Debian に fluent をインストール | 日記的な

# ruby -v
ruby 1.9.3p0 (2011-10-30 revision 33570) [x86_64-linux]
# gem -v
1.8.11

 
ようやく以下のようにインストールが完了しました。
んま、いろいろと依存してるんですねーって感じで。

# gem install fluentd
Fetching: msgpack-0.4.6.gem (100%)
Building native extensions.  This could take a while...
Fetching: json-1.6.5.gem (100%)
Building native extensions.  This could take a while...
Fetching: yajl-ruby-1.0.0.gem (100%)
Building native extensions.  This could take a while...
Fetching: iobuffer-1.0.0.gem (100%)
Building native extensions.  This could take a while...
Fetching: cool.io-1.1.0.gem (100%)
Building native extensions.  This could take a while...
Fetching: http_parser.rb-0.5.3.gem (100%)
Building native extensions.  This could take a while...
Fetching: fluentd-0.10.9.gem (100%)
Successfully installed msgpack-0.4.6
Successfully installed json-1.6.5
Successfully installed yajl-ruby-1.0.0
Successfully installed iobuffer-1.0.0
Successfully installed cool.io-1.1.0
Successfully installed http_parser.rb-0.5.3
Successfully installed fluentd-0.10.9
7 gems installed
Installing ri documentation for msgpack-0.4.6...
Installing ri documentation for json-1.6.5...
Installing ri documentation for yajl-ruby-1.0.0...
Installing ri documentation for iobuffer-1.0.0...
Installing ri documentation for cool.io-1.1.0...
Installing ri documentation for http_parser.rb-0.5.3...
Installing ri documentation for fluentd-0.10.9...
Installing RDoc documentation for msgpack-0.4.6...
Installing RDoc documentation for json-1.6.5...
Installing RDoc documentation for yajl-ruby-1.0.0...
Installing RDoc documentation for iobuffer-1.0.0...
Installing RDoc documentation for cool.io-1.1.0...
Installing RDoc documentation for http_parser.rb-0.5.3...
Installing RDoc documentation for fluentd-0.10.9...

 
fluentdがインストールできてきたところで、
何も考えずに叩いてやると↓のようになりました。んま、ダメポって感じっぽいですねw

# fluentd
2012-01-25 15:28:14 +0900: starting fluentd-0.10.9
2012-01-25 15:28:14 +0900: reading config file path="/etc/fluent/fluent.conf"
2012-01-25 15:28:14 +0900: unexpected error error="No such file or directory - /etc/fluent/fluent.conf"
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/supervisor.rb:228:in `read'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/supervisor.rb:228:in `read_config'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/supervisor.rb:77:in `block in start'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/supervisor.rb:170:in `call'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/supervisor.rb:170:in `main_process'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/supervisor.rb:145:in `block in supervise'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/supervisor.rb:144:in `fork'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/supervisor.rb:144:in `supervise'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/supervisor.rb:76:in `start'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/lib/fluent/command/fluentd.rb:128:in `<top (required)>'
  2012-01-25 15:28:14 +0900: /usr/lib/ruby/1.9.1/rubygems/custom_require.rb:36:in `require'
  2012-01-25 15:28:14 +0900: /usr/lib/ruby/1.9.1/rubygems/custom_require.rb:36:in `require'
  2012-01-25 15:28:14 +0900: /var/lib/gems/1.9.1/gems/fluentd-0.10.9/bin/fluentd:6:in `<top (required)>'
  2012-01-25 15:28:14 +0900: /usr/local/bin/fluentd:19:in `load'
  2012-01-25 15:28:14 +0900: /usr/local/bin/fluentd:19:in `<main>'
2012-01-25 15:28:14 +0900: process finished code=256
2012-01-25 15:28:14 +0900: process died within 1 second. exit.

 
中身を見ていくと、/etc/fluent/fluent.conf というファイルが無くて怒られているようです。
どうも fluentd –setup ディレクトリ って感じで、fluentのホームディレクトリ的なのが
ホゲホゲされそうなので↓のように叩いてみました。

# fluentd --setup /usr/local/fluent
Installed /usr/local/fluent/fluent.conf.
# ls -l | grep fluent
drwxr-xr-x 3 root root     4096 2012-01-25 15:31 fluent

 
fluent.confを開いてみると、結構ブワーっとイロイロ書いてありますが、
sourceが入力で、matchが出力って事みたいです。

# cat fluent.conf

## built-in TCP input
## $ echo <json> | fluent-cat <tag>
<source>
  type forward
</source>

## built-in UNIX socket input
#<source>
#  type unix
#</source>

# HTTP input
# http://localhost:8888/<tag>?json=<json>
<source>
  type http
  port 8888
</source>

## File input
## read apache logs with tag=apache.access

 
 
■ ログ収集用の環境設定
 
同じホスト内になってしまうのであれですが、
2つのプロセスからログを集めてくることにしました。
 
せっかくRubyでアレやコレやしてみたのでSinatraを使ってみることにします。

# gem install sinatra
Fetching: rack-1.4.1.gem (100%)
Fetching: rack-protection-1.2.0.gem (100%)
Fetching: tilt-1.3.3.gem (100%)
Fetching: sinatra-1.3.2.gem (100%)
Successfully installed rack-1.4.1
Successfully installed rack-protection-1.2.0
Successfully installed tilt-1.3.3
Successfully installed sinatra-1.3.2
4 gems installed
Installing ri documentation for rack-1.4.1...
Installing ri documentation for rack-protection-1.2.0...
Installing ri documentation for tilt-1.3.3...
Installing ri documentation for sinatra-1.3.2...
Installing RDoc documentation for rack-1.4.1...
Installing RDoc documentation for rack-protection-1.2.0...
Installing RDoc documentation for tilt-1.3.3...
Installing RDoc documentation for sinatra-1.3.2...

 
・1つめのアプリ(app01.rb)。 # 何のへんてつもないw

# cat app01.rb
require 'sinatra'
require 'logger'
logger = Logger.new('sinatra01.log')

get '/' do
  logger.info "log from 01"
  'Hello app01'
end

 
・2つめのアプリ(app02.rb)。#上のコピペw

# cat app02.rb
require 'sinatra'
require 'logger'
logger = Logger.new('sinatra02.log')

get '/' do
  logger.info "log from 02"
  'Hello app02'
end

 
起動します。ポートは4567と4568にしてみました。

# ruby -rubygems app01.rb -p 4567
[2012-01-26 11:25:30] INFO  WEBrick 1.3.1
[2012-01-26 11:25:30] INFO  ruby 1.9.3 (2011-10-30) [x86_64-linux]
== Sinatra/1.3.2 has taken the stage on 4567 for development with backup from WEBrick
[2012-01-26 11:25:30] INFO  WEBrick::HTTPServer#start: pid=4135 port=4567
# ruby -rubygems app02.rb -p 4568
[2012-01-26 12:20:31] INFO  WEBrick 1.3.1
[2012-01-26 12:20:31] INFO  ruby 1.9.3 (2011-10-30) [x86_64-linux]
== Sinatra/1.3.2 has taken the stage on 4568 for development with backup from WEBrick
[2012-01-26 12:20:31] INFO  WEBrick::HTTPServer#start: pid=5838 port=4568

 
上記のプロセスたちから吐かれるsinatra01.logとsinatra02.logをリモート的に集めて、
一つのログファイルに出力したいです、と。
ってことで、以下3つの設定ファイルを用意してfluentを起動します。
 
・app01.rbのログをtailで持ってくる
(pos_fileっていうのはFluentがどこまでファイル読んだか記録しておく用途)

$ cat sinatra01.conf
<source>
  type tail
  format /^(?<SeverityID>[^ ]), [(?<time>[^ ]*) (?<pid>[^ ]*)]  (?<SeverityLabel>[^ ]*) -- : (?<message>.*)$/
  time_format %Y-%m-%dT%H:%M:%S
  path /usr/local/sinatra_test/sinatra01.log
  tag sinatra
  pos_file /usr/local/fluent/tmp/sinatra01.log.pos
</source>

<match sinatra>
  type tcp
  host localhost
</match>

 
・app02.rbのログをtailで持ってくる

$ cat sinatra02.conf
<source>
  type tail
  format /^(?<SeverityID>[^ ]), [(?<time>[^ ]*) (?<pid>[^ ]*)]  (?<SeverityLabel>[^ ]*) -- : (?<message>.*)$/
  time_format %Y-%m-%dT%H:%M:%S
  path /usr/local/sinatra_test/sinatra02.log
  tag sinatra
  pos_file /usr/local/fluent/tmp/sinatra02.log.pos
</source>

<match sinatra>
  type tcp
  host localhost
</match>

 
・上記で集めたログを一ヶ所に吐き出す

$ cat log.conf
<source>
  type tcp
</source>

<match sinatra>
  type file
  path /usr/local/fluent/sinatra.log
</match>

 
※ tailのインプット(sourceタグ)の設定にちょっと手間取りました。
Fluentは↓のようにapacheのaccess_logとsyslogをformatに指定することが出来るのですが、
http://fluentd.org/doc/plugin.html#tail
Sinatraでloggerで吐いたログは自分でレイアウトをFluentに教えてあげる必要があります。
#そうするとFluentがよしなにJSONにしてくれるわけです。
 
やり方的には、
・formatのところをログレイアウトに沿って正規表現で指定して、
・日付データ(timeで指定したとこ)はformat_timeのところで指定する
感じになります。
 
日付データに関して、Sinatraからloggerで吐いたログは
↓のようになっていて、

2012-01-25T19:47:57.799700

こいつは、fluentのparser.rbで↓のように扱われるようなのですが、

time = Time.strptime(value, @time_format).to_i

そうした場合に、マイクロ秒を%6Nとかで指定すると↓のように怒られてしまいます。

irb(main):030:0> Time.strptime('2001-02-03T04:05:06.799324', '%Y-%m-%dT%H:%M:%S.%6N')
ArgumentError: invalid strptime format - `%Y-%m-%dT%H:%M:%S.%6N'

 
ってことで@yssk22がプラグイン書いてくれるそうなのですがw
そんなに困ってないので、とりあえず秒まで指定おくか的な感じにしています。
 
ってことで、それぞれの設定ファイルを指定してFluentのプロセスを起動させます。
 
・app01.rb向け

/usr/local/fluent# fluentd -c sinatra01.conf
2012-01-26 12:57:30 +0900: starting fluentd-0.10.9
2012-01-26 12:57:30 +0900: reading config file path="sinatra01.conf"
2012-01-26 12:57:30 +0900: adding source type="tail"
2012-01-26 12:57:30 +0900: adding match pattern="sinatra" type="tcp"

 
・app02.rb向け

/usr/local/fluent# fluentd -c sinatra02.conf
2012-01-26 12:57:34 +0900: starting fluentd-0.10.9
2012-01-26 12:57:34 +0900: reading config file path="sinatra02.conf"
2012-01-26 12:57:34 +0900: adding source type="tail"
2012-01-26 12:57:34 +0900: adding match pattern="sinatra" type="tcp"

 
・ログを一ヶ所に吐き出すヤツ

# fluentd -c log.conf
2012-01-26 12:57:36 +0900: starting fluentd-0.10.9
2012-01-26 12:57:36 +0900: reading config file path="log.conf"
2012-01-26 12:57:36 +0900: adding source type="tcp"
2012-01-26 12:57:36 +0900: adding match pattern="sinatra" type="file"
2012-01-26 12:57:36 +0900: listening fluent socket on 0.0.0.0:24224

 
 
■ ログ収集できるか確認
 
ログがちゃんと集まるか確認してみます。
 
Sinatraアプリのhttp://localhost:4567/とhttp://localhost:4568/をズカズカ叩いた後に、
上記のlog.confで指定した /usr/local/fluent/sinatra.log にアクセスすると、
sinatra.log.20120126.b4b765625c2912236 っていうファイルが出来ていて、
開いてみると↓のようにイイ感じです。

$ cat sinatra.log.20120126.b4b765625c2912236
2012-01-26T13:00:32+09:00	sinatra	{"SeverityID":"I","pid":"#4135","SeverityLabel":"INFO","message":"log from 01"}
2012-01-26T13:00:34+09:00	sinatra	{"SeverityID":"I","pid":"#5838","SeverityLabel":"INFO","message":"log from 02"}
2012-01-26T13:00:36+09:00	sinatra	{"SeverityID":"I","pid":"#5838","SeverityLabel":"INFO","message":"log from 02"}
2012-01-26T13:00:40+09:00	sinatra	{"SeverityID":"I","pid":"#4135","SeverityLabel":"INFO","message":"log from 01"}
2012-01-26T13:01:19+09:00	sinatra	{"SeverityID":"I","pid":"#4135","SeverityLabel":"INFO","message":"log from 01"}
2012-01-26T13:01:22+09:00	sinatra	{"SeverityID":"I","pid":"#4135","SeverityLabel":"INFO","message":"log from 01"}
2012-01-26T13:00:38+09:00	sinatra	{"SeverityID":"I","pid":"#5838","SeverityLabel":"INFO","message":"log from 02"}
2012-01-26T13:01:21+09:00	sinatra	{"SeverityID":"I","pid":"#5838","SeverityLabel":"INFO","message":"log from 02"}

 

ってことで、scpとかしないで一ヶ所にログを集めることが出来そうです。
 
あとは、pos_fileを指定してもログファイルがローテーションした時にinode番号が変わってー
とかってなった時は、プロセスが落ちたりすると、どないしよ?みたいになりそうで、
その辺のリカバリとか考えなきゃなーって気がする今日この頃です。
 
次は、こいつをMongoDBに突っ込んでGoogle Web Tool Kitとか使って、
イカしたグラフ的なUIとかでキャッキャしたいなー
 

入門 ウェブ分析論~アクセス解析を成果につなげるための新・基礎知識~
小川 卓
ソフトバンククリエイティブ
売り上げランキング: 139321

コメント

  1. […] and Brightestな感じのスゲー技術者集まってる事で有名な Treasure Dataですが、Fluentdとかは試したことありますが、 そう言えば本体使った事ないなと。。   […]

タイトルとURLをコピーしました