Coyote vs Loadbalancer

The Blog for the Rest of Us

FluentdでYAMAHA RTX1200のログを収集してみる

なんとなく大量に溜め込んでいたYAMAHA RTX1200のログを死蔵するのではなく、勉強に使ってみようということでFluentd + Elasticsearch + Kiabanaでイケイケビューなログビューを作りたいと思った。まずはFluentd編ということで。

使用用途として合ってるのか知らないけれども、うまく行けば自宅に物理で140本を超える可愛い女の子と付き合うゲームの整理にも使えないかなと思う。流石に100本を超えだすとわからないですね。

fluentdの流れ

適当に設定して済ませたかったが、やはり無理だった。なので、fluentdの処理の流れを理解する必要がある。

FluentdにてやってきたデータがどのようにしてDBなどに保存されるかの流れを公式のスライドで示す。

www.slideshare.net わかりやすいような、わかりにくいようなスライドだけども、軽く目を通しておくとこのあとの流れがわかる。

fluentdでは基本的に(1)データを取得(source, where all the data come from?)し(2)fluentdでそのデータに対して何をやらせるか(match, tell fluentd what to do)を記述していく。なお、このデータ取得からデータ処理の間でなにか別の処理をさせる(ex: ホスト名を追記する)といったこともできる(filter, Event processing pipeline)。

source : Where all the data come from

fluentdにデータ(=ログデータ)がどのように入力されるかを記述する。 難しい話ではなく、ログデータのを取得するために純粋にファイルで入力しますか、標準入力ですか、HTTP APIを叩きますかを指定するということ。
例えば、公式ドキュメントに例として以下のようなconfigが示されている。

# Receive events from 24224/tcp
# This is used by log forwarding and the fluent-cat command
<source>
  @type forward
  port 24224
</source>

# http://this.host:9880/myapp.access?json={"event":"data"}
<source>
  @type http
  port 9880
</source>

1個目の sourcefluent-cat という echo '{"message":"hello"}' | fluent-cat debug.log といった形でパイプでfluentdにログを飛ばすことができるコマンドからログを取得するという設定。2個目は http://this.host:9880/myapp.access?json={"event":"data"} というようなAPIエンドポイントをHTTPで叩いてログを取得するという設定。

ここまでで「何をするためにsourceを書くのか」はわかったが「じゃあ、どう書くのか」が実際にコンフィグを書く段になって困ってくる。そこで登場するのが公式ドキュメントの"Plugin Common Parameters"と'Input Plugins" 。基本的に、ここにあるプラグインを使って source を記述していく。

docs.fluentd.org

docs.fluentd.org

例えば、ファイルからログデータを取得するとなると in_tail プラグインを使う。

docs.fluentd.org

<source>
  @type tail
  path /var/log/httpd-access.log
  pos_file /var/log/td-agent/httpd-access.log.pos
  tag apache.access
  <parse>
    @type apache2
  </parse>
</source>

Fluentdではプラグイン@type で指定し、そのあとに各プラグイン依存の設定を行っていくのがお作法感がある。

Routing

ここで、fluentdではルーティング(Routing)という概念が存在する。ネットワークのルーティングと同じ概念。fluentdでは tag, time, record の3つの要素でルーティングを制御していく。これらのうち、最もよく使用する tag のみをここで述べる。 tagは.(ドット)で区切られた文字列でFluentd内部でのルーティングに使用される。例えば myapp.access といったようなフォーマットになる。なお、小文字の英数字とアンダースコアのみを使用することが推奨されている。 このtagに応じて、後ほどのファイル出力などを行う match 節などが実行されていく。

match : Tell fluentd what to do

source にて指定した方法で取得したデータをどう処理するかを tag 毎に指定していく。 この match 節でデータの出力などを行うので、このmatch 節で使用するプラグインをFluentdでは "output plugins" と呼ぶ。じゃあ、説の名前もmatchじゃなくてoutputにしろよ。

docs.fluentd.org

例えば、ファイルに出力したい場合には、 out_file プラグインを使います。 https://docs.fluentd.org/v1.0/articles/output-plugin-overview

<match pattern>
  @type file
  path /var/log/fluent/myapp
  compress gzip
  <buffer>
    timekey 1d
    timekey_use_utc true
    timekey_wait 10m
  </buffer>
</match>

filter : Event processing pipline

sourcematch の間でデータ処理をしたいときは、この filter を使う。だから、やることと節の名前が対応してないって。 フィルタは入力(source)と出力(match/output)の間にいくつでも挟むことができる。

filter で使用できるプラグインは以下の通り。

https://docs.fluentd.org/v1.0/articles/filter-plugin-overviewdocs.fluentd.org

また、parserにもまたプラグインがある。

docs.fluentd.org

例えば、 {"event": "data"} という入力を source で受け取り、 filter{"host_param" : "ホスト名"} を追加して、match でファイルとして出力するコンフィグは以下のようになる。(なお、fluentdはRubyで書かれているので、 Socket.gethostnameRubyのメソッド ref: https://docs.ruby-lang.org/ja/latest/method/Socket/s/gethostname.html )

# http://this.host:9880/myapp.access?json={"event":"data"}
<source>
  @type http
  port 9880
</source>

<filter myapp.access>
  @type record_transformer
  <record>
    host_param "#{Socket.gethostname}"
  </record>
</filter>

<match myapp.access>
  @type file
  path /var/log/fluent/access
</match>

label : bring order to chaos

label節自体はなくても動作するが、tagでの制御が複雑化していってしまうのを防ぐ事ができる。 なお、"label"自体は最初から入っているプラグインのパラメーターであるので、label節を使用する際には @ が頭に必要になってくる。
例えば、source にてtailプラグインで取得したデータを @SYSTEM というタグ付けをしたとするとき、 @SYSTEM というタグがつけられたデータの filtermatch をlabel節を使ってまとめると、以下のような形になる。

<source>
  @type forward
</source>

<source>
  @type tail
  @label @SYSTEM
</source>

<filter access.**>
  @type record_transformer
  <record>
    # ...
  </record>
</filter>
<match **>
  @type elasticsearch
  # ...
</match>

<label @SYSTEM>
  <filter var.log.middleware.**>
    @type grep
    # ...
  </filter>
  <match **>
    @type s3
    # ...
  </match>
</label>

とりあえず試す

既に自宅のRTX1200ではsyslogサーバにログを吐き出させていたので、それを素材にとりあえず試してみる。

インストール方法はドキュメントで様々なやり方を解説しているので、好きなのを選ぶ。

docs.fluentd.org

自分は面倒だったので、Dockerでやることにした。

hub.docker.com

適当に以下のようなファイル構成にしたディレクトリを作成

.
├── fluentd
│   └── fluent.conf
└── log
    ├── rtx1200.log
    └── rtx1200.log.org

2 directories, 3 files

このディレクトリ全体を /docker としてコンテナ内部でマウント docker run -it --rm -v /path/to/docker:/docker fluent/fluentd "/bin/sh"

fluentの公式イメージには最小限の構成しかないので、シェルがshしかない。まぁ、ホストでコンフィグいじったりして、コンテナ内部ではfluentdを実行するだけなので大きな問題はない。(というか、インタラクティブに実行することを想定しているものではない)

fluentdのインストール自体が終わったら、「Kibana|elasticsearchでイケイケでウェイウェイしたい」という気持ちを抑えて、とりあえずは以下の方針のようにシンプルな構成で試す。

結果として、以下のようなコンフィグを fluentd/fluent.conf に記述した。

# YAMAHA RTX
<source>
  @type tail
  @id yamaha_rtx_input_tail
  path /docker/log/rtx1200.log
  <parse>
    @type syslog
  </parse>
  tag yamaha.test.log
</source>

<match yamaha.test.*>
  @type file
  path /docker/yamaha_test.json
  <format>
    @type json
  </format>
</match>

ここでfluentでは実行前に source/path で指定した読み込むログファイルに存在するデータは処理されないので、まずは touch等で空のファイルを作成しておき、以下のコマンドで1回fluentを起動して、初期化処理が終わったら終了させる。 fluentd -c /docker/fluentd/fluent.conf -v その後、実際に読み込ませたいログファイルを置き、再度起動。そうすると、以下のような元のsyslog(抜粋、一部マスク済み)

Jul 22 06:25:23 192.168.12.1 PP[01] Rejected at IN(1012) filter: TCP  ***.***.***.**:***** > ***.***.**.**:****
Jul 22 06:51:52 192.168.12.1 PP[01] Rejected at IN(1030) filter: UDP ***.***.***.**:***** > ***.***.***.**:***** (DNS response)
Jul 22 07:00:00 192.168.12.1 [SCHEDULE] ntpdate ntp.nict.jp syslog
Jul 22 07:00:00 192.168.12.1 2018/07/22 07:00:00  +0second

がfluentdのsyslogプラグインで解析すると、以下のようなJSONになる。

{"host":"192.168.12.1","ident":"PP","pid":"01","message":"TCP ***.***.***.**:***** > ***.***.**.**:****"}
{"host":"192.168.12.1","ident":"PP","pid":"01","message":"UDP ***.***.***.**:***** > ***.***.***.**:***** (DNS response)"}
{"host":"192.168.12.1","ident":"","message":"[SCHEDULE] ntpdate ntp.nict.jp syslog"}
{"host":"192.168.12.1","ident":"2018/07/22","message":"00:00  +0second"}

一応、読み込めてJSON化できていることがわかる。ただ、RTX向けの設定を加えていないので重要な内容(ここでいうとRejectの内容)が message として丸められてしまっている。
このままでは困るので、filter を追加してmessageをもう少し細分化していく。

sourcematchなどの記法はさくらのナレッジがわかりやすく解説しているので、そちらを参照。但し、情報が少し古いのでそこは注意。新旧のdiffはFluentdの公式ドキュメントを参照してほしい(まぁ、でもQiitaやらの記事を見た感じではWARNが出るだけっぽい? ref:td-agentをv1からv2にバージョンアップした話 - Qiita)

knowledge.sakura.ad.jp

tail - Fluentd

file - Fluentd

上記を参考に、方針に沿ってやりたいことを/etc/td-agent/td-agent.confの末尾に書いてみる。結果は以下の感じ。

書き終わったら/etc/init.d/td-agenet configtestで書き損じがないかチェックしてから/etc/init.d/td-agenet restartでリスタート

正しくファイル等が配置されていれば、結果は以下のような感じになる。

fluentdでパースして吐き出せはしたが、だいぶ虚無な感じになっているのがわかる。無ですね。このままではだめそう。
Grokフィルターというものを使う例が以下のサイトにあるが、正規表現ゴリゴリ書きでやってみたいと思う。理由は様々です(主に仕事関係で慣れておきたいので)。面倒な人は素直に既にあるのを利用した方がいいかも(戒め)

mamori017.hatenablog.com

正規表現をゴリゴリ書く

まず、いちいち/etc/td-agent/td-agent.confに書いて云々なんてやってられないので、Fluentdの正規表現エディタを使う。

Fluentular: a Fluentd regular expression editor
なお、このエディタはHerokuの無料枠でやってるらしく、稀に落ちているらしい(ref:Fluentdの正規表現を攻略する - Qiita)。Dockerイメージがあるそうなので、落ちてた場合にはそっちを使う方がいいかも(GitHub - tomohiro/fluentular: Fluentular is a Fluentd regular expression editor)。

書き方の参考には以下のサイトが非常に有用なので、困ったら見てみるべき。

blog.glidenote.com

また、Ruby自体の正規表現の書き方は以下の公式ドキュメントを参考。

docs.ruby-lang.org

日付を取り出す。

まずはログから日付を取り出す。ここで、RTX1200のログにおける日付のフォーマットは以下のような感じになっている。

Jul  1 00:00:00 192.168.12.1 [SCHEDULE] ntpdate ntp.nict.jp syslog
Jul 22 07:00:00 192.168.12.1 [SCHEDULE] ntpdate ntp.nict.jp syslog

まず、日付はログの行頭に現れるので、行頭にマッチする^をつける。
次に月がJun, Julのようにアルファベット3文字の省略表現となっているので、書くべき正規表現Rubyのドキュメントでいうところの単語構成文字\wが3回連続({3})するものを表す \w{3}となる。
そして日が2桁の場合は普通に22のように表すが、1桁の場合には2桁目をスペースでパディングして1のようにしている。そのため、書くべき正規表現はスペース(\s)が0個、あるいは1個({0, 1})のあとに10進数(\d)が1個あるいは2個({1, 2})現れるものを表す\s{0, 1}\d{1, 2}となる。
最後に時間は日付のあとにスペース1個開けてから時間、分、秒ともに十進数2桁(\d{2})が:で区切られて表現されているので、書くべき正規表現\s\d{2}:\d{2}:\d{2}となる(まぁ、\s(\d{2}:){2}\dでもいいけど)

以上をまとめると、結果としてFluentdで書くべき正規表現

^(?<time>\w{3}\s{1,2}\d{1,2}\s\d{2}:\d{2}:\d{2})

となる。

ここで、Fluentdでは時間timeは特別な扱いをされるので(どうされるかはドキュメント参照:https://docs.fluentd.org/v1.0/articles/parser_regexp)、上記で取り出した日付のフォーマットに合わせたRubyのTime formatをtime_formatパラメータとして記載する。実際に書くと、以下のようになるはず。

%b %e %T

実際に先程のエディタに書けると以下のような感じになる(URLパラメータにすべて持たせていてすごい)

http://fluentular.herokuapp.com/parse?regexp=%5E%28%3F%3Ctime%3E%5Cw%7B3%7D%5Cs%7B1%2C2%7D%5Cd%7B1%2C2%7D%5Cs%5Cd%7B2%7D%3A%5Cd%7B2%7D%3A%5Cd%7B2%7D%29&input=Jul++1+01%3A06%3A56+192.168.12.1+LAN1%3A+PORT1+link+up+%281000BASE-T+Full+Duplex%29&time_format=%25b+%25e+%25T

ホスト名を取り出す

まぁ、今回はホスト名ではなくRTXの持っているIPアドレスなのだけれども。syslog的にはこれをホスト名と呼ぶらしいので、それに則ります。
これはIPv4のアドレスなので、日付に比べれば大変楽。大体いつもIPv4正規表現で使ってる以下を使う。

(?:(?:25[0-5]|2[0-4][0-9]|[01]?[0-9][0-9]?)\.){3}(?:25[0-5]|2[0-4][0-9]|[01]?[0-9][0-9]?)

(ref:IPアドレスの正規表現 [IPv4] – 黒川仁の文具堂ブログ三昧)

Fluentdに記録する際には、このRTXのIPアドレスhost というkeyで登録したいので、結果としてFluentdで書くべき正規表現は今までのと合わせて

^(?<time>\w{3}\s{1,2}\d{1,2}\s\d{2}:\d{2}:\d{2}) (?<host>(?:(?:25[0-5]|2[0-4][0-9]|[01]?[0-9][0-9]?)\.){3}(?:25[0-5]|2[0-4][0-9]|[01]?[0-9][0-9]?))

となる。

http://fluentular.herokuapp.com/parse?regexp=%5E%28%3F%3Ctime%3E%5Cw%7B3%7D%5Cs%7B1%2C2%7D%5Cd%7B1%2C2%7D%5Cs%5Cd%7B2%7D%3A%5Cd%7B2%7D%3A%5Cd%7B2%7D%29+%28%3F%3Chost%3E%28%3F%3A%28%3F%3A25%5B0-5%5D%7C2%5B0-4%5D%5B0-9%5D%7C%5B01%5D%3F%5B0-9%5D%5B0-9%5D%3F%29%5C.%29%7B3%7D%28%3F%3A25%5B0-5%5D%7C2%5B0-4%5D%5B0-9%5D%7C%5B01%5D%3F%5B0-9%5D%5B0-9%5D%3F%29%29&input=Jul++1+01%3A06%3A56+192.168.12.1+LAN1%3A+PORT1+link+up+%281000BASE-T+Full+Duplex%29&time_format=%25b+%25e+%25T

configtestで記法エラーは出ないが[FAIL] td-agent ... failed!だけ出てくる

ほとんどのケースで設定ファイルで指定したファイル出力先のパーミッションが不適切な場合にこうなってしまう。「(パーミッションがだめだと)そう言えや」感がすごい。

Example

/etc/td-agent/td-agent.conf

# YAMAHA RTX
<source>
  @type tail
  @id yamaha_rtx_input_tail
  path /home/vagrant/log/rtx1200.log
  format syslog
  tag yamaha.test.log
</source>

<match yamaha.test.*>
  @type file
  path /home/vagrant/fluentd_test/yamaha_test.json
  <format>
    @type json
  </format>
</match>

このとき、<match>/home/vagrant/fluentd_test/を指定しているので、このディレクトリのパーミッションが不適切だったりすると[FAIL] td-agent ... failed!だけ出てくる。いい感じに設定してあげよう。