Skip to content

Conversation

@emrox
Copy link

@emrox emrox commented Jul 23, 2014

The sequel to #170

With this patch this should work now:

{{ '{\'message\': \'this should work now\', \'foo\': {\'bar\':\'rab\'}}' }}

the main idea was to use it for a i18n filter accepting json encoded strings as argument

{{ 'translation_string' | t:'{\'count\':10,\'custom_var\':\'hello world\'}' }}

the patch should also fix #251

Benchmark result of the original current liquid master:

/Users/stefan/.rvm/rubies/ruby-2.1.1/bin/ruby ./performance/benchmark.rb lax
Rehearsal ------------------------------------------------
parse:         2.180000   0.010000   2.190000 (  2.189993)
parse & run:   5.040000   0.010000   5.050000 (  5.046477)
--------------------------------------- total: 7.240000sec

                   user     system      total        real
parse:         2.140000   0.000000   2.140000 (  2.144717)
parse & run:   5.090000   0.010000   5.100000 (  5.097024)

Benchmark result with this patch:

/Users/stefan/.rvm/rubies/ruby-2.1.1/bin/ruby ./performance/benchmark.rb lax
Rehearsal ------------------------------------------------
parse:         2.420000   0.010000   2.430000 (  2.429807)
parse & run:   5.220000   0.000000   5.220000 (  5.246784)
--------------------------------------- total: 7.650000sec

                   user     system      total        real
parse:         2.330000   0.000000   2.330000 (  2.335282)
parse & run:   5.410000   0.010000   5.420000 (  5.432291)

@fw42
Copy link
Contributor

fw42 commented Jul 23, 2014

@camilo, @dylanahsmith, thoughts?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do you have to explicitly specify the error_mode here?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

without i get an liquid parser error (i think it's because the liquid parser doesn't like the ' ?)

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

well, given that the point of this PR is to fix a parser bug, forcing a test to not run with one of the two parsers seems like the wrong approach to fixing the test :-P

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

when i try this on the original master, i also get an error:

diff --git a/test/integration/parsing_quirks_test.rb b/test/integration/parsing_quirks_test.rb
index add77c3..fadb642 100644
--- a/test/integration/parsing_quirks_test.rb
+++ b/test/integration/parsing_quirks_test.rb
@@ -91,4 +91,12 @@ class ParsingQuirksTest < Test::Unit::TestCase
     end
   end

+  def test_strings_with_escaped_quotes
+    text = 'test \\" escaping'
+
+    assert_nothing_raised do
+      Template.parse("{{ \"#{text}\" }}")
+    end
+  end
+
 end # ParsingQuirksTest

with error_mode: :lax everything is fine

should i open a new issue for that?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm confused now. I thought the fact that this doesn't work (escaped quotes) is what this PR is supposed to fix. Of course it fails on master :-) My point is that it seems like you only fixed it for the lax parser, but not the strict parser.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

damn, you are right. i should read my own headlines :(
i was fixed on the curly brackets

@fw42
Copy link
Contributor

fw42 commented Jul 23, 2014

Before you put too much effort in this, we should discuss if the performance penalty is worth it.

@jasonhl
Copy link
Collaborator

jasonhl commented Jul 23, 2014

Hmmm...can I see profile output for both master and this change? Both cpu and object please... (see #381).

Perf penalty seems high to me.

@fw42
Copy link
Contributor

fw42 commented Jul 23, 2014

I think the escaping is actually not the important part here, you can avoid that by using different quotes. You could use Liquid code in your template like this:

{{ "{'message': 'this should work now', 'foo': {'bar':'rab'}}" }}

and not need any escaping. But the curly brackets is what breaks this.

@emrox
Copy link
Author

emrox commented Jul 23, 2014

@fw42 for testing i removed the quote part

benchmark original master:

Rehearsal ------------------------------------------------
parse:         3.190000   0.010000   3.200000 (  3.192913)
parse & run:   7.080000   0.020000   7.100000 (  7.108225)
-------------------------------------- total: 10.300000sec

                   user     system      total        real
parse:         3.140000   0.010000   3.150000 (  3.144320)
parse & run:   7.000000   0.020000   7.020000 (  7.020343)

benchmark patched with just the curly bracket part:

Rehearsal ------------------------------------------------
parse:         3.500000   0.010000   3.510000 (  3.504597)
parse & run:   7.300000   0.010000   7.310000 (  7.318269)
-------------------------------------- total: 10.820000sec

                   user     system      total        real
parse:         3.450000   0.010000   3.460000 (  3.450586)
parse & run:   7.320000   0.010000   7.330000 (  7.332353)

@camilo
Copy link

camilo commented Jul 23, 2014

+1 on @jasonhl the penalty seems high object and cpu profiles would be good maybe is something easy to fix.

@emrox
Copy link
Author

emrox commented Jul 23, 2014

Original Profile:

Profiling in cpu mode...
==================================
  Mode: cpu(1000)
  Samples: 1960 (0.00% miss rate)
  GC: 283 (14.44%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       300  (15.3%)         172   (8.8%)     Liquid::Variable#lax_parse
       411  (21.0%)         151   (7.7%)     Liquid::Context#resolve
       128   (6.5%)         128   (6.5%)     block in Liquid::Variable#lax_parse
      1495  (76.3%)          96   (4.9%)     Liquid::Block#parse
      1942  (99.1%)          96   (4.9%)     Liquid::Block#render_all
        96   (4.9%)          96   (4.9%)     Liquid::Context#variable_parse
       394  (20.1%)          81   (4.1%)     Liquid::Variable#initialize
        66   (3.4%)          66   (3.4%)     Liquid::Template#tokenize
        71   (3.6%)          61   (3.1%)     block in Liquid::Context#variable
      1846  (94.2%)          55   (2.8%)     block in Liquid::Block#render_all
        65   (3.3%)          52   (2.7%)     Liquid::If#lax_parse
        43   (2.2%)          43   (2.2%)     Liquid::Context#resource_limits_reached?
        42   (2.1%)          42   (2.1%)     Liquid::Context#has_interrupt?
        36   (1.8%)          36   (1.8%)     Liquid::Context#increment_used_resources
        30   (1.5%)          30   (1.5%)     Liquid::Context#lookup_and_evaluate
        30   (1.5%)          26   (1.3%)     Liquid::Block#block_delimiter
       260  (13.3%)          21   (1.1%)     Liquid::Context#variable
        21   (1.1%)          21   (1.1%)     block in Liquid::Context#find_variable
        68   (3.5%)          21   (1.1%)     Liquid::Context#find_variable
        23   (1.2%)          21   (1.1%)     Liquid::For#lax_parse
Profiling in object mode...
==================================
  Mode: object(1)
  Samples: 7288000 (0.00% miss rate)
  GC: 0 (0.00%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
   2022100  (27.7%)     1299000  (17.8%)     Liquid::Variable#lax_parse
    723100   (9.9%)      723100   (9.9%)     block in Liquid::Variable#lax_parse
    625200   (8.6%)      625200   (8.6%)     Liquid::Context#variable_parse
   2856100  (39.2%)      597000   (8.2%)     Liquid::Block#create_variable
   9083600 (124.6%)      474300   (6.5%)     Liquid::Block#parse
    438600   (6.0%)      438600   (6.0%)     Liquid::Template#tokenize
   1282700  (17.6%)      421100   (5.8%)     Liquid::Context#resolve
   2178900  (29.9%)      300600   (4.1%)     Liquid::Variable#render
   1046400  (14.4%)      295500   (4.1%)     block in Liquid::Variable#render
    289100   (4.0%)      289100   (4.0%)     Liquid::If#lax_parse
   2259100  (31.0%)      238800   (3.3%)     block in Liquid::Block#create_variable
    204800   (2.8%)      204800   (2.8%)     Liquid::StandardFilters#truncatewords
    146100   (2.0%)      143500   (2.0%)     Liquid::For#lax_parse
    131300   (1.8%)      131300   (1.8%)     block in Liquid::Context#variable
   5942800  (81.5%)      108700   (1.5%)     Liquid::Block#render_all
    600600   (8.2%)       98500   (1.4%)     Liquid::Context#invoke
     66300   (0.9%)       66000   (0.9%)     Liquid::Context#initialize
    683300   (9.4%)       58100   (0.8%)     block in Liquid::Context#initialize
   9653300 (132.5%)       47600   (0.7%)     Liquid::Tag.parse
     47000   (0.6%)       47000   (0.6%)     block in Liquid::Context#find_variable

Change Profile (without the quote escaping patch):

Profiling in cpu mode...
==================================
  Mode: cpu(1000)
  Samples: 1925 (0.00% miss rate)
  GC: 259 (13.45%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       437  (22.7%)         184   (9.6%)     Liquid::Context#resolve
       263  (13.7%)         159   (8.3%)     Liquid::Variable#lax_parse
       134   (7.0%)         134   (7.0%)     Liquid::Template#tokenize
       116   (6.0%)         116   (6.0%)     Liquid::Context#variable_parse
       104   (5.4%)         104   (5.4%)     block in Liquid::Variable#lax_parse
      1344  (69.8%)          89   (4.6%)     Liquid::Block#parse
       365  (19.0%)          88   (4.6%)     Liquid::Variable#initialize
      1989 (103.3%)          83   (4.3%)     Liquid::Block#render_all
        63   (3.3%)          55   (2.9%)     Liquid::If#lax_parse
        60   (3.1%)          50   (2.6%)     block in Liquid::Context#variable
      1906  (99.0%)          47   (2.4%)     block in Liquid::Block#render_all
        41   (2.1%)          41   (2.1%)     Liquid::Context#resource_limits_reached?
        34   (1.8%)          34   (1.8%)     Liquid::Context#increment_used_resources
        26   (1.4%)          26   (1.4%)     Liquid::Context#[]=
        25   (1.3%)          25   (1.3%)     Liquid::Context#has_interrupt?
        59   (3.1%)          24   (1.2%)     Liquid::Context#find_variable
        24   (1.2%)          24   (1.2%)     Liquid::For#lax_parse
        19   (1.0%)          19   (1.0%)     block in Liquid::Context#find_variable
       505  (26.2%)          19   (1.0%)     Liquid::Variable#render
        19   (1.0%)          19   (1.0%)     Liquid::Template.error_mode
Profiling in object mode...
==================================
  Mode: object(1)
  Samples: 7282900 (0.00% miss rate)
  GC: 0 (0.00%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
   2022100  (27.8%)     1299000  (17.8%)     Liquid::Variable#lax_parse
    723100   (9.9%)      723100   (9.9%)     block in Liquid::Variable#lax_parse
    625200   (8.6%)      625200   (8.6%)     Liquid::Context#variable_parse
   2856100  (39.2%)      597000   (8.2%)     Liquid::Block#create_variable
   9025500 (123.9%)      474300   (6.5%)     Liquid::Block#parse
    438600   (6.0%)      438600   (6.0%)     Liquid::Template#tokenize
   1282700  (17.6%)      421100   (5.8%)     Liquid::Context#resolve
   2178900  (29.9%)      300600   (4.1%)     Liquid::Variable#render
   1046400  (14.4%)      295500   (4.1%)     block in Liquid::Variable#render
    289100   (4.0%)      289100   (4.0%)     Liquid::If#lax_parse
   2259100  (31.0%)      238800   (3.3%)     block in Liquid::Block#create_variable
    204800   (2.8%)      204800   (2.8%)     Liquid::StandardFilters#truncatewords
    146100   (2.0%)      143500   (2.0%)     Liquid::For#lax_parse
    131300   (1.8%)      131300   (1.8%)     block in Liquid::Context#variable
   5942800  (81.6%)      108700   (1.5%)     Liquid::Block#render_all
    600600   (8.2%)       98500   (1.4%)     Liquid::Context#invoke
     66300   (0.9%)       66000   (0.9%)     Liquid::Context#initialize
    683300   (9.4%)       58100   (0.8%)     block in Liquid::Context#initialize
     53000   (0.7%)       53000   (0.7%)     Liquid::Block#initialize
   9648200 (132.5%)       47600   (0.7%)     Liquid::Tag.parse

Change profile including the (currently just working in lax mode) escape patch:

Profiling in cpu mode...
==================================
  Mode: cpu(1000)
  Samples: 1755 (0.00% miss rate)
  GC: 258 (14.70%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       160   (9.1%)         160   (9.1%)     Liquid::Template#tokenize
       353  (20.1%)         141   (8.0%)     Liquid::Context#resolve
       241  (13.7%)         135   (7.7%)     Liquid::Variable#lax_parse
       106   (6.0%)         106   (6.0%)     block in Liquid::Variable#lax_parse
        77   (4.4%)          77   (4.4%)     Liquid::Context#variable_parse
      1231  (70.1%)          73   (4.2%)     Liquid::Block#parse
      1661  (94.6%)          63   (3.6%)     Liquid::Block#render_all
       319  (18.2%)          61   (3.5%)     Liquid::Variable#initialize
        55   (3.1%)          52   (3.0%)     Liquid::If#lax_parse
        60   (3.4%)          52   (3.0%)     block in Liquid::Context#variable
      1598  (91.1%)          45   (2.6%)     block in Liquid::Block#render_all
        40   (2.3%)          40   (2.3%)     Liquid::Context#increment_used_resources
        32   (1.8%)          32   (1.8%)     Liquid::Context#has_interrupt?
        30   (1.7%)          30   (1.7%)     Liquid::For#lax_parse
        24   (1.4%)          24   (1.4%)     Liquid::Template.error_mode
        24   (1.4%)          24   (1.4%)     Liquid::Context#lookup_and_evaluate
        21   (1.2%)          21   (1.2%)     Liquid::Context#resource_limits_reached?
        20   (1.1%)          20   (1.1%)     Liquid::StandardFilters#strip_html
        18   (1.0%)          18   (1.0%)     Liquid::Tag#initialize
        15   (0.9%)          15   (0.9%)     Set#include?
Profiling in object mode...
==================================
  Mode: object(1)
  Samples: 7282900 (0.00% miss rate)
  GC: 0 (0.00%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
   2022100  (27.8%)     1299000  (17.8%)     Liquid::Variable#lax_parse
    723100   (9.9%)      723100   (9.9%)     block in Liquid::Variable#lax_parse
    625200   (8.6%)      625200   (8.6%)     Liquid::Context#variable_parse
   2856100  (39.2%)      597000   (8.2%)     Liquid::Block#create_variable
   9025500 (123.9%)      474300   (6.5%)     Liquid::Block#parse
    438600   (6.0%)      438600   (6.0%)     Liquid::Template#tokenize
   1282700  (17.6%)      421100   (5.8%)     Liquid::Context#resolve
   2178900  (29.9%)      300600   (4.1%)     Liquid::Variable#render
   1046400  (14.4%)      295500   (4.1%)     block in Liquid::Variable#render
    289100   (4.0%)      289100   (4.0%)     Liquid::If#lax_parse
   2259100  (31.0%)      238800   (3.3%)     block in Liquid::Block#create_variable
    204800   (2.8%)      204800   (2.8%)     Liquid::StandardFilters#truncatewords
    146100   (2.0%)      143500   (2.0%)     Liquid::For#lax_parse
    131300   (1.8%)      131300   (1.8%)     block in Liquid::Context#variable
   5942800  (81.6%)      108700   (1.5%)     Liquid::Block#render_all
    600600   (8.2%)       98500   (1.4%)     Liquid::Context#invoke
     66300   (0.9%)       66000   (0.9%)     Liquid::Context#initialize
    683300   (9.4%)       58100   (0.8%)     block in Liquid::Context#initialize
     53000   (0.7%)       53000   (0.7%)     Liquid::Block#initialize
   9648200 (132.5%)       47600   (0.7%)     Liquid::Tag.parse

@emrox
Copy link
Author

emrox commented Jul 23, 2014

the patch is just a regex change, so all work belongs to the ruby regex engine. i think optimizing the regex should be hard work.

@jasonhl
Copy link
Collaborator

jasonhl commented Jul 24, 2014

Thank you for the benchmarks/profiles. Looks like there's no object allocation penalty but there is a ~10% penalty on parsing. That's pretty big.

The problem is that the speed of liquid (lax) parsing is almost entirely dependent on those regexes. Changing them has a disproportionate effect on the speed of the entire process.

So, unless the negative performance effect can be reduced, I'm going to vote 👎 on this one. Too high a penalty for what is effectively a corner case.

@emrox
Copy link
Author

emrox commented Jul 24, 2014

atm i can't see a way to make the regex faster. sure, i can strip the quote-escaping part, but the pure regex (without the other liquid stuff around) is still 2 times slower then the current liquid regex.

require 'benchmark'

TESTRUNS = 1_000_000

class OriginalTestrunner
  TagStart                    = /\{\%/
  TagEnd                      = /\%\}/
  VariableStart               = /\{\{/
  VariableIncompleteEnd       = /\}\}?/
  AnyStartingTag              = /\{\{|\{\%/
  PartialTemplateParser       = /#{TagStart}.*?#{TagEnd}|#{VariableStart}.*?#{VariableIncompleteEnd}/om
  TemplateParser              = /(#{PartialTemplateParser}|#{AnyStartingTag})/om

  def run
    'Posted by {{ comment.author }} on {{ comment.created_at | date: "%B %d, %Y }}" | dummy: "{{ }}" }}'.scan(TemplateParser)
  end
end

class PatchedTestrunner
  TagStart                    = /\{\%/
  TagEnd                      = /\%\}/
  VariableStart               = /\{\{/
  VariableIncompleteEnd       = /\}\}?/
  VariableEnd                 = /\}\}/
  AnyStartingTag              = /\{\{|\{\%/
  QuotedString                = /"[^"]*?"|'[^']*?'/
  PartialTemplateParser       = /#{TagStart}(?:#{QuotedString}|.*?)*?#{TagEnd}|#{VariableStart}(?:#{QuotedString}|.*?)*?#{VariableIncompleteEnd}/om
  TemplateParser              = /(#{PartialTemplateParser}|#{AnyStartingTag})/o

  def run
    'Posted by {{ comment.author }} on {{ comment.created_at | date: "%B %d, %Y }}" | dummy: "{{ }}" }}'.scan(TemplateParser)
  end
end

original_benchmark_result = Benchmark.measure { c = OriginalTestrunner.new; for i in 1..TESTRUNS; c.run; end }
patched_benchmark_result = Benchmark.measure { c = PatchedTestrunner.new; for i in 1..TESTRUNS; c.run; end }

original_result = OriginalTestrunner.new.run
patched_result = PatchedTestrunner.new.run


puts "Original: #{original_benchmark_result.to_s.strip} >> #{original_result}"
puts "Patched:  #{patched_benchmark_result.to_s.strip} >> #{patched_result}"

Result:

Original: 4.350000   0.010000   4.360000 (  4.358090) >> [["{{ comment.author }}"], ["{{ comment.created_at | date: \"%B %d, %Y }}"], ["{{ }}"]]
Patched:  9.190000   0.000000   9.190000 (  9.211747) >> [["{{ comment.author }}"], ["{{ comment.created_at | date: \"%B %d, %Y }}\" | dummy: \"{{ }}\" }}"]]

@fw42
Copy link
Contributor

fw42 commented Jul 28, 2014

Given the performance penalty of this, I'm afraid we will have to close this for now. Sorry! Thanks so much for taking the time to pull this together. I would love to get rid of all those shitty little parser quirks, but at the end of the day, they are "just" edge cases and fixing them all would slow us down significantly :-(

@fw42 fw42 closed this Jul 28, 2014
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants