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