embulk-parser-grokの紹介

先日の [Embulk Meetup Tokyo #2](http://eventdots.jp/event/575046) で発表したembulk-parser-grokというプラグインが好評だったので、使い方を紹介したいと思います。

- [embulk-parser-grok](https://github.com/arielnetworks/embulk-parser-grok)
- [Embulkを活用したログ管理システム](http://www.slideshare.net/zoetrope/embulk)

# embulk-parser-grok

embulk-parser-grokは、Grokというライブラリを利用した汎用的なパーサライブラリです。

- https://github.com/thekrakken/java-grok

Grokはほぼ正規表現のようなものなのですが、パターンに名前をつけて再利用できるという大きなメリットを持っています。

社内ではこのプラグインを使って、各種アプリケーションログ、Apacheのアクセスログ、Javaのスレッドダンプ、GC Log、JMeterの出力などをパースしています。
汎用的に使えるのでとても重宝しています。

# 簡単なログをパースしてみる

こんな感じの簡単なログをパースしてみましょう。

~~~access.log
/index.html GET 1234
/sample.html POST 1
/api/status GET 9999
/api/save POST 100
~~~

まずはgrokのパターンファイルをつくります。

~~~sample.patterns
URIPATH     (?:/[A-Za-z0-9$.+!*'(){},~:;=@#%_\-]*)+
WORD        \b\w+\b
NUMBER      (?<![0-9.+-])(?>[+-]?(?:(?:[0-9]+(?:\.[0-9]+)?)|(?:\.[0-9]+)))
ACCESS_LOG  %{URIPATH:request} %{WORD:method} %{NUMBER:duration}
~~~

パターン名のあとにスペースをあけてパターンを記述します。パターンは正規表現で記述できます。
パターンの中で`%{パターン名:id}`と記述することで、パターンを再利用することができます。
`id`はパターンにマッチした文字列を取り出すための識別子になります。パターンにマッチした結果を利用しない場合は`id`に"UNWANTED"を指定します。

なお、パターンファイルは自分で書かなくても、汎用的なものをlogstashのリポジトリなどで見つけられるので、必要に応じてもらってくるとよいでしょう。

- https://github.com/logstash-plugins/logstash-patterns-core/tree/master/patterns

また、Grok Constructorというサービスを使うとブラウザ上でパターンの確認ができるので便利です。

- http://grokconstructor.appspot.com/

次に、embulkの設定ファイルをつくります。

~~~yaml:config.yml
in:
  type: file
  path_prefix: access.log
  parser:
    type: grok
    grok_pattern_files:
      - sample.patterns
    grok_pattern: '%{ACCESS_LOG}'
    charset: UTF-8
    newline: CRLF
    columns:
    - {name: request, type: string}
    - {name: method, type: string}
    - {name: duration, type: long}
~~~

`parser`の`type`に"grok"を指定します。
`grok_pattern_files`には、さきほど作成したパターンファイルのパスを指定します。
`grok_pattern`には、ログにマッチするパターンの名前を指定します。
`charset`,`newline`,`columns`は他のparserプラグインと同じ使い方になります。なお、`column`の`name`は、パターンファイルに記述したidと同じ名前を指定します。

実行してみましょう。

~~~
$ embulk preview config.yml
~~~

以下のように出力されたら成功です。

~~~
+----------------+---------------+---------------+
| request:string | method:string | duration:long |
+----------------+---------------+---------------+
|    /index.html |           GET |         1,234 |
|   /sample.html |          POST |             1 |
|    /api/status |           GET |         9,999 |
|      /api/save |          POST |           100 |
+----------------+---------------+---------------+
~~~

# 複数行のログをパースする

embulk-parser-grokは、1つのレコードが複数行に渡るログにも対応しています。

例えば、以下のようなスタックトレースが含まれるログファイルをパースしてみましょう。

~~~multiline.log
2015-12-15 11:45:44.342+0900 [INFO] (transaction): Loaded plugin embulk-parser-grok (0.1.5)
2015-12-15 11:45:44.355+0900 [INFO] (transaction): Listing local files at directory 'src/test/resources' filtering filename by prefix 'apache.log'
2015-12-15 11:45:44.358+0900 [INFO] (transaction): Loading files [src/test/resources/apache.log]
org.embulk.exec.PartialExecutionException: org.embulk.config.ConfigException: com.fasterxml.jackson.core.JsonParseException: Unrecognized token 'ruby': was expecting ('true', 'false' or 'null')
 at [Source: ruby; line: 1, column: 9]
	at org.embulk.exec.BulkLoader$LoaderState.buildPartialExecuteException(org/embulk/exec/BulkLoader.java:363)
	at org.embulk.exec.BulkLoader.doRun(org/embulk/exec/BulkLoader.java:572)
	at org.embulk.exec.BulkLoader.access$000(org/embulk/exec/BulkLoader.java:33)
	at org.embulk.exec.BulkLoader$1.run(org/embulk/exec/BulkLoader.java:374)
	at org.embulk.exec.BulkLoader$1.run(org/embulk/exec/BulkLoader.java:370)
	at org.embulk.spi.Exec.doWith(org/embulk/spi/Exec.java:25)
	at org.embulk.exec.BulkLoader.run(org/embulk/exec/BulkLoader.java:370)
	at org.embulk.EmbulkEmbed.run(org/embulk/EmbulkEmbed.java:180)
	at java.lang.reflect.Method.invoke(java/lang/reflect/Method.java:497)
	at RUBY.run(/home/ikezoe/.embulk/bin/embulk!/embulk/runner.rb:77)
	at RUBY.run(/home/ikezoe/.embulk/bin/embulk!/embulk/command/embulk_run.rb:296)
	at RUBY.<top>(/home/ikezoe/.embulk/bin/embulk!/embulk/command/embulk_main.rb:2)
	at org.jruby.RubyKernel.require(org/jruby/RubyKernel.java:940)
	at RUBY.(root)(uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rubygems/core_ext/kernel_require.rb:1)
	at home.ikezoe.$_dot_embulk.bin.embulk.embulk.command.embulk_bundle.<top>(file:/home/ikezoe/.embulk/bin/embulk!/embulk/command/embulk_bundle.rb:51)
	at java.lang.invoke.MethodHandle.invokeWithArguments(java/lang/invoke/MethodHandle.java:627)
	at org.embulk.cli.Main.main(org/embulk/cli/Main.java:23)
~~~

このログにマッチするパターンを作成します。

~~~multiline.patterns
MULTILINES (.*+\n)*+

MULTILINELOG_FIRSTLINE %{TIMESTAMP_ISO8601:timestamp} \[%{LOGLEVEL:log_level}\] %{DATA:message}$
MULTILINELOG %{TIMESTAMP_ISO8601:timestamp} \[%{LOGLEVEL:log_level}\] %{DATA:message}(?:\n%{MULTILINES:stack_trace})?$
~~~

複数行のログをパースする場合は、ログの1行目だけにマッチするパターン(`MULTILINELOG_FIRSTLINE`)と、ログ全体にマッチするパターン(`MULTILINELOG`)の2種類を用意します。

なお、上記のパターンファイルに含まれる `TIMESTAMP_ISO8601`, `LOGLEVEL`, `DATA`などのパターンは [logstashのリポジトリにあるgrok-patterns](https://github.com/logstash-plugins/logstash-patterns-core/blob/master/patterns/grok-patterns) に定義されているものを使います。

embulkの設定ファイルをつくります。

~~~yaml:config.yml
in:
  type: file
  path_prefix: multiline.log
  parser:
    type: grok
    grok_pattern_files: 
      - grok-patterns
      - multiline.patterns
    first_line_pattern: '%{MULTILINELOG_FIRSTLINE}'
    grok_pattern: '%{MULTILINELOG}'
    charset: UTF-8
    newline: CRLF
    columns:
      - {name: timestamp, format: '%Y-%m-%d %H:%M:%S.%N%z', type: timestamp}
      - {name: log_level, type: string}
      - {name: message, type: string}
      - {name: stack_trace, type: string}
~~~

今回はパターンファイルを複数個使うので、`grok_pattern_files`にファイルのパスを2つ指定しています。
`first_line_pattern`にログの1行目にマッチするパターン、`grok_pattern`にログ全体にマッチするパターンを記述します。
その他は、1行のログの場合と同じです。

# その他のオプション

## stop_on_invalid_record

パターンにマッチしないレコードがあったときに、処理を停止する(true)か、無視して続行する(false)かを指定することができます。
デフォルトでは、処理を続行する(false)設定になっています。

## timestamp_parser

EmbulkではタイムスタンプをパースするためにJRubyのAPIを使っているのですが、このパーサが非常に遅いという問題があります。

https://github.com/embulk/embulk/issues/145

そこで、embulk-parser-grokプラグインでは利用するタイムスタンプのパーサをオプションで選択できるようにしています。
`timestamp_parser`を指定しないか"ruby"を指定した場合は標準のタイムスタンプパーサ、"sdf"や"SimpleDateFormat"を指定するとJavaのSimpleDateFormatを利用します。
どちらのパーサを使う場合でも、`columns`に指定するフォーマットはJRuby形式のものにしてください。(例: `%Y-%m-%d %H:%M:%S.%N%z`)

なお、Embulk Meetupで標準のタイムスタンプのパーサが遅いとお伝えしたところ、v0.8で対応してくれることになりました。
そうなればこのオプションは不要ですね。

<blockquote class="twitter-tweet" lang="ja"><p lang="ja" dir="ltr">json型は <a href="https://twitter.com/oreradio">@oreradio</a> さんが来週までに作るハズなので！ その後諸々してから来月には embulk v0.8 を出せるのでは。API互換性が一部壊れる部分は、timestampパーサが速くなる目玉機能で補償する感じで。 <a href="https://twitter.com/muga_nishizawa">@muga_nishizawa</a></p>&mdash; Sadayuki Furuhashi (@frsyuki) <a href="https://twitter.com/frsyuki/status/676930319090647044">2015, 12月 16</a></blockquote>

# guess機能

embulk-parser-grokプラグインはguess機能も備えています。

ここでは、とあるApacheのアクセスログを推測してみましょう。Apacheのアクセスログはカスタマイズされている可能性があるので、いくつかのパターンの中からマッチするものを探す必要があります。

まず、以下のような設定ファイルをつくります。

~~~yaml:config.yml
in:
  type: file
  path_prefix: apache.log
  parser:
    type: grok
    grok_pattern_files:
      - grok-patterns
    guess_patterns:
      - "%{COMBINEDAPACHELOG}"
      - "%{COMMONAPACHELOG}"
    charset: UTF-8
    newline: CRLF
~~~

`guess_patterns`に、パターンファイルに記述されているパターン名を羅列します。
ここに指定したパターンの中からマッチするものを推測します。なお、複数のパターンにマッチした場合は、一番最初にマッチしたものが採用されます。
ここでは [grok-patterns](https://github.com/logstash-plugins/logstash-patterns-core/blob/master/patterns/grok-patterns) に定義されている`%{COMBINEDAPACHELOG}`と`%{COMMONAPACHELOG}`を指定します。

guessコマンドを実行してみましょう。

~~~
$ embulk guess -g grok config.yml -o apache.yml
~~~

guessに成功すると、以下のように`grok_pattern`にマッチするパターン名が指定され、`columns`の定義が出力されます。

~~~yaml:apache.yml
in:
  type: file
  path_prefix: apache.log
  parser:
    type: grok
    grok_pattern_files: [grok-patterns]
    guess_patterns: ['%{COMBINEDAPACHELOG}', '%{COMMONAPACHELOG}']
    charset: UTF-8
    newline: CRLF
    grok_pattern: '%{COMBINEDAPACHELOG}'
    columns:
    - {name: request, type: string}
    - {name: agent, type: string}
    - {name: COMMONAPACHELOG, type: string}
    - {name: auth, type: string}
    - {name: ident, type: string}
    - {name: verb, type: string}
    - {name: referrer, type: string}
    - {name: bytes, type: long}
    - {name: response, type: long}
    - {name: clientip, type: string}
    - {name: COMBINEDAPACHELOG, type: string}
    - {name: httpversion, type: string}
    - {name: rawrequest, type: string}
    - {name: timestamp, format: '%d/%b/%Y:%T %z', type: timestamp}
~~~

ただし、現在のところ複数行ログのguessには未対応です。また、タイムスタンプのフォーマットと、データ型の推測がちょっと弱いです。

なお、Embulk 0.7.10ではJavaで書かれたGuess Pluginが動かない不具合があるのでご注意ください。( https://github.com/embulk/embulk/pull/348 )

# おわりに

embulk-parser-grokプラグインを使うと、様々なフォーマットのログをパースすることができるようになります。
とても便利なのでぜひ使ってみてください。フィードバックもお待ちしております。

ちなみに

<blockquote class="twitter-tweet" lang="ja"><p lang="ja" dir="ltr">Grok parser pluginの初期実装はインド人留学生が作ったんだよね。一か月ちょっとで2、3個作れていたし、embulkのpluginを作るのはそこまでハードル高くないと思ってる。 <a href="https://twitter.com/hashtag/embulk?src=hash">#embulk</a></p>&mdash; Yusuke Suzuki (@Batista104) <a href="https://twitter.com/Batista104/status/676754658249932800">2015, 12月 15</a></blockquote>