Last active
March 7, 2016 12:41
-
-
Save jsvd/a591afa3e2fe6a9aaf22 to your computer and use it in GitHub Desktop.
Why is grok slow?
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
% bundle exec ruby -J-Xmx6g --profile bench_slow.rb | |
Profiling enabled; ^C shutdown will now dump profile info | |
generating data..done. benchmarking... | |
Total time: 93.88 | |
%total %self total self children calls name | |
--------------------------------------------------------------------------------------------------------- | |
0.00 0.00 0.00 1000000/4000001 LogStash::Filters::Grok#match_against_groks | |
0.00 0.00 0.00 2000000/4000001 LogStash::Filters::Base#filter_matched | |
0.00 0.00 0.00 1000000/4000001 LogStash::Util::Decorators.add_tags | |
93.88 0.38 93.50 1/4000001 (top) | |
100% 0% 93.88 0.38 93.50 4000001 Array#each | |
93.50 1.55 91.95 1000000/1000000 LogStash::Filters::Grok#filter | |
77.57 1.28 76.29 1000000/1000000 Grok#match_and_capture | |
0.06 0.06 0.00 1000000/1000000 String#to_s | |
--------------------------------------------------------------------------------------------------------- | |
100% 0% 93.88 0.00 93.88 1 (top) | |
93.88 0.38 93.50 1/4000001 Array#each | |
--------------------------------------------------------------------------------------------------------- | |
93.50 1.55 91.95 1000000/1000000 Array#each | |
99% 1% 93.50 1.55 91.95 1000000 LogStash::Filters::Grok#filter | |
83.53 1.19 82.34 1000000/2000000 Hash#each | |
4.27 3.97 0.31 2000000/3000000 Cabin::Mixins::Logger.debug? | |
4.15 2.17 1.98 1000000/1000000 LogStash::Filters::Base#filter_matched | |
--------------------------------------------------------------------------------------------------------- | |
0.07 0.07 0.00 1000000/2000000 LogStash::Util::Decorators.add_fields | |
83.53 1.19 82.34 1000000/2000000 LogStash::Filters::Grok#filter | |
89% 1% 83.60 1.26 82.34 2000000 Hash#each | |
82.34 0.92 81.42 1000000/1000000 LogStash::Filters::Grok#match | |
--------------------------------------------------------------------------------------------------------- | |
82.34 0.92 81.42 1000000/1000000 Hash#each | |
87% 0% 82.34 0.92 81.42 1000000 LogStash::Filters::Grok#match | |
79.71 0.66 79.05 1000000/1000000 LogStash::Filters::Grok#match_against_groks | |
1.62 1.62 0.00 1000000/10000000 LogStash::Event#[] | |
0.09 0.09 0.00 1000000/10000000 Kernel.kind_of? | |
--------------------------------------------------------------------------------------------------------- | |
79.71 0.66 79.05 1000000/1000000 LogStash::Filters::Grok#match | |
84% 0% 79.71 0.66 79.05 1000000 LogStash::Filters::Grok#match_against_groks | |
0.00 0.00 0.00 1000000/4000001 Array#each | |
--------------------------------------------------------------------------------------------------------- | |
77.57 1.28 76.29 1000000/1000000 Array#each | |
82% 1% 77.57 1.28 76.29 1000000 Grok#match_and_capture | |
54.89 4.54 50.35 1000000/11000000 Proc#call | |
19.48 19.48 0.00 1000000/1000000 Regexp#match | |
1.92 1.77 0.15 1000000/3000000 Cabin::Mixins::Logger.debug? | |
--------------------------------------------------------------------------------------------------------- | |
0.00 0.00 0.00 10000000/11000000 Proc#call | |
54.89 4.54 50.35 1000000/11000000 Grok#match_and_capture | |
58% 4% 54.89 4.54 50.35 11000000 Proc#call | |
45.89 21.16 24.73 10000000/10000000 LogStash::Filters::Grok#handle | |
1.32 1.32 0.00 10000000/10000000 MatchData#[] | |
0.00 0.00 0.00 10000000/11000000 Proc#call | |
--------------------------------------------------------------------------------------------------------- | |
45.89 21.16 24.73 10000000/10000000 Proc#call | |
48% 22% 45.89 21.16 24.73 10000000 LogStash::Filters::Grok#handle | |
15.58 15.58 0.00 9000000/9000000 LogStash::Event#[]= | |
6.89 6.89 0.00 9000000/10000000 LogStash::Event#[] | |
0.49 0.49 0.00 10000000/10000000 NilClass#nil? | |
0.48 0.48 0.00 9000000/10000000 Kernel.kind_of? | |
0.47 0.47 0.00 9000000/9000000 Array#include? | |
0.42 0.42 0.00 9000000/9000000 Kernel.nil? | |
0.39 0.39 0.00 9000000/9000000 String#empty? | |
--------------------------------------------------------------------------------------------------------- | |
19.48 19.48 0.00 1000000/1000000 Grok#match_and_capture | |
20% 20% 19.48 19.48 0.00 1000000 Regexp#match | |
--------------------------------------------------------------------------------------------------------- | |
15.58 15.58 0.00 9000000/9000000 LogStash::Filters::Grok#handle | |
16% 16% 15.58 15.58 0.00 9000000 LogStash::Event#[]= | |
--------------------------------------------------------------------------------------------------------- | |
1.62 1.62 0.00 1000000/10000000 LogStash::Filters::Grok#match | |
6.89 6.89 0.00 9000000/10000000 LogStash::Filters::Grok#handle | |
9% 9% 8.51 8.51 0.00 10000000 LogStash::Event#[] | |
--------------------------------------------------------------------------------------------------------- | |
1.92 1.77 0.15 1000000/3000000 Grok#match_and_capture | |
4.27 3.97 0.31 2000000/3000000 LogStash::Filters::Grok#filter | |
6% 6% 6.19 5.73 0.46 3000000 Cabin::Mixins::Logger.debug? | |
0.46 0.46 0.00 6000000/6000000 Hash#[] | |
--------------------------------------------------------------------------------------------------------- | |
4.15 2.17 1.98 1000000/1000000 LogStash::Filters::Grok#filter | |
4% 2% 4.15 2.17 1.98 1000000 LogStash::Filters::Base#filter_matched | |
0.96 0.96 0.00 2000000/2000000 Module#name | |
0.46 0.40 0.07 1000000/1000000 LogStash::Util::Decorators.add_fields | |
0.36 0.30 0.06 1000000/1000000 LogStash::Util::Decorators.add_tags | |
0.09 0.09 0.00 2000000/2000000 Kernel.class | |
0.00 0.00 0.00 2000000/4000001 Array#each | |
--------------------------------------------------------------------------------------------------------- | |
1.32 1.32 0.00 10000000/10000000 Proc#call | |
1% 1% 1.32 1.32 0.00 10000000 MatchData#[] | |
--------------------------------------------------------------------------------------------------------- | |
0.96 0.96 0.00 2000000/2000000 LogStash::Filters::Base#filter_matched | |
1% 1% 0.96 0.96 0.00 2000000 Module#name | |
--------------------------------------------------------------------------------------------------------- | |
0.09 0.09 0.00 1000000/10000000 LogStash::Filters::Grok#match | |
0.48 0.48 0.00 9000000/10000000 LogStash::Filters::Grok#handle | |
0% 0% 0.56 0.56 0.00 10000000 Kernel.kind_of? | |
--------------------------------------------------------------------------------------------------------- | |
0.49 0.49 0.00 10000000/10000000 LogStash::Filters::Grok#handle | |
0% 0% 0.49 0.49 0.00 10000000 NilClass#nil? | |
--------------------------------------------------------------------------------------------------------- | |
0.47 0.47 0.00 9000000/9000000 LogStash::Filters::Grok#handle | |
0% 0% 0.47 0.47 0.00 9000000 Array#include? | |
--------------------------------------------------------------------------------------------------------- | |
0.46 0.40 0.07 1000000/1000000 LogStash::Filters::Base#filter_matched | |
0% 0% 0.46 0.40 0.07 1000000 LogStash::Util::Decorators.add_fields | |
0.07 0.07 0.00 1000000/2000000 Hash#each | |
--------------------------------------------------------------------------------------------------------- | |
0.46 0.46 0.00 6000000/6000000 Cabin::Mixins::Logger.debug? | |
0% 0% 0.46 0.46 0.00 6000000 Hash#[] | |
--------------------------------------------------------------------------------------------------------- | |
0.42 0.42 0.00 9000000/9000000 LogStash::Filters::Grok#handle | |
0% 0% 0.42 0.42 0.00 9000000 Kernel.nil? | |
--------------------------------------------------------------------------------------------------------- | |
0.39 0.39 0.00 9000000/9000000 LogStash::Filters::Grok#handle | |
0% 0% 0.39 0.39 0.00 9000000 String#empty? | |
--------------------------------------------------------------------------------------------------------- | |
0.36 0.30 0.06 1000000/1000000 LogStash::Filters::Base#filter_matched | |
0% 0% 0.36 0.30 0.06 1000000 LogStash::Util::Decorators.add_tags | |
0.00 0.00 0.00 1000000/4000001 Array#each | |
--------------------------------------------------------------------------------------------------------- | |
0.09 0.09 0.00 2000000/2000000 LogStash::Filters::Base#filter_matched | |
0% 0% 0.09 0.09 0.00 2000000 Kernel.class | |
--------------------------------------------------------------------------------------------------------- | |
0.06 0.06 0.00 1000000/1000000 Array#each | |
0% 0% 0.06 0.06 0.00 1000000 String#to_s | |
main profile results: | |
Total time: 93.88 | |
total self children calls method | |
---------------------------------------------------------------- | |
93.88 0.38 93.50 4000001 Array#each | |
93.50 1.55 91.95 1000000 LogStash::Filters::Grok#filter | |
83.60 1.26 82.34 2000000 Hash#each | |
82.34 0.92 81.42 1000000 LogStash::Filters::Grok#match | |
79.71 0.66 79.05 1000000 LogStash::Filters::Grok#match_against_groks | |
77.57 1.28 76.29 1000000 Grok#match_and_capture | |
54.89 4.54 50.35 11000000 Proc#call | |
45.89 21.16 24.73 10000000 LogStash::Filters::Grok#handle | |
19.48 19.48 0.00 1000000 Regexp#match | |
15.58 15.58 0.00 9000000 LogStash::Event#[]= | |
8.51 8.51 0.00 10000000 LogStash::Event#[] | |
6.19 5.73 0.46 3000000 Cabin::Mixins::Logger.debug? | |
4.15 2.17 1.98 1000000 LogStash::Filters::Base#filter_matched | |
1.32 1.32 0.00 10000000 MatchData#[] | |
0.96 0.96 0.00 2000000 Module#name | |
0.56 0.56 0.00 10000000 Kernel.kind_of? | |
0.49 0.49 0.00 10000000 NilClass#nil? | |
0.47 0.47 0.00 9000000 Array#include? | |
0.46 0.40 0.07 1000000 LogStash::Util::Decorators.add_fields | |
0.46 0.46 0.00 6000000 Hash#[] | |
0.42 0.42 0.00 9000000 Kernel.nil? | |
0.39 0.39 0.00 9000000 String#empty? | |
0.36 0.30 0.06 1000000 LogStash::Util::Decorators.add_tags | |
0.09 0.09 0.00 2000000 Kernel.class | |
0.06 0.06 0.00 1000000 String#to_s |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment