Lubuntu 16.04 で fluentd ( td-agent ) を利用する 2 – nginx のアクセスログをパース

Contents

1 概要
2 手順
- 2.1 監視対象ログのパーミッション設定を変更する
- 2.2 fluentd の設定追加
3 動作確認
4 トラブルシューティング
5 参考サイト

概要

fluentd のインストールと単体動作確認は前回終わらせましたので、今回は nginx のアクセスログをパースしていきたいと思います。

手順

監視対象ログのパーミッション設定を変更する

td-agent は、td-agent ユーザとして実行されています。


$ ps aux | grep td-
td-agent  1639  0.0  0.3 122772 31844 ?        Sl   10月21   0:00 /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid
td-agent  1644  0.0  0.8 168340 66112 ?        Sl   10月21   3:19 /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --daemon /var/run/td-agent/td-agent.pid

そのため、td-agent ユーザがログファイルの読み取りができるようにパーミッションを変更します。


$ sudo chmod 644 /var/log/nginx/*

logrotate された際のパーミッション設定も変更しておきます。


$ sudo vi /etc/logrotate.d/nginx
/var/log/nginx/*.log {
        daily
        missingok
        rotate 14
        compress
        delaycompress
        notifempty
        create 0644 www-data adm
        sharedscripts
        prerotate
                if [ -d /etc/logrotate.d/httpd-prerotate ]; then \
                        run-parts /etc/logrotate.d/httpd-prerotate; \
                fi \
        endscript
        postrotate
                invoke-rc.d nginx rotate >/dev/null 2>&1
        endscript
}

fluentd の設定追加

fluentd ( td-agent ) の設定をします。問題となるのは、format として指定する正規表現くらいでしょう。これは監視対象となるログの文字列によって変わってくるため、その都度正規表現を書くのが面倒ですなぁ。これは如何ともし難いものであるか。と思ったらすでに実践されている方がいらっしゃいました。fluentular を利用すると良さそう！なのだが、部分的にはうまくいくのだけど、正しくても結果表示がされなかったり、Internal Server Error が返されたりする感じ。特定の文字列から正規表現を提案してくれるようなウェブサービスがあったら便利だなぁつくれたらつくりたいな。。パッと思い浮かぶのは形態要素解析なのですが、解体要素っつてもこれは名詞、これは動詞のような語彙の情報が前提にある。しかし、ログは違うからパターンマッチの「種」として人間が補助するのはデリミタくらいにしてそこから斬りさばいていくような方式なら実装できるかなぁ、いや無理かなぁなどと考える。

format 以外の注意点として、<source> タグ中の tag で指定した名前（この例では nginx.access ）と <match> タグでの指定は同一にする（この例では <match nginx.access> ）必要がある。


$ sudo vi /etc/td-agent/td-agent.conf
# nginx access.log
<source>
  type tail
  tag nginx.access
  path /var/log/nginx/access.log
  pos_file /var/log/td-agent/nginx-access.log.pos
  format /^(?<remote>[^ ]*) (?<host>[^ ]*) (?<user>[^ ]*) \[(?<time>[^\]]*)\] "(?<method>\S+)(?: +(?<path>[^ ]*) +\S*)?" (?<code>[^ ]*) (?<size>[^ ]*)(?: "(?<referer>[^\"]*)" "(?<agent>[^\"]*)" "(?<forwarder>[^\"]*)")?/
  time_format %d/%b/%Y:%H:%M:%S %z
</source>

<match nginx.access>
  type file
  path /tmp/test
</match>

動作確認

td-agent を再起動し、nginx にアクセスがあると以下のような感じでアクセスログがパースされて JSON 形式で必要な key / value が確認できていれば問題ありません。このとき、/tmp/test にログが出力されるのではなく、/tmp/test.timestamp.hash のような名前のファイルに出力されます。<match> タグで暗黙に buffer_path /tmp/test.* と定義されているようです。


$ sudo tail -f /tmp/test.20161027.b53fd26283b59abc3
2016-10-27T14:55:37+09:00       nginx.access    {"remote":"111.222.333.444","host":"-","user":"-","method":"GET","path":"/wp-content/plugins/jetpack/_inc/jquery.jetpack-resize.js","code":"304","size":"95"}
2016-10-27T14:55:37+09:00       nginx.access    {"remote":"111.222.333.444","host":"-","user":"-","method":"GET","path":"/wp-content/plugins/jetpack/_inc/jquery.inview.js","code":"304","size":"95"}
2016-10-27T14:55:37+09:00       nginx.access    {"remote":"111.222.333.444","host":"-","user":"-","method":"GET","path":"/wp-content/plugins/jetpack/modules/likes/queuehandler.js","code":"304","size":"95"}
2016-10-27T14:55:37+09:00       nginx.access    {"remote":"111.222.333.444","host":"-","user":"-","method":"GET","path":"/wp-content/plugins/jetpack/modules/sharedaddy/sharing.js","code":"304","size":"95"}
2016-10-27T14:55:38+09:00       nginx.access    {"remote":"111.222.333.444","host":"-","user":"-","method":"GET","path":"/wp-content/uploads/2016/10/newrsynclogo.jpg","code":"304","size":"0"}
2016-10-27T14:55:46+09:00       nginx.access    {"remote":"111.222.333.444","host":"-","user":"-","method":"GET","path":"/security/ssl-certificate/3050/?relatedposts=1","code":"200","size":"2239"}

トラブルシューティング

正規表現のミス

format で正規表現のミスがあると以下のようにサービスが再起動できず、syslog にエラーが記録されます。


$ sudo /etc/init.d/td-agent restart
[....] Restarting td-agent (via systemctl): td-agent.serviceJob for td-agent.service failed because the control process exited with error code. See "systemctl status td-agent.service" and "journalctl -xe" for details.
 failed!

syslog に出力されるエラーの例


Oct 27 00:11:54 vm-nfj-201 td-agent[21782]: Starting td-agent: 2016-10-27 00:11:54 +0900 [error]: fluent/supervisor.rb:373:rescue in main_process: config error file="/etc/td-agent/td-agent.conf" error="Invalid regexp '^(?<remote>[^ ]*) (?<host>[^ ]*) (?<user>[^ ]*) \\[?<time>[^\\]]*)\\] \"(?<method>\\S+)(?: +(?<path>[^ ]*) +\\S*)?\" (?<code>[^ ]*) (?<size>[^ ]*)(?: \"(?<referer>[^\\\"]*)\" \"(?<agent>[^\\\"]*)\" \"(?<forwarder>[^\\\"]*)\")?': unmatched close parenthesis: /^(?<remote>[^ ]*) (?<host>[^ ]*) (?<user>[^ ]*) \\[?<time>[^\\]]*)\\] \"(?<method>\\S+)(?: +(?<path>[^ ]*) +\\S*)?\" (?<code>[^ ]*) (?<size>[^ ]*)(?: \"(?<referer>[^\\\"]*)\" \"(?<agent>[^\\\"]*)\" \"(?<forwarder>[^\\\"]*)\")?/"

ログが出力されない

td-agent.log を確認すると permisson error が出ている場合は監視対象ログのパーミッションを見直します。644 であれば、少なくとも td-agent に読み取り権限があるはず。


$ sudo less /var/log/td-agent/td-agent.log
2016-10-27 00:32:51 +0900 [error]: Permission denied @ rb_file_s_stat - /var/log/nginx/access.log
  2016-10-27 00:32:51 +0900 [error]: suppressed same stacktrace

td-agent ユーザでのチェック

Lubuntu 16.04 では、fluentd をインストールすると td-agent というユーザが作られる。設定は正しい筈だが、/var/log/td-agent/td-agent.log や /var/log/syslog の出力を見ても原因がわからない場合に sudo で td-agent ユーザになると切り分けがつくことがあった。一旦、td-agent を停止してから sudo で td-agent になってみると以下のような出力がでてリアルタイムに待ち受け状態となる。つまり、td-agent 自身がどのように起動しているかや受信している情報を目視確認できるので意外と使える方法ではなかろうか。抜けるときは、Ctrl+C で終了できます。


$ /etc/init.d/td-agent stop
$ sudo td-agent
2016-10-27 14:58:08 +0900 [info]: reading config file path="/etc/td-agent/td-agent.conf"
2016-10-27 14:58:08 +0900 [info]: starting fluentd-0.12.29
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-mixin-config-placeholders' version '0.4.0'
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-mixin-plaintextformatter' version '0.2.6'
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-plugin-kafka' version '0.3.1'
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-plugin-mongo' version '0.7.15'
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-plugin-rewrite-tag-filter' version '1.5.5'
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-plugin-s3' version '0.7.1'
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-plugin-scribe' version '0.10.14'
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-plugin-td' version '0.10.29'
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-plugin-td-monitoring' version '0.2.2'
2016-10-27 14:58:08 +0900 [info]: gem 'fluent-plugin-webhdfs' version '0.4.2'
2016-10-27 14:58:08 +0900 [info]: gem 'fluentd' version '0.12.29'
2016-10-27 14:58:08 +0900 [info]: adding match pattern="td.*.*" type="tdlog"
2016-10-27 14:58:09 +0900 [info]: adding match pattern="debug.**" type="stdout"
2016-10-27 14:58:09 +0900 [info]: adding match pattern="nginx.access" type="file"
2016-10-27 14:58:09 +0900 [info]: adding source type="forward"
2016-10-27 14:58:09 +0900 [info]: adding source type="http"
2016-10-27 14:58:09 +0900 [info]: adding source type="debug_agent"
2016-10-27 14:58:09 +0900 [info]: adding source type="tail"
2016-10-27 14:58:09 +0900 [info]: using configuration file: <ROOT>
  <match td.*.*>
    @type tdlog
    apikey xxxxxx
    auto_create_table 
    buffer_type file
    buffer_path /var/log/td-agent/buffer/td
    buffer_chunk_limit 33554432
    <secondary>
      @type file
      path /var/log/td-agent/failed_records
      buffer_path /var/log/td-agent/failed_records.*
    </secondary>
  </match>
  <match debug.**>
    @type stdout
  </match>
  <source>
    @type forward
  </source>
  <source>
    @type http
    port 8888
  </source>
  <source>
    @type debug_agent
    bind 127.0.0.1
    port 24230
  </source>
  <source>
    type tail
    tag nginx.access
    path /var/log/nginx/access.log
    pos_file /var/log/td-agent/nginx-access.log.pos
    format /^(?<remote>[^ ]*) (?<host>[^ ]*) (?<user>[^ ]*) \[(?<time>[^\]]*)\] "(?<method>\S+)(?: +(?<path>[^ ]*) +\S*)?" (?<code>[^ ]*) (?<size>[^ ]*)(?: "(?<referer>[^\"]*)" "(?<agent>[^\"]*)" "(?<forwarder>[^\"]*)")?/
    time_format %d/%b/%Y:%H:%M:%S %z
  </source>
  <match nginx.access>
    type file
    path /tmp/test
    buffer_path /tmp/test.*
  </match>
</ROOT>
2016-10-27 14:58:09 +0900 [info]: listening fluent socket on 0.0.0.0:24224
2016-10-27 14:58:09 +0900 [info]: listening dRuby uri="druby://127.0.0.1:24230" object="Engine"
2016-10-27 14:58:09 +0900 [info]: following tail of /var/log/nginx/access.log

参考サイト

Thanks.

Glide Note – fluentdのformat(正規表現)の作り方について試行錯誤中 #fluentd by Akira Maeda
Tomohiro/fluentular @GitHub – by Tomohiro TAIRA
Fluentular v0.14.6 – a Fluentd regular expression editor @herokuapp – by Tomohiro TAIRA

2020年5月
月	火	水	木	金	土	日
				1	2	3
4	5	6	7	8	9	10
11	12	13	14	15	16	17
18	19	20	21	22	23	24
25	26	27	28	29	30	31