はじめに
td-agent使って最初はいろいろ四苦八苦しましたが、
だいぶ期間も経ってしまって忘れそうなのでタグの扱いについて自分なりにメモっておこーっていう記事です
①では
- fluent-plugin-parse
- fluent-plugin-config-expander
- fluent-plugin-rewrite
- fluent-plugin-record-reformer
を使っていろいろやりましたが、もっと好きにやりたいけどplugin作るまでではないんだよなーというときのout_exec_filterについてです。
こちらも参考にしてみてください
→td-agent(fluentd)を本番サ―ビスで小さく使ってみたメモ-まとめ - tweeeetyのぶろぐ的めも
ながれ
- 前提とか(fluent-plugin-parser)
- 前提
- 関連ディレクトリ構成
- イメージ
- out_exec_filter使ってみる
補足
そんなにテクニカルでも有用でもないカモですがこちらにメモまとめをメモっておきました →td-agent(fluentd)を本番サ―ビスで小さく使ってみたメモ-まとめ
前提とか
前提
関連ディレクトリ構成
outファイルで出力するログやpos、シンボリックリンクを格納するフォルダの構成はこんな感じにしてます
- 送信・受信側共通
# tree /var/log/td-agent /var/log/td-agent |-- project | |-- aclog | |-- buffer | |-- out | |-- pos | `-- slink `-- unmatched
イメージ
いくつかプラグインを使いますが基本的な流れはこれで行います。
送信側はaccessログをそのまんまの形で送信
↓
受信側は来たログをparserでパースしてemit~からのいろいろやる
理由はサービスに導入時にwebサーバに負荷をかけたくなかったので
パース処理は受信側で行いたいという感じです
- 図だとこんな感じ
準備
fluent-plugin-parserだけは最初にインストールしておきます
/usr/lib64/fluent/ruby/bin/gem install fluent-plugin-parser
2. out_exec_filter使ってみる
やってみるながれはこんな感じです
ってことで早速
シンプルに動かしてみる
まずはシンプルに動かしてみます。
主に受信側ですが、動かしてみる内容としてはこんな感じのイメージ
perlに渡すだけで何もしませんw
td-agentでアクセスログをparseしてjsonにする
↓
out_exec_filterでjsonをperlに渡す
↓
perlプログラムでjsonを受け取って何もせずそのまま標準出力
↓
td-agentでperlから出力されたjsonをファイルに出力
そして用意はこれだけ
- config書く
- perlプログラム
config書く
- 送信側
<source> type config_expander <config> type tail format none time_format %d/%b/%Y:%T %z path /var/log/td-agent/project/slink/access.log pos_file /var/log/td-agent/project/pos/access.pos #rotate_wait 30 tag raw.project.apache.access.__HOSTNAME__ </config> </source>
- 受信側
exec_filterにfluentd_exec_filter_simple.plという後述するperlを指定します
<match raw.project.apache.**> type parser remove_prefix raw add_prefix parsed format /^(?<host>[^ ]+) [^ ]+ [^ ]+ \[(?<time>[^\]]+)\] "(?<method>[^ ]+) (?<path>[^ ]+) [^ ]+" (?<code>[^ ]+) .+ ".+" "(?<ua>.+)" (?<response_time>[^ ]+)$/ time_format %d/%b/%Y:%T %z key_name message </match> <match parsed.**> type exec_filter command /usr/bin/perl /etc/td-agent/script/fluentd_exec_filter_simple.pl in_format json out_format msgpack tag exec.filtered </match> <match exec.**> type file path /var/log/td-agent/project/out/exec </match>
perlプログラム
ソース補足
$| = 1;
printするごとに強制的にフラッシュします($OUTPUT_AUTOFLUSH)
while ( my $json = <STDIN> ) { my $decode = eval { decode_json($json); }; next if ($@); print $mp->pack($decode); }
while文で標準入力を受け取ってjson形式でなければスルー、json形式だったらprintします
結果
結果はこんな感じです。
tailするアクセスログと、いったんperl経由でout_fileプラグインでファイルに出したjsonを載せときます
アクセスログ
172.21.65.97 - - [27/May/2014:14:41:18 +0900] "GET /mypage HTTP/1.1" 200 78958 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11" 297664 172.21.65.97 - - [27/May/2014:14:41:18 +0900] "GET /js/mypage/main.js?4 HTTP/1.1" 200 11760 "http://hogehoge.co.jp/mypage" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11" 346 172.21.65.97 - - [27/May/2014:14:41:18 +0900] "GET /js/libs/jquery.htmlaudio.js HTTP/1.1" 200 2079 "http://hogehoge.co.jp/mypage" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11" 334
/var/log/td-agent/project/out/exec
# pwd /var/log/td-agent/project/out # ls exec.20140527.b4fa5ac92e18cc51c # cat exec.20140527.b4fa5ac92e18cc51c 2014-05-27T14:41:20+09:00 exec.filtered {"code":"200","host":"172.21.65.97","method":"GET","path":"/mypage","response_time":"297664","ua":"Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11"} 2014-05-27T14:41:20+09:00 exec.filtered {"code":"200","host":"172.21.65.97","method":"GET","path":"/js/mypage/main.js","response_time":"346","ua":"Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11"} 2014-05-27T14:41:20+09:00 exec.filtered {"code":"200","host":"172.21.65.97","method":"GET","path":"/js/libs/jquery.htmlaudio.js","response_time":"334","ua":"Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11"}
うまく行きました!
デバッグ、動かない場合やエラーについて
exec_filterやってみたけど、
デバッグの仕方やエラーのときわかりにくいという記事をいくつか見かけたので
自分なりにやった感じをメモっておきます
動かない、エラーについて
動かないとかエラーの場合は当たり前ですがこのいずれかだと思います
- configの間違え
- perのエラー
- td-agent再起動忘れ
config間違えの場合はおおよそ/etc/init.d/td-agent start
やった直後のログ見ればわかります。perlのエラーの場合が若干わかりにくいですが、後述するデバッグなんかでうまくやりましょう
また、正常に動いていたperlを変更した場合はtd-agentを再起動しないと反映されません。当たり前ですね
一応、エラーの感じをのっけときます
perlをシンタックスエラーにしてみた場合
起動時にこんなエラーが出ます
2014-05-27 15:46:20 +0900 [error]: plugin/out_exec_filter.rb:327:run: exec_filter process unexpectedly exited. command="/usr/bin/perl /etc/td-agent/script/fluentd_exec_filter_simple.pl" ecode=65280
perlを実行時エラーにしてみた場合
アクセスログのparse後にこんな(上記と同じ)エラーが出ます
今回はprint $mp->pack($decode);
をprint $mp->pack();
にしてみました
2014-05-27 15:51:58 +0900 [error]: plugin/out_exec_filter.rb:327:run: exec_filter process unexpectedly exited. command="/usr/bin/perl /etc/td-agent/script/fluentd_exec_filter_simple.pl" ecode=65280
デバッグについて
デバッグ方法は何でも良いかと思いますがこんな感じでやれば良いかと。
1. perl単体で実行
- 概要
そのまんまですが、結果がわかりやすいようにwhile内のプログラムを変えました
- プログラム
- 結果
# perl fluentd_exec_filter_simple.pl ※入力待ちになるので何か打つ aaa not a json! at fluentd_exec_filter_simple02.pl line 16, <STDIN> line 1. ※jsonを打つとエラーは出ない {"name":"hoge"}
2. perlをtd-agentから呼ばれる想定でもう一つ用意したperlから実行
- 概要
上記の方法でも十分ですが、
アクセスログ並みのjsonを手で打って確認するのはしんどいので
out_exec_filterに指定するperlを他のperlからjson渡す&実行してみます
- プログラム
fluentd_exec_filter_simple.plはエラーの際に$jsonの内容を表示するように変えました
呼び出し側はこんな感じ。パイプで標準入力として渡すように呼び出します
- 結果
# ls -al drwxr-xr-x 3 root wheel 4096 5月 27 15:19 2014 . drwxr-xr-x 8 root wheel 4096 1月 15 20:51 2014 .. -rwxrwxrwx 1 td-agent td-agent 593 5月 27 15:17 2014 call_fluentd_exec_filter_simple.pl -rwxrwxrwx 1 td-agent td-agent 283 5月 27 14:19 2014 fluentd_exec_filter_simple.pl # perl call_fluentd_exec_filter_simple.pl #### not json sample#### [ERROR]not a json! [IN] mojiretu #### json sample####
3. perlに標準エラーを書き出すよう追記
- 概要
1でも2でもデバッグは十分できますが、
実際にtd-agentのconfigに指定してperlにゴリゴリ書いてみた結果、
動かない、意味わかんない、やめたいみたい。。orz...
みたいな感じにならないように標準エラーをファイルに書き出すようにしてみます
- 下準備(error.log) 下準備としてエラーを書き出すファイルを用意しておきます
# pwd /etc/td-agent/script # touch error.log # chown td-agent:td-agent error.log # chmod 777 error.log
補足しておくと、
chown
するのはtd-agentを起動した際にtd-agentが書き込めるように、
chmod
するのはperlコマンドで直接プログラム叩いたときに書き込めるように、
です。
td-agent起動かperlコマンド実行かのどちらかではエラーが出力されないかも
という本文ではないところで躓かないようにやっちゃいましょう。
- プログラム
out_exec_filterに指定するperlを修正します。こんな感じ(8~11行目)
fluentd_exec_filter_fix.pl
- 結果
fluentd_exec_filter_fix.plをわざとシンタックスエラーにしてperlコマンドで実行してみる
(13行目に$vvvv;
とだけ追記)
# perl fluentd_exec_filter_fix.pl Global symbol "$vvvv" requires explicit package name at fluentd_exec_filter_fix.pl line 13. Execution of fluentd_exec_filter_fix.pl aborted due to compilation errors. # cat error.log Global symbol "$vvvv" requires explicit package name at fluentd_exec_filter_fix.pl line 13. Execution of fluentd_exec_filter_fix.pl aborted due to compilation errors.
td-agent起動してみる(/etc/init.d/td-agent restart
)
td-agent.log
2014-05-27 18:10:04 +0900 [error]: plugin/out_exec_filter.rb:327:run: exec_filter process unexpectedly exited. command="/usr/bin/perl /etc/td-agent/script/fluentd_exec_filter_fix.pl" ecode=65280
error.log
# cat error.log ※↓perlコマンドで出たエラー Global symbol "$vvvv" requires explicit package name at fluentd_exec_filter_fix.pl line 13. Execution of fluentd_exec_filter_fix.pl aborted due to compilation errors. ※↓td-agent起動時に出たエラー Global symbol "$vvvv" requires explicit package name at /etc/td-agent/script/fluentd_exec_filter_fix.pl line 13. Execution of /etc/td-agent/script/fluentd_exec_filter_fix.pl aborted due to compilation errors.
ってことで、エラーが出るようになりました。
json形式かどうかにかかわらずwhileの直後にwarn "$json";
とかしておけば、
中身もerror.logに出るので本当にちゃんと値が来てるのか見たいときも良いですね!
例)jsonから静的ファイル名だけ抜き出してみる
ここからは説明なしでサンプルソースメインです。
こんな想定
config修正
- 受信側 exec_filterにfluentd_exec_filter_staticfile_list.plを指定
<match raw.project.apache.**> type parser remove_prefix raw add_prefix parsed format /^(?<host>[^ ]+) [^ ]+ [^ ]+ \[(?<time>[^\]]+)\] "(?<method>[^ ]+) (?<path>[^ ]+) [^ ]+" (?<code>[^ ]+) .+ ".+" "(?<ua>.+)" (?<response_time>[^ ]+)$/ time_format %d/%b/%Y:%T %z key_name message </match> <match parsed.**> type exec_filter command /usr/bin/perl /etc/td-agent/script/fluentd_exec_filter_staticfile_list.pl in_format json out_format msgpack tag exec.filtered </match> <match exec.**> type file path /var/log/td-agent/project/out/exec </match>
perlプログラム
結果
結果はこんな感じです。
アクセスログ
172.21.65.97 - - [27/May/2014:18:45:48 +0900] "GET /mypage HTTP/1.1" 200 79061 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11" 302246 172.21.65.97 - - [27/May/2014:18:45:48 +0900] "GET /js/project.js HTTP/1.1" 200 35020 "http://hogehoge.co.jp/mypage" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11" 1573 172.21.65.97 - - [27/May/2014:18:45:48 +0900] "GET /js/mypage/main.js HTTP/1.1" 200 11760 "http://hogehoge.co.jp/mypage" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11" 339 172.21.65.97 - - [27/May/2014:18:45:48 +0900] "GET /img/project/640/background.png HTTP/1.1" 200 99635 "http://hogehoge.co.jp/mypage" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11" 8231 172.21.65.97 - - [27/May/2014:18:45:48 +0900] "GET /img/project/640/base.png HTTP/1.1" 200 117854 "http://hogehoge.co.jp/mypage" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11" 13856
/var/log/td-agent/project/out/exec
# pwd /var/log/td-agent/project/out # ls static_file_list.20140527.b4fa5e7fcd972e80b # cat static_file_list.20140527.b4fa5e7fcd972e80b 2014-05-27T18:45:51+09:00 exec.filtered {"file_name":"project.js"} 2014-05-27T18:45:51+09:00 exec.filtered {"file_name":"main.js"} 2014-05-27T18:45:51+09:00 exec.filtered {"file_name":"background.png"} 2014-05-27T18:45:51+09:00 exec.filtered {"file_name":"base.png"}
/mypage
みたいなページアクセスは無視してファイル名っぽいのでだけfile_name
として出るようになりました!
まとめ
思った以上に長くなってしまいましたが、
out_exec_filterもいろいろできて面白いですね! \(^o^)/
また、下記のサイトがすごく参考になるかと思います!thx!