bench.rb

# -*- coding: utf-8 -*-
require 'fluent/config'
require 'fluent/engine'
require 'fluent/parser'
require 'benchmark'

optimized_log = '172.21.65.11 - - [07/Jan/2014:16:09:26 +0900] "GET /mypage HTTP/1.1" 302 - "-" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11"'
optimized_format = /^(?<host>[^ ]*) [^ ]* (?<user>[^ ]*) \[(?<time>[^\]]*)\] "(?<method>\S+)(?: +(?<path>[^ ]*) +\S*)?" (?<code>[^ ]*) (?<size>[^ ]*)(?: "(?<referer>[^\"]*)" "(?<agent>[^\"]*)")?$/
optimized_time_format = "%d/%b/%Y:%H:%M:%S %z"
optimized_parser = Fluent::TextParser::RegexpParser.new(optimized_format, 'time_format' => optimized_time_format)

greedy_log = '172.21.65.11 - - [07/Jan/2014:16:09:26 +0900] "GET /mypage HTTP/1.1" 302 - "-" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/535.11 (KHTML, like Gecko) Chrome/17.0.963.33 Safari/535.11"'
greedy_format = /^(?<host>.*) .* (?<user>.*) \[(?<time>[^\]]*)\] "(?<method>\S+)(?: +(?<path>.*) +\S*)?" (?<code>.*) (?<size>.*)(?: "(?<referer>[^\"]*)" "(?<agent>[^\"]*)")?$/
greedy_time_format = "%d/%b/%Y:%H:%M:%S %z"
greedy_parser = Fluent::TextParser::RegexpParser.new(greedy_format, 'time_format' => greedy_time_format)

ltsv_log = "time:2013-11-20 23:39:42 +0900\tlevel:ERROR\tmethod:POST\turi:/api/v1/people\treqtime:3.1983877060667103"
ltsv_parser = Fluent::TextParser::LabeledTSVParser.new()
ltsv_parser.configure({})

n = 100000
Benchmark.bm(7) do |x|
  x.report("ltsv")  {  n.times { ltsv_parser.call(ltsv_log) } }
  x.report("faster_regexp") { n.times { optimized_parser.call(optimized_log) } }
  x.report("greedy_regexp") { n.times { greedy_parser.call(greedy_log) } }
end