Skip to content

Instantly share code, notes, and snippets.

@jasonroelofs
Last active August 29, 2015 14:02
Show Gist options
  • Save jasonroelofs/79bde3d22ede168a5ae8 to your computer and use it in GitHub Desktop.
Save jasonroelofs/79bde3d22ede168a5ae8 to your computer and use it in GitHub Desktop.
Benchmark and Profile of Liquid performance with alias_method hooks (Ruby 2.1.2)
] rake benchmark:run benchmark:strict profile:run profile:strict
ruby ./performance/benchmark.rb lax
Rehearsal ------------------------------------------------
parse: 4.420000 0.030000 4.450000 ( 4.455098)
parse & run: 9.050000 0.030000 9.080000 ( 9.078304)
-------------------------------------- total: 13.530000sec
user system total real
parse: 4.320000 0.020000 4.340000 ( 4.339127)
parse & run: 8.810000 0.020000 8.830000 ( 8.832378)
ruby ./performance/benchmark.rb strict
Rehearsal ------------------------------------------------
parse: 4.830000 0.020000 4.850000 ( 4.861274)
parse & run: 9.720000 0.020000 9.740000 ( 9.752936)
-------------------------------------- total: 14.590000sec
user system total real
parse: 4.780000 0.020000 4.800000 ( 4.803024)
parse & run: 9.090000 0.010000 9.100000 ( 9.108606)
ruby ./performance/profile.rb
==================================
Mode: cpu(1000)
Samples: 1499 (0.00% miss rate)
GC: 312 (20.81%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
1381 (92.1%) 144 (9.6%) Liquid::Block#render_all
210 (14.0%) 138 (9.2%) Liquid::Context#variable
229 (15.3%) 136 (9.1%) Liquid::Variable#lax_parse
1047 (69.8%) 116 (7.7%) Liquid::Block#parse
93 (6.2%) 93 (6.2%) block in Liquid::Variable#lax_parse
278 (18.5%) 68 (4.5%) Liquid::Context#resolve
47 (3.1%) 47 (3.1%) Liquid::Context#has_interrupt?
46 (3.1%) 46 (3.1%) Liquid::Template#tokenize
265 (17.7%) 32 (2.1%) Liquid::Variable#initialize
31 (2.1%) 28 (1.9%) Liquid::If#lax_parse
1237 (82.5%) 28 (1.9%) block in Liquid::Block#render_all
24 (1.6%) 24 (1.6%) Liquid::For#lax_parse
30 (2.0%) 24 (1.6%) block in Liquid::Context#variable
19 (1.3%) 19 (1.3%) Liquid::Context#increment_used_resources
17 (1.1%) 17 (1.1%) Liquid::Context#[]=
15 (1.0%) 15 (1.0%) block in Liquid::Context#find_variable
15 (1.0%) 15 (1.0%) Liquid::Context#lookup_and_evaluate
42 (2.8%) 12 (0.8%) Liquid::Context#find_variable
12 (0.8%) 12 (0.8%) Liquid::Context#resource_limits_reached?
12 (0.8%) 12 (0.8%) Set#include?
ruby ./performance/profile.rb strict
==================================
Mode: cpu(1000)
Samples: 1405 (0.00% miss rate)
GC: 230 (16.37%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
196 (14.0%) 132 (9.4%) Liquid::Context#variable
123 (8.8%) 123 (8.8%) Liquid::Lexer#tokenize
1099 (78.2%) 120 (8.5%) Liquid::Block#parse
1340 (95.4%) 99 (7.0%) Liquid::Block#render_all
278 (19.8%) 82 (5.8%) Liquid::Context#resolve
67 (4.8%) 67 (4.8%) Liquid::Template#tokenize
218 (15.5%) 44 (3.1%) Liquid::Variable#initialize
42 (3.0%) 42 (3.0%) Liquid::Context#has_interrupt?
169 (12.0%) 32 (2.3%) Liquid::Variable#strict_parse
30 (2.1%) 30 (2.1%) Liquid::Parser#consume
1241 (88.3%) 26 (1.9%) block in Liquid::Block#render_all
31 (2.2%) 24 (1.7%) block in Liquid::Context#variable
23 (1.6%) 23 (1.6%) Liquid::Lexer#initialize
23 (1.6%) 23 (1.6%) Liquid::Context#[]=
27 (1.9%) 22 (1.6%) Liquid::StandardFilters#to_date
16 (1.1%) 16 (1.1%) Liquid::Context#resource_limits_reached?
16 (1.1%) 16 (1.1%) Liquid::Context#increment_used_resources
15 (1.1%) 15 (1.1%) Liquid::Context#lookup_and_evaluate
13 (0.9%) 13 (0.9%) Set#include?
11 (0.8%) 11 (0.8%) Liquid::Parser#look
ruby ./performance/benchmark.rb lax
Rehearsal ------------------------------------------------
parse: 4.850000 0.030000 4.880000 ( 4.874793)
parse & run: 10.450000 0.040000 10.490000 ( 10.507083)
-------------------------------------- total: 15.370000sec
user system total real
parse: 4.920000 0.030000 4.950000 ( 4.948618)
parse & run: 10.500000 0.030000 10.530000 ( 10.548399)
ruby ./performance/benchmark.rb strict
Rehearsal ------------------------------------------------
parse: 5.570000 0.040000 5.610000 ( 5.613936)
parse & run: 11.390000 0.050000 11.440000 ( 11.454482)
-------------------------------------- total: 17.050000sec
user system total real
parse: 5.660000 0.040000 5.700000 ( 5.720896)
parse & run: 11.180000 0.050000 11.230000 ( 11.242862)
ruby ./performance/profile.rb
==================================
Mode: cpu(1000)
Samples: 2006 (0.00% miss rate)
GC: 558 (27.82%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
1229 (61.3%) 139 (6.9%) Liquid::Block#parse
222 (11.1%) 132 (6.6%) Liquid::Variable#lax_parse
282 (14.1%) 101 (5.0%) Liquid::Context#resolve
181 (9.0%) 95 (4.7%) Liquid::Context#variable
90 (4.5%) 90 (4.5%) block in Liquid::Variable#lax_parse
75 (3.7%) 75 (3.7%) block in Liquid::Template#tokenize
284 (14.2%) 56 (2.8%) Liquid::Variable#initialize
52 (2.6%) 52 (2.6%) Liquid::Profiler::Timing#finished
124 (6.2%) 49 (2.4%) Liquid::Template#tokenize
53 (2.6%) 44 (2.2%) Liquid::Profiler::Timing#initialize
1720 (85.7%) 39 (1.9%) Liquid::Block#render_all
38 (1.9%) 38 (1.9%) Liquid::Profiler.current_profile
39 (1.9%) 36 (1.8%) Liquid::If#lax_parse
36 (1.8%) 36 (1.8%) Liquid::Context#has_interrupt?
31 (1.5%) 26 (1.3%) block in Liquid::Context#variable
24 (1.2%) 24 (1.2%) Liquid::For#lax_parse
1681 (83.8%) 23 (1.1%) block in Liquid::Block#render_all
21 (1.0%) 21 (1.0%) Liquid::Context#increment_used_resources
20 (1.0%) 20 (1.0%) block in Liquid::Context#find_variable
19 (0.9%) 19 (0.9%) Liquid::Context#lookup_and_evaluate
ruby ./performance/profile.rb strict
==================================
Mode: cpu(1000)
Samples: 2153 (0.00% miss rate)
GC: 445 (20.67%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
185 (8.6%) 185 (8.6%) Liquid::Lexer#tokenize
1459 (67.8%) 171 (7.9%) Liquid::Block#parse
252 (11.7%) 141 (6.5%) Liquid::Context#variable
370 (17.2%) 118 (5.5%) Liquid::Context#resolve
78 (3.6%) 78 (3.6%) block in Liquid::Template#tokenize
2038 (94.7%) 72 (3.3%) Liquid::Block#render_all
60 (2.8%) 60 (2.8%) Liquid::Profiler::Timing#finished
315 (14.6%) 57 (2.6%) Liquid::Variable#initialize
131 (6.1%) 53 (2.5%) Liquid::Template#tokenize
58 (2.7%) 52 (2.4%) Liquid::Profiler::Timing#initialize
45 (2.1%) 45 (2.1%) Liquid::Lexer#initialize
253 (11.8%) 43 (2.0%) Liquid::Variable#strict_parse
41 (1.9%) 41 (1.9%) Liquid::Context#has_interrupt?
37 (1.7%) 37 (1.7%) Liquid::Profiler.current_profile
45 (2.1%) 33 (1.5%) block in Liquid::Context#variable
31 (1.4%) 31 (1.4%) Liquid::Parser#consume
26 (1.2%) 26 (1.2%) Liquid::Context#lookup_and_evaluate
26 (1.2%) 26 (1.2%) block in Liquid::Context#find_variable
26 (1.2%) 26 (1.2%) Liquid::Context#increment_used_resources
1966 (91.3%) 21 (1.0%) block in Liquid::Block#render_all
ruby ./performance/benchmark.rb lax
Rehearsal ------------------------------------------------
parse: 4.910000 0.040000 4.950000 ( 4.963176)
parse & run: 9.640000 0.030000 9.670000 ( 9.672796)
-------------------------------------- total: 14.620000sec
user system total real
parse: 4.940000 0.040000 4.980000 ( 4.986263)
parse & run: 9.540000 0.020000 9.560000 ( 9.565731)
ruby ./performance/benchmark.rb strict
Rehearsal ------------------------------------------------
parse: 5.400000 0.020000 5.420000 ( 5.425801)
parse & run: 10.040000 0.030000 10.070000 ( 10.066415)
-------------------------------------- total: 15.490000sec
user system total real
parse: 5.340000 0.020000 5.360000 ( 5.365540)
parse & run: 10.450000 0.030000 10.480000 ( 10.495040)
ruby ./performance/profile.rb
==================================
Mode: cpu(1000)
Samples: 2014 (0.00% miss rate)
GC: 683 (33.91%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
244 (12.1%) 153 (7.6%) Liquid::Context#variable
241 (12.0%) 141 (7.0%) Liquid::Variable#lax_parse
1242 (61.7%) 140 (7.0%) Liquid::Block#parse
100 (5.0%) 100 (5.0%) block in Liquid::Variable#lax_parse
334 (16.6%) 90 (4.5%) Liquid::Context#resolve
1496 (74.3%) 67 (3.3%) Liquid::Block#render_all
67 (3.3%) 67 (3.3%) block in Liquid::Template#tokenize
307 (15.2%) 57 (2.8%) Liquid::Variable#initialize
113 (5.6%) 46 (2.3%) Liquid::Template#tokenize
38 (1.9%) 38 (1.9%) Liquid::Context#has_interrupt?
49 (2.4%) 34 (1.7%) block in Liquid::Context#variable
33 (1.6%) 28 (1.4%) Liquid::If#lax_parse
1429 (71.0%) 21 (1.0%) block in Liquid::Block#render_all
21 (1.0%) 20 (1.0%) Liquid::For#lax_parse
18 (0.9%) 18 (0.9%) Liquid::Context#increment_used_resources
18 (0.9%) 18 (0.9%) block in Liquid::Context#find_variable
28 (1.4%) 17 (0.8%) Liquid::StandardFilters#to_date
16 (0.8%) 16 (0.8%) Liquid::Context#lookup_and_evaluate
16 (0.8%) 16 (0.8%) Liquid::Context#resource_limits_reached?
400 (19.9%) 14 (0.7%) Liquid::Variable#render
ruby ./performance/profile.rb strict
==================================
Mode: cpu(1000)
Samples: 1685 (0.00% miss rate)
GC: 376 (22.31%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
1291 (76.6%) 158 (9.4%) Liquid::Block#parse
147 (8.7%) 147 (8.7%) Liquid::Lexer#tokenize
203 (12.0%) 131 (7.8%) Liquid::Context#variable
309 (18.3%) 106 (6.3%) Liquid::Context#resolve
83 (4.9%) 83 (4.9%) block in Liquid::Template#tokenize
1380 (81.9%) 61 (3.6%) Liquid::Block#render_all
274 (16.3%) 54 (3.2%) Liquid::Variable#initialize
129 (7.7%) 46 (2.7%) Liquid::Template#tokenize
216 (12.8%) 44 (2.6%) Liquid::Variable#strict_parse
37 (2.2%) 37 (2.2%) Liquid::Context#has_interrupt?
30 (1.8%) 30 (1.8%) Liquid::Parser#consume
1319 (78.3%) 24 (1.4%) block in Liquid::Block#render_all
23 (1.4%) 23 (1.4%) Liquid::Lexer#initialize
21 (1.2%) 21 (1.2%) block in Liquid::Context#find_variable
27 (1.6%) 19 (1.1%) block in Liquid::Context#variable
17 (1.0%) 17 (1.0%) Liquid::Context#[]=
14 (0.8%) 14 (0.8%) Set#include?
14 (0.8%) 14 (0.8%) Liquid::Context#increment_used_resources
14 (0.8%) 14 (0.8%) Liquid::Context#lookup_and_evaluate
13 (0.8%) 13 (0.8%) Liquid::Parser#look
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment