37
64
get immediate profiling results in the browser, use
38
65
<code>++profile++show</code>.</tal:block> <tal:block condition="not:
39
66
always_log">In order to get profiling results, you need to ask for an HTML
40
view (<code>++profile++show</code>), a KCacheGrind-friendly log on the
41
filesystem (<code>++profile++callgrind</code>), or a PStats-friendly log
67
view of the profile and OOPS data including SQL calls
68
(<code>++profile++show</code>), a KCacheGrind-friendly log on the
69
filesystem (<code>++profile++callgrind</code>), a PStats-friendly log
42
70
(Python standard library) on the filesystem
43
(<code>++profile++pstats</code>). You can also ask for local HTML
44
profiling plus one of the two log files
45
(<code>++profile++show,callgrind</code> or
46
<code>++profile++show,pstats</code>).</tal:block></p>
71
(<code>++profile++pstats</code>), an HTML view of the SQL and the
72
Python stacktrace when each SQL call was made
73
(<code>++profile++sqltrace</code>), or an HTML view of only the SQL
74
(<code>++profile++sql</code>). You can also combine these
75
(<code>++profile++show&callgrind</code> or
76
<code>++profile++show&pstats</code> or others, with each action separated
77
with ampersands).</tal:block></p>
78
<p>The <code>++profile++sqltrace</code> can take too much time to let a
79
page practically render, especially on qastaging and staging. You can
80
filter to only get the stacktraces you want in this case; see information
81
in the "SQL trace" section below on how to do this.</p>
47
82
<p>The "++profile++" path segment can usually go anywhere in the URL
48
83
(e.g., <code>http://launchpad.dev/++profile++show</code> or
49
84
<code>http://launchpad.dev/++profile++show/Firefox</code> or
111
146
href="http://docs.python.org/library/profile.html#instant-user-s-manual"
112
147
>Python documentation</a>.</p>
150
<tal:block condition="not:sqltrace">
151
<p>Use <code>++profile++sqltrace</code> in your URL to see the SQL that
152
the page runs, along with start and stop times, the database used, and the
153
stacktrace for when each sql call is made.</p>
154
<p>If you only want SQL and not the tracebacks,
155
<code>++profile++sql</code> will give you what you want, or
156
<code>++profile++show</code> will include OOPS data at the end of the
157
profiling information.</p>
158
<p>If you want stacktraces only for certain SQL statements, you can do
159
that too. You can use <code>startswith</code>, <code>endswith</code>
160
or <code>includes</code> to specify parts of the SQL that you want to use
161
as triggers. Note that this is whitespace and case normalized, so you
162
just need to get the spelling right. Here are some examples.</p>
164
<dt><code>/++profile++sqltrace: includes Product.blueprints_usage/</code>
166
<dd>This will get a stacktrace for any SQL statement that has the
167
string "Product.blueprints_usage" in it.</dd>
168
<dt><code>/++profile++sqltrace:startswith SELECT
169
Distribution.answers_usage/</code> </dt>
170
<dd>This will get a stacktrace for any SQL statement that starts with the
171
string "SELECT Distribution.answers_usage" in it.</dd>
172
<dt><code>/++profile++sqltrace:endswith WHERE Project.id = 5 LIMIT
174
<dd>This will get a stacktrace for any SQL statement that ends with the
175
string given. Note that it does not end in a semicolon, and note that
176
parameters are filled in.</dd>
178
<p>You can also combine requests with the <code>|</code> mark (the
179
pipe). Here's an example:
180
<code>/++profile++sqltrace:startswith SELECT Distribution.answers_usage |
181
includes Product.blueprints_usage/</code>.</p>
183
<tal:block condition="sqltrace">
184
<p tal:condition="options/sql_traceback_all|nothing">You have requested
185
tracebacks for all SQL statements. You can filter these with conditions
186
like <code>startswith</code>, <code>endswith</code> or
187
<code>includes</code>. Here's a simple example:
188
<code>/++profile++sqltrace: includes Product.blueprints_usage/</code>.</p>
189
<p tal:condition="options/sql_traceback_none|nothing">You have requested no
190
tracebacks. Use <code>++profile++sqltrace</code> to get tracebacks.</p>
191
<tal:block condition="options/sql_traceback_conditions|nothing">
192
<p>You have requested tracebacks for statements that match only certain
195
condition="not:options/sql_traceback_conditions/included">
196
<p><strong> You had no valid conditions, so no tracebacks were
197
included.</strong> The available conditions are <code>startswith</code>,
198
<code>endswith</code> or <code>includes</code>. Here's a simple
200
<pre>++profile++sqltrace: includes Product.blueprints_usage/</pre>
203
<li tal:repeat="condition options/sql_traceback_conditions/included">
204
<em tal:content="condition/constraint">CONSTRAINT</em>
205
<span tal:replace="condition/value">VALUE</span>
208
<tal:block condition="options/sql_traceback_conditions/ignored">
209
<p><strong>Warning</strong>: these conditions were not understood, and
212
<li tal:repeat="condition options/sql_traceback_conditions/ignored">
213
<em tal:content="condition/constraint">CONSTRAINT</em>
214
<span tal:replace="condition/value">VALUE</span>
219
<h3>Top 10 SQL times</h3>
221
<li tal:repeat="info options/top_sql" tal:attributes="class info/cls">
222
<a tal:attributes="href string:#sqlstep-${info/ix}">Query number
223
<tal:block tal:content="info/ix"></tal:block></a> (<tal:block
224
replace="info/value"></tal:block> milliseconds)
227
<h3>Top 10 Python times</h3>
228
<p tal:condition="options/sql_traceback_all|nothing">Note that generating
229
stacktraces can add significantly to these numbers, and skew results. Use
230
<code>++profile++sql</code> for a more accurate view.</p>
231
<p tal:condition="options/sql_traceback_conditions|nothing">Note that
232
generating stacktraces can add significantly to these numbers, and
233
selectively choosing when to generate stacktraces will produce so much
234
skew as to potentially make these values meaningless. Use
235
<code>++profile++sql</code> for the most accurate view.</p>
237
<li tal:repeat="info options/top_python" tal:attributes="class info/cls">
238
<a tal:attributes="href string:#pythonstep-${info/ix}">Before query
239
number <tal:block tal:content="info/ix"></tal:block></a> (<tal:block
240
replace="info/value"></tal:block> milliseconds)
243
<tal:block condition="not: options/sql_traceback_none|nothing">
244
<h3>Repeated Python SQL Triggers</h3>
245
<p tal:condition="options/sql_traceback_conditions|nothing">These are
246
only calculated for the stacktraces that were collected.</p>
247
<p tal:condition="not: options/top_triggers">None.</p>
248
<div tal:condition="options/top_triggers">
249
<p>Typically, these show loops. The traceback may show extra
250
information, such as from page templates, that indicate the variable
251
within the loop. If you want to add more information to identify the
252
variables in the loop, in your Python add either an informational
253
string with the variable name <code>__traceback_info__</code>, or add
254
a <code>__traceback_supplement__</code> as used in
255
lp.services.stacktrace.</p>
256
<div tal:repeat="trigger options/top_triggers">
257
<div>File "<tal:block
258
replace="trigger/filename"></tal:block>", line <tal:block
259
replace="trigger/lineno"></tal:block></div>
260
<div class="querylinks"> <tal:block
261
replace="trigger/count"></tal:block> related queries (<a href="#"
262
class="expandall">expand all tracebacks</a>): <span tal:repeat="ix
263
trigger/indexes"> <a tal:attributes="href string:#sqlstep-${ix}"
264
tal:content="ix"></a> </span> </div>
268
<h3>SQL (<tal:block replace="options/sql_count"></tal:block> queries)</h3>
269
<p>Each sql line begins with the start time and the stop time, along with
270
the name of the database on which the query ran. Times are in
271
milliseconds since request start.</p>
272
<div tal:condition="not:options/sql_traceback_none|nothing"><a href="#"
273
id="show-all-tracebacks">Show all tracebacks</a> / <a href="#"
274
id="hide-all-tracebacks">Hide all tracebacks</a></div>
275
<div tal:repeat="step sqltrace_steps">
276
<div tal:condition="step/python_rank|nothing" tal:attributes="class
277
string: python_topten ${step/python_class}; id
278
string:pythonstep-${step/id}"><strong>Top ten (# <tal:block
279
replace="step/python_rank"></tal:block>):</strong> Python work took
280
<span tal:replace="step/python_time" /> milliseconds in-between SQL
282
<div tal:attributes="class string: sqlstep ${step/sql_class|nothing};
283
id string:sqlstep-${step/id};">
284
<div class="sqlinfo">
285
<div class="col1"><span><tal:block replace="step/id"></tal:block>.
286
<span class="sqlstats"><span
287
tal:replace="step/sql/start"></span> - <span
288
tal:replace="step/sql/stop"></span> @ <tal:block
289
replace="step/sql/name"></tal:block></span></span> <span
290
tal:condition="step/sql_rank|nothing"><strong>Top ten (# <tal:block
291
replace="step/sql_rank"></tal:block>):</strong> SQL took <span
292
tal:replace="step/sql_time" /> milliseconds</span></div> <a href="#"
293
class="clicktext" tal:condition="step/stack">Click to toggle Python
294
traceback.</a><span tal:condition="not:step/stack">--</span>
296
<div class="trace" tal:condition="step/stack"><div class="inner">
297
<div class="appstack" tal:define="stack step/app_stack">
298
<div tal:repeat="frame stack" metal:define-macro="draw-stack">
299
<div>File "<tal:block replace="frame/filename"></tal:block>",
300
line <tal:block replace="frame/lineno"></tal:block>, in
301
<tal:block replace="frame/name"></tal:block></div>
302
<div tal:condition="frame/line" tal:content="frame/line" class="line"></div>
303
<div tal:define="supp frame/supplement" tal:condition="supp" class="supplement">
304
<div tal:condition="supp/source_url" tal:content="supp/source_url"></div>
305
<div tal:define="line supp/line; column supp/column;"
306
tal:condition="python:line or column">
307
<tal:block condition="line">Line <span tal:replace="line"></span><tal:block condition="column">, </tal:block></tal:block>
308
<tal:block condition="column">Column <span tal:replace="column"></span></tal:block>
310
<div tal:condition="supp/expression">Expression: <code tal:content="supp/expression"></code></div>
311
<div tal:condition="supp/warnings">
312
<div tal:repeat="warning supp/warnings" class="tracebackwarning">Warning: <span tal:replace="supp/warnings"></span></div>
314
<pre tal:condition="supp/extra"
315
tal:content="supp/extra"></pre>
317
<pre tal:condition="frame/info" tal:content="frame/info" class="extrainfo"></pre>
320
<div class="dbstack" tal:define="stack step/db_stack">
321
<div metal:use-macro="template/macros/draw-stack"></div>
324
<pre tal:attributes="class string: sql ${step/sql_class|nothing}" tal:content="step/sql/statement"></pre>
114
328
<h2>Profile quick view</h2>
115
329
<tal:block condition="not:show">
116
330
<p>Use <code>++profile++show</code> in your URL in order to see immediate
117
profile results (or <code>++profile++callgrind,show</code> or
118
<code>++profile++pstats,show</code> to see both the log information and
331
profile results (or <code>++profile++callgrind&show</code> or
332
<code>++profile++pstats&show</code> to see both the log information and
119
333
immediate results).</p>
121
335
<tal:block condition="show">
136
LPS.use('node', 'lp', function (Y) {
350
LPS.use('node', 'lp', 'transition', function (Y) {
137
351
Y.one('div#reveal_profiling').on('click', function (e) {
138
352
Y.one('div#profiling_info').setStyle('display', 'block');
140
355
Y.one('div#hide_profiling').on('click', function (e) {
141
356
Y.one('div#profiling_info').setStyle('display', 'none');
361
<script tal:condition="not:options/sql_traceback_none|nothing">
362
LPS.use('node', 'lp', 'transition', function (Y) {
363
function slideIn(target) {
366
duration: 0.75, // seconds
369
target.setStyle('display', 'none');
372
function slideOut(target) {
373
target.setStyles({display: 'block', height: '0px'});
374
var inner = target.one('.inner');
375
var height = parseInt(inner.getComputedStyle('height'));
378
duration: 0.75, // seconds
381
target.setStyle('height', 'auto');
384
// We use "all" on these two as a lazy way to handle the possibility
385
// that the link may not be there.
386
Y.all('#show-all-tracebacks').on('click', function (e) {
387
// For speed, just force them all open without animation.
388
Y.all('.trace').setStyles({display: 'block', height: 'auto'});
391
Y.all('#hide-all-tracebacks').on('click', function (e) {
392
// For speed, just force them all closed without animation.
393
Y.all('.trace').setStyle('display', 'none');
396
Y.all('.expandall').on('click', function (e) {
397
var links = e.currentTarget.ancestor('.querylinks').all('span a');
398
links.each(function (link) {
399
var href = link.get('href');
400
var identifier = href.slice(href.indexOf('#'));
401
var target = Y.one(identifier).one('.trace');
402
// target.setStyles({display: 'block', height: 'auto'});
403
if (target.getStyle('display') !== 'block') {
409
Y.on('load', function(e) {
410
// We hide the tracebacks with Javascript so that, if the Javascript
411
// does not load, we still can easily see the tracebacks.
412
Y.all('.trace').setStyle('display', 'none');
413
Y.all('.sqlinfo').on('click', function(e) {
414
var trace = e.currentTarget.ancestor('.sqlstep').one('.trace');
415
if (trace.getStyle('display') === 'block') {