1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
|
# frozen_string_literal: true
require 'liquid/profiler/hooks'
module Liquid
# Profiler enables support for profiling template rendering to help track down performance issues.
#
# To enable profiling, first require 'liquid/profiler'.
# Then, to profile a parse/render cycle, pass the <tt>profile: true</tt> option to <tt>Liquid::Template.parse</tt>.
# After <tt>Liquid::Template#render</tt> is called, the template object makes available an instance of this
# class via the <tt>Liquid::Template#profiler</tt> 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 <tt>{% include %}</tt> tags.
#
# profile.each do |node|
# # Access to the node itself
# node.code
#
# # Which template and line number of this node.
# # The top-level template name is `nil` by default, but can be set in the Liquid::Context before rendering.
# 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 <tt>Liquid::Profiler#total_render_time</tt>.
#
# 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, :template_name, :line_number, :children
attr_accessor :total_time
alias_method :render_time, :total_time
alias_method :partial, :template_name
def initialize(code: nil, template_name: nil, line_number: nil)
@code = code
@template_name = template_name
@line_number = line_number
@children = []
end
def self_time
@self_time ||= begin
total_children_time = 0.0
@children.each do |child|
total_children_time += child.total_time
end
@total_time - total_children_time
end
end
end
attr_reader :total_time
alias_method :total_render_time, :total_time
def initialize
@root_children = []
@current_children = nil
@total_time = 0.0
end
def profile(template_name, &block)
# nested renders are done from a tag that already has a timing node
return yield if @current_children
root_children = @root_children
render_idx = root_children.length
begin
@current_children = root_children
profile_node(template_name, &block)
ensure
@current_children = nil
if (timing = root_children[render_idx])
@total_time += timing.total_time
end
end
end
def children
children = @root_children
if children.length == 1
children.first.children
else
children
end
end
def each(&block)
children.each(&block)
end
def [](idx)
children[idx]
end
def length
children.length
end
def profile_node(template_name, code: nil, line_number: nil)
timing = Timing.new(code: code, template_name: template_name, line_number: line_number)
parent_children = @current_children
start_time = monotonic_time
begin
@current_children = timing.children
yield
ensure
@current_children = parent_children
timing.total_time = monotonic_time - start_time
parent_children << timing
end
end
private
def monotonic_time
Process.clock_gettime(Process::CLOCK_MONOTONIC)
end
end
end
|
