Open jsvd opened 8 years ago
On a note: JRuby 9.0.5.0 performs similarly, if not slightly faster (after working around https://github.com/jruby/jruby/issues/3715):
main profile results:
Total time: 88.77
total self children calls method
----------------------------------------------------------------
88.77 0.46 88.31 4000001 Array#each
88.31 1.11 87.20 1000000 LogStash::Filters::Grok#filter
80.29 1.50 78.79 2000000 Hash#each
78.79 1.41 77.39 1000000 LogStash::Filters::Grok#match
75.69 1.08 74.62 1000000 LogStash::Filters::Grok#match_against_groks
72.80 0.81 71.99 1000000 Grok#match_and_capture
39.77 7.88 31.89 11000000 Proc#call
30.60 30.60 0.00 1000000 Regexp#match
25.34 11.93 13.41 10000000 LogStash::Filters::Grok#handle
6.84 6.84 0.00 9000000 LogStash::Event#[]=
5.17 5.17 0.00 10000000 LogStash::Event#[]
4.32 3.81 0.51 3000000 Cabin::Mixins::Logger.debug?
4.28 2.49 1.79 1000000 LogStash::Filters::Base#filter_matched
1.10 1.10 0.00 10000000 MatchData#[]
0.74 0.74 0.00 10000000 Kernel.kind_of?
...
On a side note, big props to @colinsurprenant for the logstash-core-event-java. In my tests using the old ruby version of logstash-core-event made the []/[]= methods take a bigger slice of the whole, making Regexp#match use only ~10/12% of the time.
Total time to process the same apache log line 1_000_000 times with
%{COMMONAPACHELOG}
: 93.88s (~10k e/s)The 6 biggest time offenders use 70.46s - 75% of total time:
Note: this is using:
Ruby script used to test:
The full profile.graph output can be found here