From 1e9163fdf449acefcbd541ff41cb447883be3557 Mon Sep 17 00:00:00 2001 From: Florian Weingarten Date: Fri, 5 Jun 2015 00:11:22 +0000 Subject: [PATCH] Liquid profiler --- bin/jekyll | 1 + lib/jekyll.rb | 1 + lib/jekyll/convertible.rb | 6 +- lib/jekyll/liquid_renderer.rb | 34 +++++++++++ lib/jekyll/liquid_renderer/file.rb | 40 +++++++++++++ lib/jekyll/liquid_renderer/table.rb | 88 +++++++++++++++++++++++++++++ lib/jekyll/renderer.rb | 4 +- lib/jekyll/site.rb | 15 ++++- lib/jekyll/tags/include.rb | 4 +- test/test_liquid_renderer.rb | 26 +++++++++ test/test_site.rb | 13 ++++- 11 files changed, 221 insertions(+), 11 deletions(-) create mode 100644 lib/jekyll/liquid_renderer.rb create mode 100644 lib/jekyll/liquid_renderer/file.rb create mode 100644 lib/jekyll/liquid_renderer/table.rb create mode 100644 test/test_liquid_renderer.rb diff --git a/bin/jekyll b/bin/jekyll index 60330cd7..0407df8b 100755 --- a/bin/jekyll +++ b/bin/jekyll @@ -24,6 +24,7 @@ Mercenary.program(:jekyll) do |p| p.option 'safe', '--safe', 'Safe mode (defaults to false)' p.option 'plugins', '-p', '--plugins PLUGINS_DIR1[,PLUGINS_DIR2[,...]]', Array, 'Plugins directory (defaults to ./_plugins)' p.option 'layouts', '--layouts DIR', String, 'Layouts directory (defaults to ./_layouts)' + p.option 'profile', '--profile', 'Generate a Liquid rendering profile' Jekyll::Command.subclasses.each { |c| c.init_with_program(p) } diff --git a/lib/jekyll.rb b/lib/jekyll.rb index 58eda759..9d6b5b63 100644 --- a/lib/jekyll.rb +++ b/lib/jekyll.rb @@ -66,6 +66,7 @@ module Jekyll autoload :Regenerator, 'jekyll/regenerator' autoload :RelatedPosts, 'jekyll/related_posts' autoload :Renderer, 'jekyll/renderer' + autoload :LiquidRenderer, 'jekyll/liquid_renderer' autoload :Site, 'jekyll/site' autoload :StaticFile, 'jekyll/static_file' autoload :Stevenson, 'jekyll/stevenson' diff --git a/lib/jekyll/convertible.rb b/lib/jekyll/convertible.rb index 5767ab02..0cf8e1c1 100644 --- a/lib/jekyll/convertible.rb +++ b/lib/jekyll/convertible.rb @@ -108,8 +108,8 @@ module Jekyll # info - the info for Liquid # # Returns the converted content - def render_liquid(content, payload, info, path = nil) - Liquid::Template.parse(content).render!(payload, info) + def render_liquid(content, payload, info, path) + site.liquid_renderer.file(path).parse(content).render(payload, info) rescue Tags::IncludeTagError => e Jekyll.logger.error "Liquid Exception:", "#{e.message} in #{e.path}, included in #{path || self.path}" raise e @@ -243,7 +243,7 @@ module Jekyll payload["highlighter_prefix"] = converters.first.highlighter_prefix payload["highlighter_suffix"] = converters.first.highlighter_suffix - self.content = render_liquid(content, payload, info) if render_with_liquid? + self.content = render_liquid(content, payload, info, path) if render_with_liquid? self.content = transform # output keeps track of what will finally be written diff --git a/lib/jekyll/liquid_renderer.rb b/lib/jekyll/liquid_renderer.rb new file mode 100644 index 00000000..191deeaf --- /dev/null +++ b/lib/jekyll/liquid_renderer.rb @@ -0,0 +1,34 @@ +require 'jekyll/liquid_renderer/file' +require 'jekyll/liquid_renderer/table' + +module Jekyll + class LiquidRenderer + def initialize(site) + @site = site + reset + end + + def reset + @stats = {} + end + + def file(filename) + filename = @site.in_source_dir(filename).sub(/\A#{Regexp.escape(@site.source)}\//, '') + + LiquidRenderer::File.new(self, filename).tap do |file| + @stats[filename] ||= {} + @stats[filename][:count] ||= 0 + @stats[filename][:count] += 1 + end + end + + def increment_time(filename, time) + @stats[filename][:time] ||= 0.0 + @stats[filename][:time] += time + end + + def stats_table(n = 50) + LiquidRenderer::Table.new(@stats).to_s(n) + end + end +end diff --git a/lib/jekyll/liquid_renderer/file.rb b/lib/jekyll/liquid_renderer/file.rb new file mode 100644 index 00000000..597a1003 --- /dev/null +++ b/lib/jekyll/liquid_renderer/file.rb @@ -0,0 +1,40 @@ +module Jekyll + class LiquidRenderer + class File + def initialize(renderer, filename) + @renderer = renderer + @filename = filename + end + + def parse(content) + measure_time do + @template = Liquid::Template.parse(content) + end + + self + end + + def render(*args) + measure_time do + @template.render(*args) + end + end + + def render!(*args) + measure_time do + @template.render!(*args) + end + end + + private + + def measure_time + before = Time.now + yield + ensure + after = Time.now + @renderer.increment_time(@filename, after - before) + end + end + end +end diff --git a/lib/jekyll/liquid_renderer/table.rb b/lib/jekyll/liquid_renderer/table.rb new file mode 100644 index 00000000..128ac374 --- /dev/null +++ b/lib/jekyll/liquid_renderer/table.rb @@ -0,0 +1,88 @@ +module Jekyll + class LiquidRenderer::Table + def initialize(stats) + @stats = stats + end + + def to_s(n = 50) + data = data_for_table(n) + widths = table_widths(data) + generate_table(data, widths) + end + + private + + def generate_table(data, widths) + str = "\n" + + table_head = data.shift + str << generate_row(table_head, widths) + str << generate_table_head_border(table_head, widths) + + data.each do |row_data| + str << generate_row(row_data, widths) + end + + str << "\n" + str + end + + def generate_table_head_border(row_data, widths) + str = "" + + row_data.each_index do |cell_index| + str << '-' * widths[cell_index] + str << '-+-' unless cell_index == row_data.length-1 + end + + str << "\n" + str + end + + def generate_row(row_data, widths) + str = '' + + row_data.each_with_index do |cell_data, cell_index| + if cell_index == 0 + str << cell_data.ljust(widths[cell_index], ' ') + else + str << cell_data.rjust(widths[cell_index], ' ') + end + + str << ' | ' unless cell_index == row_data.length-1 + end + + str << "\n" + str + end + + def table_widths(data) + widths = [ 0, 0, 0 ] + + data.each do |row| + row.each_with_index do |cell, index| + widths[index] = [ cell.length, widths[index] ].max + end + end + + widths + end + + def data_for_table(n) + sorted = @stats.sort_by{ |filename, file_stats| -file_stats[:time] } + sorted = sorted.slice(0, n) + + table = [[ 'Filename', 'Count', 'Total time' ]] + + sorted.each do |filename, file_stats| + row = [] + row << filename + row << file_stats[:count].to_s + row << "%.3f" % file_stats[:time] + table << row + end + + table + end + end +end diff --git a/lib/jekyll/renderer.rb b/lib/jekyll/renderer.rb index 4a772978..ca79e5a8 100644 --- a/lib/jekyll/renderer.rb +++ b/lib/jekyll/renderer.rb @@ -49,7 +49,7 @@ module Jekyll output = document.content if document.render_with_liquid? - output = render_liquid(output, payload, info) + output = render_liquid(output, payload, info, document.path) end output = convert(output) @@ -92,7 +92,7 @@ module Jekyll # # Returns the content, rendered by Liquid. def render_liquid(content, payload, info, path = nil) - Liquid::Template.parse(content).render!(payload, info) + site.liquid_renderer.file(path).parse(content).render!(payload, info) rescue Tags::IncludeTagError => e Jekyll.logger.error "Liquid Exception:", "#{e.message} in #{e.path}, included in #{path || document.relative_path}" raise e diff --git a/lib/jekyll/site.rb b/lib/jekyll/site.rb index e7307bbf..a1ea8644 100644 --- a/lib/jekyll/site.rb +++ b/lib/jekyll/site.rb @@ -11,7 +11,7 @@ module Jekyll :gems, :plugin_manager attr_accessor :converters, :generators, :reader - attr_reader :regenerator + attr_reader :regenerator, :liquid_renderer # Public: Initialize a new Site. # @@ -33,6 +33,8 @@ module Jekyll # Initialize incremental regenerator @regenerator = Regenerator.new(self) + @liquid_renderer = LiquidRenderer.new(self) + self.plugin_manager = Jekyll::PluginManager.new(self) self.plugins = plugin_manager.plugins_path @@ -57,6 +59,13 @@ module Jekyll render cleanup write + print_stats + end + + def print_stats + if @config['profile'] + puts @liquid_renderer.stats_table + end end # Reset Site details. @@ -70,7 +79,8 @@ module Jekyll self.static_files = [] self.data = {} @collections = nil - @regenerator.clear_cache() + @regenerator.clear_cache + @liquid_renderer.reset if limit_posts < 0 raise ArgumentError, "limit_posts must be a non-negative number" @@ -319,7 +329,6 @@ module Jekyll end.to_a end - def each_site_file %w(posts pages static_files docs_to_write).each do |type| send(type).each do |item| diff --git a/lib/jekyll/tags/include.rb b/lib/jekyll/tags/include.rb index b809ffe7..cbc59d44 100644 --- a/lib/jekyll/tags/include.rb +++ b/lib/jekyll/tags/include.rb @@ -95,7 +95,7 @@ eos # Render the variable if required def render_variable(context) if @file.match(VARIABLE_SYNTAX) - partial = Liquid::Template.parse(@file) + partial = context.registers[:site].liquid_renderer.file("(variable)").parse(@file) partial.render!(context) end end @@ -123,7 +123,7 @@ eos end begin - partial = Liquid::Template.parse(read_file(path, context)) + partial = site.liquid_renderer.file(path).parse(read_file(path, context)) context.stack do context['include'] = parse_params(context) if @params diff --git a/test/test_liquid_renderer.rb b/test/test_liquid_renderer.rb new file mode 100644 index 00000000..3da2d054 --- /dev/null +++ b/test/test_liquid_renderer.rb @@ -0,0 +1,26 @@ +require 'helper' + +class TestLiquidRenderer < JekyllUnitTest + context "profiler" do + setup do + @site = Site.new(site_configuration) + @renderer = @site.liquid_renderer + end + + should "return a table with profiling results" do + @site.process + + output = @renderer.stats_table + + expected = [ + /^Filename\s+|\s+Count\s+|\s+Total time$/, + /^-+\++-+\++-+$/, + /^_posts\/2010-01-09-date-override\.markdown\s+|\s+\d+\s+|\s+\d+\.\d{3}$/, + ] + + expected.each do |regexp| + assert_match regexp, output + end + end + end +end diff --git a/test/test_site.rb b/test/test_site.rb index 6b65ddb4..ca4438e6 100644 --- a/test/test_site.rb +++ b/test/test_site.rb @@ -310,7 +310,7 @@ class TestSite < JekyllUnitTest custom_processor = "CustomMarkdown" s = Site.new(site_configuration('markdown' => custom_processor)) - assert !!s.process + s.process # Do some cleanup, we don't like straggling stuff's. Jekyll::Converters::Markdown.send(:remove_const, :CustomMarkdown) @@ -459,6 +459,17 @@ class TestSite < JekyllUnitTest end end + context "with liquid profiling" do + setup do + @site = Site.new(site_configuration('profile' => true)) + end + + should "print profile table" do + @site.liquid_renderer.should_receive(:stats_table) + @site.process + end + end + context "incremental build" do setup do @site = Site.new(site_configuration({