Windows でログ収集データ化ツール logstash を動かす

ログ収集してデータ化するツールとして、fluentd という有名なツールがあるが、今回は、ほぼ同じ事ができて、Windows でのインストールや設定が、より簡単な logstash を動かす。

インストールと利用方法、特に、正規表現とRubyスクリプトによる入力文字列のパースとフィールド追加、Windowsでのバックグラウンド起動について扱う。

logstash も動作のエンジンには、Ruby スクリプトを利用しているが、JRubyが同梱されているので、Javaさえインストールされていれば、Ruby をインストールしていなくても、パッケージをダウンロードし展開したら、すぐに利用できる。
fluentd と比べると、プラグインが若干少ないが、必要十分なプラグインは揃っているし、比較的簡単なRubyスクリプトを書けば、入力も出力も拡張できる。

logstash のダウンロードと動作テスト

logstash を以下からダウンロードする。
https://download.elastic.co/logstash/logstash/logstash-1.4.2.zip

任意のフォルダ（今回は、C:\Apps\logstash-1.4.2 とする）に展開する。

起動バッチファイルの修正

展開したフォルダに移動し、コマンドプロンプトから bin\logstash を使って logstash を起動できる。
が、簡単な動作テストをするときに、コマンドラインオプションで設定しようとすると、起動バッチファイルに問題があってうまくいかないので、修正する。
bin\logstash.bat をエディタで開いて、58行目を以下のようにする。

bin\logstash.bat__line_58

if "%1"=="deps" goto install_deps

標準入力を標準出力にだすテスト

本格的には、別のファイルに設定を書いて、それをコマンドラインで -f オプションとともに指定するが、簡易テストをするためにコマンドラインに設定を直接書く事もできる（-e オプションで指定する）。
以下のコマンドを入力して数秒すると入力待ち受けになる。
キーボードから入力した文字列が logstash で解釈されて、表示される。

bin\logstash agent -e "input { stdin {}} output { stdout { codec => rubydebug }}"

ここでは、出力が見やすいよう、rubydebug というコーデック（フォーマット）に変換して、 Ruby の Hash 形式で表示させている。例えば、hello と入力すると以下のような出力が得られると思う。

{
    "message" => "hello\r",
   "@version" => "1",
 "@timestamp" => "2015-05-01T02:03:04.567Z",
       "host" => "your-hostname"
}

いくつかのフィールドが自動的に挿入されて、ログらしく出力されることがわかる。また、Windows で標準入力したログは、"\r" が残っていて、改行の処理が十分でないこともわかる。

CSV形式の入力ログの整形

ログをデータ化したいのだから、入力された文字列を、具体的なフィールドに分割しておきたいだろう。ログを出力する前に、入力をさまざまな filter を通す事で、出力内容を整形できる。

簡単なフィルタの例として、csv フィルタを使ってみる。csv フィルタは、入力された行を、カンマ区切りで、それぞれを別のフィールドにする。また、フィルード名も指定できる。

bin\logstash agent -e "input { stdin {}} output { stdout { codec => rubydebug }} filter { csv { columns => [ 'info','app','function','data']}} "

コマンドラインから指定しているので、みづらくなっているが、filter の部分は以下のような形になっている。

filter {
  csv {
    columns => ['info', 'app', 'function', 'data']
  }
}

ここでは、１行に４つの情報（カラム）があることを想定し、おのおの、情報レベル、アプリ名、機能名、データとしている。
標準入力から、Error,MyApp,Connect,URL ??? Not Found と入力すると、以下のような出力が得られる。

{
    "message" => [
    [0] "Error,MyApp,Connect,URL ??? Not Found\r"
   ],
   "@version" => "1",
 "@timestamp" => "2015-05-01T02:03:04.567Z",
       "host" => "your-hostname",
       "info" => "Error",
        "app" => "MyApp",
   "function" => "Connect",
       "data" => "URL ??? Not Found"
}

このようにして、CSV形式の文字列をフィールドに分割できる。

ファイルからログ入力

標準入力ではなく、あるファイルを監視して、ファイルが変更（ファイルの最後に新しいログが追加）されたら、ログにするには、以下のようにする。

bin\logstash agent -e "input { file { path => ['c:/temp/myapp.log']}} output { stdout { codec => rubydebug }} filter { csv { columns => ['info','app','function','data']}}"

file 入力の部分は、以下のようになっている。

input {
  file {
    path => ['c:/temp/myapp.log']
  }
}

ここで c:\temp\myapp.log ファイルを監視するようになっているので、コマンドラインから

echo Error,MyApp,Connect,URL ??? Not Found > c:\temp\myapp.log

のようにすると、ログとして処理されるのがわかるだろう。

入力に、UDPパケットを受け付ける

ネットワーク越しに外部のアプリからログを受け付けるには、UDPやTCPから入力したいだろう。ここでは、UDPの例をあげる。

input {
  udp {
    port => 6969
  }
}

input の設定を上記のようにして、logstash を起動すれば、logstash が UDPのポート6969 で待ち受けるようになるので、ネットワーク越しにログを保存できる。
例えば、Ruby を使って、

ruby -rsocket -e "u=UDPSocket.open; a=Socket.pack_sockaddr_in(6969,'127.0.0.1'); u.send('Error,MyApp,Connect,URL ??? Not Found', 0, a); u.close"

を実行すると、ログされるのがわかるだろう。

ログのファイル出力

出力先を標準出力からファイルに変更するには、output { stdout { .. }}の箇所を output { file { .. }} にする。

bin\logstash agent -e "input { stdin {}} output { file { path => 'output.log'}} filter { csv { columns => [ 'info','app','function','data']}} "

ここでは出力ファイルのパスに output.log と指定しているので、現在のフォルダの output.log ファイルに出力される。
さきほどと同様に、標準入力から、CSV形式で文字列を入力すると、output.log ファイルが作成されて、そこにこれまでみた出力が、JSON形式で出力されていると思う。
１行で完結したJSON文字列なので、ファイルとしては jsonファイルではないことに注意する。つまり、後で何か処理をしたいときは、１行ずつ読み込んでデコードする必要がある。

Elasticsearch を利用する設定

いまどきの簡単なログ可視化をめざすのであれば、Elasticsearch とKibana を考えて、出力先は、Elasticsearch も利用したいだろう。
Elasticsearch のインストールは、後にするとして、設定方法だけ確認する。
今度は、コマンドラインから設定するのではなく、設定ファイルを作成しておく。入力も、標準入力ではなく、なんらかのファイルから入力することにする。
conf フォルダを作成し、エディタで csvfile-2-es.conf を作成し、以下の内容にする。

conf/csvfile-2-es.conf

input {
  file {
    path => [ "c:/temp/applog-*"]
    discover_interval => 2
    type => "temp-file"
  }
}

filter {
  csv {
   columns => [ "info","app","function","data"]
  }
}

output {
  elasticsearch {
    host => "localhost"
    port => "9300"
    index => "applog-%{+YYYY.MM}"
  }
}

入力は、C:\Temp フォルダにできる applog- で始まるファイル名のファイルすべてを監視して、変化があったら、それをログとして取り込む。ファイルの監視は、2秒ごとで、 discover_interval で指定する。 type は、Elasticsearch が利用するフィールドで、RDB上のテーブル名のような役割のものになる。

出力は、ローカルに起動した、Elasticsearch に、applog-2015.05 のような名前の index （RDB上のデータベース名のようなもの）として作成する。作成されるデータは、いままでみたような内容になっている。

設定ファイルを作成できたら、コマンドラインから logstash を起動する。

bin\logstash agent -f conf/csvfile-2-es.conf

今回は、入力も出力も、標準入出力を利用しないので、動作の様子がよくわからない。もし、確認したい場合は、 --debug オプションをつければ、ファイルを監視したり、ファイルに変化があったときにログされる様子が、標準出力にでてくる。また、設定に間違いがあったときに、エラー内容を確認するときにも有用となる。

正規表現による入力文字列の分割（grokフィルタ）

様々なログ入力を処理するには、正規表現による方法が柔軟で応用範囲が広いだろう。logstash では、これを grok フィルタで行える。
grok フィルタでは、定型的な正規表現が patterns フォルダに用意されている。自分で正規表現を悩まなくても、そのパターン名を指定できる。
もちろん、通常の正規表現をそのまま記述できるので、どちらでも、利用しやすいほうを選べばよい。

例えば、apache_log を処理したいなら、COMMONAPACHELOG という定型パターンが用意されているので、以下のようにすることで、適宜フィールドの分割をしてくれる。

filter {
  grok {
    match => [ "message", "%{COMMONAPACHELOG}" ]
  }
}

logstash のフィルタでは、message キーに入力ログの文字列が渡されてくる。最初の "message" は、message キーを分割する指定である。

また、例えば、先述の CSV のフォーマットのデータを grok フィルタで処理したい場合、

filter {
  grok {
    match => [ "message", '(?<info>[^,]*),(?<app>[^,]*),(?<function>[^,]*),(?<data>[^,]*)\r']
  }
}

のようにできるだろう（ただし、csv フィルタと異なり、ダブルクォーテーションによるカンマ入りのフィールド文字列の扱いまでは行っていない）。

Ruby スクリプトによる入力文字列分割とフィールド追加（Rubyフィルタ）

さらに柔軟に、ログのデータ化をしたいとき、ruby フィルタを使うと、ruby スクリプトを直接記述して、ログデータを処理できる。
この方法は、入力データに含まれないデータを挿入したいときなどに便利に使えるだろう。

まずは、grok フィルタで行った csv 形式の文字列の分割を ruby フィルタで同じ事をしてみる。

filter {
  ruby {
    code => "
      m = %r{(?<info>[^,]*),(?<app>[^,]*),(?<function>[^,]*),(?<data>[^,]*)\r}.match(event[%Q{message}])
      if m then
        event.append({%Q{info} => m[:info]})
        event.append({%Q{app} => m[:app]})
        event.append({%Q{function} => m[:function]})
        event.append({%Q{data} => m[:data]})
      end
    "
  }
}

ruby フィルタでは、処理するデータは、ハッシュに似た、Event クラスのインスタンスで渡されてくるので、event データから、message キーのデータを読み込み、正規表現で、分割している。マッチした内容を、ログデータ上のフィールドにするため、event データに、キーと値を追加する事で、フィールドの追加を行っている。

ruby フィルタが役立つ例として、連続したログを処理し、直前のログ入力からの経過時間を新しいフィールドとして追加したいを考える。この場合、以下のようなスクリプトで処理できる。

filter {
  ruby {
    init => "
      @last_log_time = Time.now.to_i
    "
    code => "
      m = %r{(?<info>[^,]*),(?<app>[^,]*),(?<function>[^,]*),(?<data>[^,]*)\r}.match(event[%Q{message}])
      if m then
        event.append({%Q{info} => m[:info]})
        event.append({%Q{app} => m[:app]})
        event.append({%Q{function} => m[:function]})
        event.append({%Q{data} => m[:data]})

        t = Time.strptime(event[%Q{@timestamp}].to_s,%Q{%Y-%m-%d %H:%M:%S %Z}).to_i
        event.append({%Q{elapsed} => t - @last_log_time})
        @last_log_time = t
      end
    "
  }
}

ruby フィルタの init パラメータの文字列で、インスタンス変数を定義する。code パラメータで、そのインスタンス変数の変更を行っても logstash の起動している間は、ruby フィルタは変更を覚えている。永続的に記憶させたいなら、外部に保存する必要があるが、簡易的には、この方法が便利だろう。
経過時間を計算するために、もともとの event データにある @timestamp の値を文字列に変換して、それを strptimeメソッドで時刻情報として取り出している。その値から、直前に保存した値を引いて、経過時間としている。

値を永続化して覚えておきたい場合には、logstash には、redisライブラリが組み込まれているので、別途 redisサーバーを起動しておけば、ruby スクリプト上から、redis を利用できる。（同じ方法で elasticsearch も rubyスクリプトから利用できるが redis のほうが高速だろう）

ruby フィルタでは、スクリプトを文字列として記述する必要があるため、多少読みにくい。それでも、スクリプト中に、puts などで処理する内容を標準出力にだしてみて、動作確認もできるため、短いスクリプトなら、実用的だろう。
logstash の ruby は、JRuby であるため、スクリプト中に Java クラスも扱えるので、Javaのライブラリを利用することも可能である。

logstash をバックグラウンドで起動する

logstash は、サービスのようなツールなので、コマンドラインから起動すると、ずっとコマンドプロンプトが画面に出たままで、少し格好よくない。
Windows版の Elasticsearch はサービス化してインストールできるが logstash はそうなっていないため、見かけ上バックグラウンドで起動する簡単な VBスクリプトを用意する。

以下のVBスクリプトを bin フォルダに作成する。

bin\start-background.vbs

set oshell = CreateObject("Wscript.Shell")
set ofilesys = CreateObject("Scripting.FileSystemObject")
set logdir = ofilesys.GetFile(Wscript.Arguments(0))

dim strargs
strargs = "cmd /c "
for i=0 to Wscript.Arguments.Count-1
  strargs = strargs & Wscript.Arguments(i) & " "
next
strargs = strargs & " 1>" & logdir.ParentFolder & "\..\console.log 2>&1"
Wscript.echo strargs
oshell.Run strargs, 0, false

コマンドラインから、以下のようにして、起動テストをする。

cscript //nologo bin\start-background.vbs bin\logstash.bat -f conf\csvfile-2-es.conf

終了するには、タスクマネージャを開き、logstash と思われる java.exe のタスクを終了させるか、コマンドラインから、

wmic process where name="java.exe" get Name,ProcesseId,CommandLine /format:list

と入力すると、java.exe のプロセスだけリストされるので、コマンドラインの内容から、logstash のタスクを探し、その ProcessId を使い、taskkill /f /pid <ProcessId> とすれば、終了できる。

Windowsログイン時に、同時に起動しておくには、上記のVBスクリプトのショートカットをスタートアップフォルダに作成する。
ショートカットのプロパティを開き、作業フォルダを C:\Apps\logstash-1.4.2 にし、リンク先に c:\apps\logstash-1.4.2\bin\start-background.vbs bin\logstash -f conf\csvfile-2-es.conf とすれば、見かけ上、バックグラウンドで起動した状態になる。

まとめ

このようにして、logstash はログ収集データ化ツールとして、便利に利用でき、rubyスクリプトを使って柔軟にデータ化の前処理も行える。
少し工夫すれば、バックグラウンドで起動しておけるので、日常的なログ収集に、活用できるだろう。