ども、最近ちょっと体調不良の cloudpackかっぱ (@inokara) です。

はじめに

ラズパイ触ってあげたいのでネタを探しているというわけではありませんが、ラズパイで mod_mruby を動かしつつアプリケーションログとして fluent-logger-mruby を介してロギングしてみました。

追記(2014/11/30)

@matsumotory さんから助言をいただきまして /etc/apache2/mods-enabled/mruby.conf にソースコードをベタ書きしていたのを以下のように修正しました。


    mrubyHandlerMiddle /etc/apache2/hooks/test.rb cache

mrubyHandlerMiddle にスクリプトのパス、そして cache を付加することで Apache を再起動する際にスクリプトがコンパイルされてキャッシュされるようになります。尚、/etc/apache2/hooks/test.rb に以下のように記載しています。

Apache.echo 'hello mod_mruby world on Raspberry Pi'
log = Fluent::Logger.new(nil, :host=>'127.0.0.1', :port=>'8888')
c = Apache::Connection.new()
log.post('test.hoge', {"remote_ip"=>"#{c.remote_ip}", "local_ip"=>"#{c.local_ip}", "keepalives"=>"#{c.keepalives.to_s}"})

ソースコードをキャッシュすることで処理能力の変化が見られるか試してみましたが以下のような結果でした。

Transactions:                    711 hits
Availability:                 100.00 %
Elapsed time:                  59.96 secs
Data transferred:               0.03 MB
Response time:                  0.76 secs
Transaction rate:              11.86 trans/sec
Throughput:                     0.00 MB/sec
Concurrency:                    8.96
Successful transactions:         711
Failed transactions:               0
Longest transaction:            2.57
Shortest transaction:           0.09

参考

準備

既に…

前回の記事「ラズパイで mruby をビルドして利用出来る状態にする」で mruby はセットアップ済みですが…

fluent-logger-mruby を組み込む為に…

再度 mruby をビルドする必要がありますので以下のように build_config.rb に追記します。

  conf.gem :git => 'https://github.com/iij/mruby-socket.git'
  conf.gem :git => 'https://github.com/iij/mruby-pack.git'
  conf.gem :git => 'https://github.com/suzukaze/mruby-msgpack.git'
  conf.gem :git => 'https://github.com/mattn/mruby-http.git'
  conf.gem :git => 'https://github.com/y-ken/mruby-simplehttp-socket.git'
  conf.gem :git => 'https://github.com/matsumoto-r/mruby-simplehttp.git'
  conf.gem :git => 'https://github.com/matsumoto-r/mruby-httprequest.git'
  conf.gem :git => 'https://github.com/y-ken/fluent-logger-mruby.git'

追記した上で改めてビルドします。

make

ビルドが終わったら簡単な動作テストを行います。(fluentd を起動しておきましょう。尚、現時点では fluent-logger-mruby は in_http プラグインのみに対応しています。)

cat << EOT | mruby
log = Fluent::Logger.new(nil, :host=>'127.0.0.1', :port=>'8888')
log.post('test.hoge', {"message"=>"foo"})
EOT

実行すると fluentd を起動させた際に指定したログファイルに以下のように出力されているはずです。

2014-11-30 18:47:26 +0900 test.hoge: {"message":"foo"}
2014-11-30 18:47:31 +0900 test.hoge: {"message":"foo"}

mod_mruby のインストール

mod_mruby のインストールは mruby を展開しているディレクトリに以下のように git clone してくるところから始めます。

pi@raspberrypi ~/mruby $ ls -ltr
total 8
drwxr-xr-x 16 pi pi 4096 Nov 30 18:18 mruby
git clone git://github.com/matsumoto-r/mod_mruby.git

また、ビルドに際しては apxs2 が必要になりますので以下のように apache2-prefork-dev をインストールしておきましょう。

sudo apt-get install apache2-prefork-dev

引続き、mod_mruby のビルドを進めます。

cd ../mod_mruby
./configure --with-mruby-root=../mruby
make
make install

設定

mod_mruby の設定

以下のように mruby.conf と hooks ディレクトリを用意します。

sudo mkdir /etc/apache2/hooks/
sudo sh -c 'cat << EOT > /etc/apache2/mods-available/mruby.conf
mrubyTranslateNameMiddle /etc/apache2/hooks/test.rb
EOT
'

スクリプトの用意

/etc/apache2/hooks/test.rb を以下のように用意しました。

module ModMruby
  class Test
    def logging
      log = Fluent::Logger.new(nil, :host=>'127.0.0.1', :port=>'8888')
      c = Apache::Connection.new()
      log.post('test.hoge', {"remote_ip"=>"#{c.remote_ip}", "local_ip"=>"#{c.local_ip}", "keepalives"=>"#{c.keepalives.to_s}"})
    end
    #def request
    #  r = Apache::Request.new()
    #  Apache.echo "- filename = #{r.filename}"
    #  Apache.echo "- uri = #{r.uri}"
    #  r.filename = "/var/www/index.html"
    #  r.uri = "/index.html"
    #end
  end
end


t = ModMruby::Test.new
t.logging
#t.request

スクリプトはこちらを参考にさせて頂きました。

設定後…

Apache を再起動しましょう。

sudo service apache2 restart

試してみる

とりあえず

以下のようにラズパイ(xxx.xxx.xxx.21)で起動している Apache にアクセスしてみます。

curl xxx.xxx.xxx.21

ラズパイ側では fluentd のログを tail しておきましょう。

2014-11-30 19:08:00 +0900 test.hoge: {"keepalives":"0","local_ip":"xxx.xxx.xxx.21","remote_ip":"xxx.xxx.xxx.18"}

おお、ちゃんとログが記録されていますね。とりあえず、以下はスクショ。
Raspberry Pi で mod_mruby と fluent-logger-mruby でアプリケーションログ取得: 実行結果

パフォーマンスの確認

あまり参考にはならないとは思いますが mod_mruby 組み込みなし、mod_mruby 組み込み、fluent-logger でのログ出力有りの三パターンで siege でパフォーマンスを確認してみましょ。

用意

mod_mruby 組み込み無しの場合には以下のような静的なページへのアクセスを設定します。

hello apache on Raspberry Pi

mod_mruby 組み込みの場合には以下のような設定を行います。


    sethandler mruby-native-script
    mrubyhandlercode "
      Apache.rputs 'hello mod_mruby world on Raspberry Pi';
    "

fluent-logger でのログ出力有りの場合には以下のような設定を行います。


    sethandler mruby-native-script
    mrubyhandlercode "
      Apache.rputs 'hello mod_mruby world on Raspberry Pi';
      log = Fluent::Logger.new(nil, :host=>'127.0.0.1', :port=>'8888');
      c = Apache::Connection.new();
      log.post('test.hoge', {"remote_ip"=>"#{c.remote_ip}", "local_ip"=>"#{c.local_ip}", "keepalives"=>"#{c.keepalives.to_s}"});
    "

結果

mod_mruby 組み込み無し。

Transactions:                   1721 hits
Availability:                  99.94 %
Elapsed time:                  59.89 secs
Data transferred:               0.08 MB
Response time:                  0.01 secs
Transaction rate:              28.74 trans/sec
Throughput:                     0.00 MB/sec
Concurrency:                    0.30
Successful transactions:        1721
Failed transactions:               1
Longest transaction:            0.32
Shortest transaction:           0.00

mod_mruby を組み込んだ状態。

Transactions:                   1729 hits
Availability:                 100.00 %
Elapsed time:                  59.13 secs
Data transferred:               0.06 MB
Response time:                  0.01 secs
Transaction rate:              29.24 trans/sec
Throughput:                     0.00 MB/sec
Concurrency:                    0.27
Successful transactions:        1729
Failed transactions:               0
Longest transaction:            0.06
Shortest transaction:           0.00

mod_mruby を組み込んだ状態とログ出力。

Transactions:                    661 hits
Availability:                 100.00 %
Elapsed time:                  59.25 secs
Data transferred:               0.10 MB
Response time:                  0.85 secs
Transaction rate:              11.16 trans/sec
Throughput:                     0.00 MB/sec
Concurrency:                    9.48
Successful transactions:         661
Failed transactions:               0
Longest transaction:            2.59
Shortest transaction:           0.17

まず、驚くのは単純な静的なページ出力と mod_mruby で出力したパフォーマンスが殆ど変わらない、むしろ mod_mruby 組み込みの方がパフォーマンスが良い点。これは @matsumotory さんのこちらの記事でも触れられていますが、HTML ファイルを読み込むよりも効率が良いということでしょうか…。そして、fluent-logger を介してのログ出力を含む場合には処理は三分の一程度に留まっていますが、ログ出力が無い状態とは単純に比較は出来ないかなと思っています。

最後に

最後はあまりラズパイは関係は無い状態になりましたが、mruby と mod_mruby と fluentd の連携をラズパイでお手軽に試すことが出来ました。これらをラズパイでちゃんと動かすことで軽量な Web アプリケーションで発生するログ(標準の Apache ログでは取得出来ないようなログ)やデータを fluentd を利用して収集したり加工したり出来そうな未来がちょっと見えたような気がします。

元記事はこちらです。
ラズパイで mod_mruby と fluent-logger-mruby を組み合わせてアプリケーションログの取得を試してみる