module Liquid # Profiler enables support for profiling template rendering to help track down performance issues. # # To enable profiling, pass the profile: true option to Liquid::Template.parse. Then, after # Liquid::Template#render is called, the template object makes available an instance of this # class via the Liquid::Template#profiler method. # # template = Liquid::Template.parse(template_content, profile: true) # output = template.render # profile = template.profiler # # This object contains all profiling information, containing information on what tags were rendered, # where in the templates these tags live, and how long each tag took to render. # # This is a tree structure that is Enumerable all the way down, and keeps track of tags and rendering times # inside of {% include %} tags. # # profile.each do |node| # # Access to the token itself # node.code # # # Which template and line number of this node. # # If top level, this will be "". # node.partial # node.line_number # # # Render time in seconds of this node # node.render_time # # # If the template used {% include %}, this node will also have children. # node.children.each do |child2| # # ... # end # end # # Profiler also exposes the total time of the template's render in Liquid::Profiler#total_render_time. # # All render times are in seconds. There is a small performance hit when profiling is enabled. # class Profiler include Enumerable class Timing attr_reader :code, :partial, :line_number, :children def initialize(token, partial) @code = token.respond_to?(:raw) ? token.raw : token @partial = partial @line_number = token.respond_to?(:line_number) ? token.line_number : nil @children = [] end def self.start(token, partial) new(token, partial).tap do |t| t.start end end def start @start_time = Time.now end def finish @end_time = Time.now end def render_time @end_time - @start_time end end def self.profile_token_render(token) if Profiler.current_profile && token.respond_to?(:render) Profiler.current_profile.start_token(token) output = yield Profiler.current_profile.end_token(token) output else yield end end def self.profile_children(template_name) if Profiler.current_profile Profiler.current_profile.push_partial(template_name) output = yield Profiler.current_profile.pop_partial output else yield end end def self.current_profile Thread.current[:liquid_profiler] end def initialize @partial_stack = [""] @root_timing = Timing.new("", current_partial) @timing_stack = [@root_timing] @render_start_at = Time.now @render_end_at = @render_start_at end def start Thread.current[:liquid_profiler] = self @render_start_at = Time.now end def stop Thread.current[:liquid_profiler] = nil @render_end_at = Time.now end def total_render_time @render_end_at - @render_start_at end def each(&block) @root_timing.children.each(&block) end def [](idx) @root_timing.children[idx] end def length @root_timing.children.length end def start_token(token) @timing_stack.push(Timing.start(token, current_partial)) end def end_token(token) timing = @timing_stack.pop timing.finish @timing_stack.last.children << timing end def current_partial @partial_stack.last end def push_partial(partial_name) @partial_stack.push(partial_name) end def pop_partial @partial_stack.pop end end end