Cache Document#to_liquid #3693

Merged
merged 1 commit into from May 10, 2015

Conversation

Projects
None yet
3 participants
@fw42
Contributor

fw42 commented May 10, 2015

I'm probably overlooking something, but this passes tests and (on my machine) shaves off about ~1.5 seconds of build time for the page in "site". Turns out Document#to_liquid is called a lot, which calls url, which calls url_placeholders which calls slugify, which apparently is kinda expensive.

I don't know how "representative" the site in "site" is and if this PR has any value to "real" and bigger Jekyll pages.

CPU profile before (master)

==================================
  Mode: cpu(100)
  Samples: 1345 (1.10% miss rate)
  GC: 92 (6.84%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       104   (7.7%)         104   (7.7%)     Jekyll::Utils#slugify
        98   (7.3%)          97   (7.2%)     Jekyll::Tags::IncludeTag#read_file
       135  (10.0%)          63   (4.7%)     Kramdown::Parser::Kramdown#parse_spans
        62   (4.6%)          62   (4.6%)     block in Jekyll::Utils#deep_merge_hashes
        99   (7.4%)          37   (2.8%)     Jekyll::Utils#deep_merge_hashes

As you can see, slugify is right up there on number 1.

CPU profile after (this branch)

==================================
  Mode: cpu(100)
  Samples: 905 (1.09% miss rate)
  GC: 64 (7.07%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       124  (13.7%)          51   (5.6%)     Kramdown::Parser::Kramdown#parse_spans
        41   (4.5%)          39   (4.3%)     Liquid::Context#[]=
       217  (24.0%)          30   (3.3%)     Liquid::Context#evaluate
        30   (3.3%)          30   (3.3%)     Jekyll::Tags::IncludeTag#read_file
        26   (2.9%)          26   (2.9%)     Liquid::Context#lookup_and_evaluate

And it's gone.

Naively comparing runtime

$ time be jekyll build -s site

Configuration file: site/_config.yml
            Source: site
       Destination: /home/vagrant/src/jekyll/_site
 Incremental build: enabled
      Generating...
                    done in 5.515 seconds.
 Auto-regeneration: disabled. Use --watch to enable.
bundle exec jekyll build -s site  6.26s user 0.42s system 99% cpu 6.720 total

$ mv _site _site_master

$ git checkout cache_document_to_liquid
Switched to branch 'cache_document_to_liquid'

$ rm -rf **/.jekyll-metadata

$ time be jekyll build -s site
Configuration file: site/_config.yml
            Source: site
       Destination: /home/vagrant/src/jekyll/_site
 Incremental build: enabled
      Generating...
                    done in 3.706 seconds.
 Auto-regeneration: disabled. Use --watch to enable.
bundle exec jekyll build -s site  4.60s user 0.40s system 99% cpu 5.034 total

$ diff -r _site _site_master
diff -r _site/feed.xml _site_master/feed.xml
14,15c14,15
<     <pubDate>Sun, 10 May 2015 03:36:50 +0000</pubDate>
<     <lastBuildDate>Sun, 10 May 2015 03:36:50 +0000</lastBuildDate>

---
>     <pubDate>Sun, 10 May 2015 03:36:28 +0000</pubDate>
>     <lastBuildDate>Sun, 10 May 2015 03:36:28 +0000</lastBuildDate>

Memory profile before (master)

==================================
  Mode: object(100)
  Samples: 4435643 (0.00% miss rate)
  GC: 0 (0.00%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
    765501  (17.3%)      765501  (17.3%)     Jekyll::Utils#slugify
    716532  (16.2%)      716529  (16.2%)     Jekyll::URL#sanitize_url
    237305   (5.3%)      237305   (5.3%)     Jekyll::Utils#add_permalink_suffix
    241451   (5.4%)      142712   (3.2%)     Jekyll::URL#generate_url
    113113   (2.6%)      112633   (2.5%)     Jekyll::Utils#deep_merge_hashes

Memory profile after (this branch)

==================================
  Mode: object(100)
  Samples: 2030618 (0.00% miss rate)
  GC: 0 (0.00%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
   3584644 (176.5%)      109374   (5.4%)     Liquid::Block#render_all
    107631   (5.3%)      107631   (5.3%)     Jekyll::Post#relative_path
    430758  (21.2%)       93150   (4.6%)     Jekyll::Convertible#to_liquid
    255939  (12.6%)       81482   (4.0%)     block in Jekyll::Convertible#to_liquid
     57568   (2.8%)       57568   (2.8%)     Liquid::Variable#taint_check

Code changes

I'm not sure if the changes are safe, but tests pass for me locally. The only potential problem I can see is if someone changes the value of @collection after to_liquid has already been called, but I didn't see any code that changes @collection except #initialize.

@parkr, does this make any sense?

If not, then at least we now know that there is some untested behaviour :-)

@parkr

This comment has been minimized.

Show comment
Hide comment
@parkr

parkr May 10, 2015

Member

Flo, you get hella props for your detailed and thorough PR description. Holy hell! That's amazing!

I'm 👍 👍 on this.

Member

parkr commented May 10, 2015

Flo, you get hella props for your detailed and thorough PR description. Holy hell! That's amazing!

I'm 👍 👍 on this.

@parkr parkr added this to the 3.0 milestone May 10, 2015

parkr added a commit that referenced this pull request May 10, 2015

@parkr parkr merged commit 5acac35 into jekyll:master May 10, 2015

1 check passed

continuous-integration/travis-ci/pr The Travis CI build passed
Details

parkr added a commit that referenced this pull request May 10, 2015

@parkr

This comment has been minimized.

Show comment
Hide comment
@parkr

parkr May 10, 2015

Member

Keep going! Haha :)

Member

parkr commented May 10, 2015

Keep going! Haha :)

@parkr

This comment has been minimized.

Show comment
Hide comment
@parkr

parkr May 10, 2015

Member

Collection#to_liquid could probably also be cached, no?

Member

parkr commented May 10, 2015

Collection#to_liquid could probably also be cached, no?

@parkr

This comment has been minimized.

Show comment
Hide comment
@parkr

parkr May 10, 2015

Member

And maybe Page#to_liquid?

Member

parkr commented May 10, 2015

And maybe Page#to_liquid?

@fw42 fw42 referenced this pull request in Shopify/liquid Jun 11, 2015

Closed

Liquid performance is slow #598

@jekyll jekyll locked and limited conversation to collaborators Feb 27, 2017

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.