nginx でのログ操作($time_iso8601 ・ Fluentd)

概要

nginxのアクセスログを月日が分割されるようにする

結論-2014/09/25追記

http://wiki.nginx.org/LogRotation
公式にlogrotateの方法があり、これを真似てbashで月日を分割するようにした
いろいろ試したが、”time_iso8601″ variable が利用できない場合は自作が一番良さそう

その前に

root@hostname:/home/shimizu# vi /etc/nginx/sites-enabled/default
=====
access_log /var/log/nginx/default/access.log;
=====
root@hostname:/home/shimizu# rm /var/log/nginx/default/access.log
root@hostname:/home/shimizu# /etc/init.d/nginx start # もしくは reload でaccess.log が作成される
root@hostname:/home/shimizu# ls -al /var/log/nginx/default/access.log
-rw-r--r-- 1 root root 385  7月 29 20:42 /var/log/nginx/default/access.log

nginx機能で実現

root@hostname:/home/shimizu# nginx -v
nginx version: nginx/1.6.0

root@hostname:/home/shimizu# vi /etc/nginx/sites-enabled/default
=====
if ($time_iso8601 ~ "^(\d{4})-(\d{2})-(\d{2})") {
    set $year $1;
    set $month $2;
    set $day $3;
}
=====
root@hostname:/home/shimizu# ls -al /var/log/nginx/default/
合計 20
drwxr-xr-x 2 www-data adm      4096  7月 29 20:46 .
drwxr-x--- 4 www-data adm      4096  7月 29 20:45 ..
-rw-r--r-- 1 www-data www-data  385  7月 29 20:46 2014-07-29-access.log # www-data権限で作成される
-rw-r--r-- 1 www-data www-data  385  7月 29 20:46 2014-07-29T20:46:32+09:00-access.log
-rw-r--r-- 1 root     root      385  7月 29 20:42 access.log 

root@hostname:/home/shimizu# ps aufx | grep [n]ginx
root      2988  0.0  0.3 132300  2264 ?        Ss   20:46   0:00 nginx: master process /usr/sbin/nginx
www-data  2992  0.0  0.5 132660  3628 ?        S    20:46   0:00  \_ nginx: worker process

nginx: [emerg] unknown “time_iso8601” variable

上のエラーが出た場合は、バージョンが違う可能性があり
In the modern nginx versions variables $status (1.3.2, 1.2.2), $bytes_sent (1.3.8, 1.2.5), $connection (1.3.8, 1.2.5), $connection_requests (1.3.8, 1.2.5), $msec (1.3.9, 1.2.6), $request_time (1.3.9, 1.2.6), $pipe (1.3.12, 1.2.7), $request_length (1.3.12, 1.2.7), $time_iso8601 (1.3.12, 1.2.7), and $time_local (1.3.12, 1.2.7) are also available as common variables.

nginx() + Fluentd

Fluentdとは

柔軟なログ収集することが可能
2014-07-29_215403

インストール

td-agent をインストールする。td-agent とは Treasure Data 社が作成している Fluentd安定版の配布パッケージのこと
ruby環境を内包しているので、システムのruby環境に依存せず非破壊的に導入可能
公式サイトに debian/Ubuntu のインストール手順があるが、サポートされておらず、多くの人がはまっている模様。。

root@hostname:/home/shimizu# vi /etc/apt/sources.list # 以下を追記する
=====
# fluentd(td-agent)
deb http://packages.treasure-data.com/debian/ lucid contrib
=====
root@hostname:/home/shimizu# aptitude update
(中略)
W: GPG エラー: http://packages.treasure-data.com lucid Release: 公開鍵を利用できないため、以下の署名は検証できませんでした: NO_PUBKEY 1093DB45A12E206F

root@hostname:/home/shimizu# wget http://packages.treasure-data.com/debian/RPM-GPG-KEY-td-agent
--2014-07-29 22:31:28--  http://packages.treasure-data.com/debian/RPM-GPG-KEY-td-agent
packages.treasure-data.com (packages.treasure-data.com) をDNSに問いあわせています... 54.230.233.15, 54.230.234.52, 54.230.233.27, ...
packages.treasure-data.com (packages.treasure-data.com)|54.230.233.15|:80 に接続しています... 接続しました。
HTTP による接続要求を送信しました、応答を待っています... 200 OK
長さ: 934 [binary/octet-stream]
`RPM-GPG-KEY-td-agent' に保存中

100%[===========================================================>] 934         --.-K/s 時間 0s

2014-07-29 22:31:29 (1740 GB/s) - `RPM-GPG-KEY-td-agent' へ保存完了 [934/934]

root@hostname:/home/shimizu# apt-key add RPM-GPG-KEY-td-agent
OK
root@hostname:/home/shimizu# rm RPM-GPG-KEY-td-agent
root@hostname:/home/shimizu# aptitude install td-agent
以下の新規パッケージがインストールされます:
  td-agent{b}
以下のパッケージが推奨されていますがインストールされません:
  ntp
更新: 0 個、新規インストール: 1 個、削除: 0 個、保留: 0 個。
60.9 M バイトのアーカイブを取得する必要があります。展開後に 107 M バイトのディスク領域が新たに消費されます。
以下のパッケージには満たされていない依存関係があります:
 td-agent : 依存: libssl0.9.8 (>= 0.9.8k-1)[仮想パッケージです]
            依存: libyaml-0-2 [インストールされません]
以下のアクションでこれらの依存関係の問題は解決されます:

     以下のパッケージを現在のバージョンに一時固定する:
1)     td-agent [インストールされていません]



この解決方法を受け入れますか? [Y/n/q/?]n

*** 利用可能な解決方法がこれ以上ありません。 ***

以下のアクションでこれらの依存関係の問題は解決されます:

     以下のパッケージを現在のバージョンに一時固定する:
1)     td-agent [インストールされていません]



この解決方法を受け入れますか? [Y/n/q/?]n

t
root@hostname:/home/shimizu# wget -d http://ftp.jp.debian.org/debian/pool/main/o/openssl/libssl0.9.8_0.9.8o-4squeeze14_amd64.deb
DEBUG output created by Wget 1.13.4 on linux-gnu.

URI encoding = `UTF-8'
--2014-07-29 23:07:36--  http://ftp.jp.debian.org/debian/pool/main/o/openssl/libssl0.9.8_0.9.8o-4squeeze14_amd64.deb
ftp.jp.debian.org (ftp.jp.debian.org) をDNSに問いあわせています... 133.242.8.20
Caching ftp.jp.debian.org => 133.242.8.20
ftp.jp.debian.org (ftp.jp.debian.org)|133.242.8.20|:80 に接続しています... 接続しました。
Created socket 3.
Releasing 0x0000000000abc8c0 (new refcount 1).

---request begin---
GET /debian/pool/main/o/openssl/libssl0.9.8_0.9.8o-4squeeze14_amd64.deb HTTP/1.1
User-Agent: Wget/1.13.4 (linux-gnu)
Accept: */*
Host: ftp.jp.debian.org
Connection: Keep-Alive

---request end---
HTTP による接続要求を送信しました、応答を待っています...
---response begin---
HTTP/1.1 200 OK
Date: Tue, 29 Jul 2014 14:07:36 GMT
Server: Apache/2.2.22 (Debian)
Last-Modified: Wed, 13 Feb 2013 20:15:13 GMT
ETag: "20856c5-f49ce-4d5a0ccb8f640"
Accept-Ranges: bytes
Content-Length: 1001934
Keep-Alive: timeout=5, max=100
Connection: Keep-Alive
Content-Type: application/x-debian-package

---response end---
200 OK
Registered socket 3 for persistent reuse.
長さ: 1001934 (978K) [application/x-debian-package]
`libssl0.9.8_0.9.8o-4squeeze14_amd64.deb' に保存中

100%[===========================================================>] 1,001,934   2.59M/s 時間 0.4s

2014-07-29 23:07:36 (2.59 MB/s) - `libssl0.9.8_0.9.8o-4squeeze14_amd64.deb' へ保存完了 [1001934/1001934]

root@hostname:/home/shimizu# dpkg -i libssl0.9.8_0.9.8o-4squeeze14_amd64.deb
以前に未選択のパッケージ libssl0.9.8 を選択しています。
(データベースを読み込んでいます ... 現在 68478 個のファイルとディレクトリがインストールされています。)
(libssl0.9.8_0.9.8o-4squeeze14_amd64.deb から) libssl0.9.8 を展開しています...
libssl0.9.8 (0.9.8o-4squeeze14) を設定しています ...

root@hostname:/home/shimizu# aptitude search libssl
p   libssl-dev                                 - 開発用 SSL ライブラリ、ヘッダおよびドキュメント
p   libssl-doc                                 - SSL development documentation documentation
p   libssl-ocaml                               - OCaml bindings for OpenSSL (runtime)
p   libssl-ocaml-dev                           - OCaml bindings for OpenSSL
v   libssl-ocaml-dev-l8h98                     -
v   libssl-ocaml-l8h98                         -
i   libssl0.9.8                                - SSL shared libraries
i   libssl1.0.0                                - SSL 共有ライブラリ
p   libssl1.0.0-dbg                            - libssl および libcrypto 用シンボルテーブル
p   libsslcommon2                              - enterprise messaging system - common SSL libraries
p   libsslcommon2-dev                          - enterprise messaging system - common SSL development

root@hostname:/home/shimizu# aptitude install td-agent
以下の新規パッケージがインストールされます:
  td-agent
更新: 0 個、新規インストール: 1 個、削除: 0 個、保留: 0 個。
60.9 M バイトのアーカイブを取得する必要があります。展開後に 107 M バイトのディスク領域が新たに消費されます。
(中略)
(.../td-agent_1.1.20-1_amd64.deb から) td-agent を展開しています...
td-agent (1.1.20-1) を設定しています ...
システムユーザ `td-agent' (UID 114) を追加しています...
新しいグループ `td-agent' (GID 121) を追加しています...
新しいユーザ `td-agent' (UID 114) をグループ `td-agent' に追加しています...
ホームディレクトリ `/home/td-agent' は作成しません。
Installing default conffile /etc/td-agent/td-agent.conf ...
[ ok ] Starting td-agent : td-agent.

nginxをLTSV形式に

Labeled Tab-serapated Valuesの略で、parse処理がとてもしやすい

root@hostname:/home/shimizu# vi /etc/nginx/nginx.conf # httpコンテキストに追記
=====
log_format ltsv 'time:$time_iso8601\t'
        'remote_addr:$remote_addr\t'
        'request_method:$request_method\t'
        'request_length:$request_length\t'
        'request_uri:$request_uri\t'
        'https:$https\t'
        'uri:$uri\t'
        'query_string:$query_string\t'
        'status:$status\t'
        'bytes_sent:$bytes_sent\t'
        'body_bytes_sent:$body_bytes_sent\t'
        'referer:$http_referer\t'
        'useragent:$http_user_agent\t'
        'forwardedfor:$http_x_forwarded_for\t'
        'request_time:$request_time\t'
        'upstream_response_time:$upstream_response_time\t'
        'host:$host';
=====

root@hostname:/home/shimizu# vi /etc/nginx/sites-enabled/default
=====
access_log  /var/log/nginx/default/access.log ltsv;
=====
root@hostname:/home/shimizu# nginx -t
nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
nginx: configuration file /etc/nginx/nginx.conf test is successful
root@hostname:/home/shimizu# /etc/init.d/nginx reload
Reloading nginx configuration: nginx.
root@hostname:/home/shimizu# tail -f /var/log/nginx/default/access.log
time:2014-07-30T22:08:53+09:00  remote_addr:11.11.11.111        request_method:GET      request_length:312    request_uri:/favicon.ico https:  uri:/favicon.ico        query_string:-  status:404      bytes_sent:383  body_bytes_sent:198    referer:-       useragent:Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/36.0.1985.125 Safari/537.36        forwardedfor:-  request_time:0.000      upstream_response_time:-       host:49.212.204.46

td-agentの設定

root@hostname:/home/shimizu# which td-agent
/usr/sbin/td-agent
root@hostname:/home/shimizu# lv /usr/sbin/td-agent
root@hostname:/home/shimizu# cat /usr/sbin/td-agent # 設定ファイルの場所が記載されている
#!/usr/lib/fluent/ruby/bin/ruby
ENV["GEM_HOME"]="/usr/lib/fluent/ruby/lib/ruby/gems/1.9.1/"
ENV["GEM_PATH"]="/usr/lib/fluent/ruby/lib/ruby/gems/1.9.1/"
ENV["FLUENT_CONF"]="/etc/td-agent/td-agent.conf"
ENV["FLUENT_PLUGIN"]="/etc/td-agent/plugin"
ENV["FLUENT_SOCKET"]="/var/run/td-agent/td-agent.sock"
load "/usr/lib/fluent/ruby/bin/fluentd"

root@hostname:/home/shimizu# cp /etc/td-agent/td-agent.conf /etc/td-agent/td-agent.conf_
root@hostname:/home/shimizu# vi /etc/td-agent/td-agent.conf
=====
# Input
<source>
  type tail
  path /var/log/nginx/default/access.log
  tag nginx.access
  pos_file /var/log/td-agent/buffer/access.log.pos
  format ltsv
</source>

# Output
<match nginx.access>
  type file
  path /var/log/td-agent/access.log
</match>

#<match nginx.access>
#  type forward
#  buffer_type memory
#  buffer_chunk_limit 256m
#  buffer_queue_limit 128
#  flush_interval 5s
#  <server>
#    # ログの送信先IPアドレス
#    host 192.168.1.100
#    port 24224 # default port : TCPで送信、UDPで監視
#  </server>
#</match>
=====
root@hostname:/var/log/td-agent# /etc/init.d/td-agent restart
[ ok ] Restarting td-agent: td-agent.
root@hostname:/var/log/td-agent# ls -al /var/log/td-agent/
合計 48
drwxr-xr-x  4 td-agent td-agent  4096  7月 31 00:10 .
drwxr-xr-x 20 root     root      4096  7月 30 06:25 ..
-rw-r--r--  1 td-agent td-agent  1356  7月 31 00:01 access.log.20140731.b4ff6a69443049725
drwxrwxrwx  2 td-agent td-agent  4096  7月 30 23:58 buffer
-rw-r--r--  1 td-agent td-agent 17104  7月 31 00:15 td-agent.log

[error]: unexpected error error_class=Errno::EACCES error=#

/var/log/td-agent/td-agent.log にて出たエラー、pos_fileを権限のない場所におくと起動しないため注意

todo

http://blog.star-flare.com/posts/2013-10-11/1160/
path %Y/%m/%d/%H/blog.star-flare.com.access.log

参考URL

http://www.cambus.net/log-rotation-directly-within-nginx-configuration-file/
http://nginx.org/en/docs/http/ngx_http_log_module.html
https://packages.debian.org/squeeze/amd64/libssl0.9.8/download
http://docs.fluentd.org/ja/articles/install-by-deb
https://sites.google.com/site/itsikao/it-memo/fluentd
http://mtoyoshi.hateblo.jp/entry/2013/06/22/235408