~launchpad-pqm/launchpad/devel

« back to all changes in this revision

Viewing changes to lib/lp/services/profile/profile.pt

  • Committer: Launchpad Patch Queue Manager
  • Date: 2011-08-23 21:54:33 UTC
  • mfrom: (13723.1.7 sqlprofiler)
  • Revision ID: launchpad@pqm.canonical.com-20110823215433-77gtrsn5v1coarbl
[r=gmb][bug=832208, 832215] Add ++profile++sqltrace,
        and extended frame information to LP_DEBUG_SQL_EXTRA.

Show diffs side-by-side

added added

removed removed

Lines of Context:
 
1
<!-- Style is supposed to go in the head. We don't have one here. This seems
 
2
to work for FF and WebKit. -->
 
3
<style type="text/css">
 
4
.python_topten {margin-bottom: 4px;}
 
5
.python_danger {background-color: red;}
 
6
.python_warning {background-color: yellow;}
 
7
.sql_danger .sqlstep {background-color: red;}
 
8
.sql_warning .sqlstep {background-color: yellow;}
 
9
.trace .dbstack {font-size: smaller; color: gray}
 
10
.sqlinfo {border-bottom: 1px gray dotted; padding-bottom: 2px;}
 
11
.sqlstats {margin-left: 1ex;}
 
12
.sqlstep {border: LightGray solid 1px; margin-bottom: 4px;}
 
13
.sqlstep.sql_danger {border-color: red;}
 
14
.sqlstep.sql_warning {border-color: yellow;}
 
15
.sqlstep .trace {background-color: GhostWhite; font-size: small; clear: both;}
 
16
.sqlstep .trace .line {margin-left: 2em; font-family: monospace;}
 
17
.sqlstep .trace .supplement, .sqlstep .trace .extrainfo {
 
18
    font-weight: bold; margin-left: 2em;}
 
19
.tracebackwarning {color: red;}
 
20
.col1 {width: 60em; float: left;}
 
21
a.clicktext {font-weight: normal;}
 
22
.trace {overflow: hidden;}
 
23
.trace.inner {height: auto; overflow: hidden;}
 
24
.querylinks {margin-left: 2em;}
 
25
</style>
1
26
<div class="profiling_info">
2
27
  <div class="hide_reveal_profiling" id="reveal_profiling">
3
 
  Click to REVEAL profiling information
 
28
  <a href="#">Click to REVEAL profiling information</a>
4
29
  </div>
5
30
</div>
6
31
<div class="profiling_info" id="profiling_info"
22
47
                 multiple_profiles options/multiple_profiles|nothing;
23
48
                 inline_ignored actions/inline_ignored|nothing;
24
49
                 inline actions/inline|nothing;
 
50
                 sqltrace actions/sqltrace|nothing;
 
51
                 sqltrace_steps options/sqltrace|nothing;
25
52
                 ">
26
53
  <div class="hide_reveal_profiling" id="hide_profiling">
27
 
  Click to HIDE profiling information
 
54
  <a href="#">Click to HIDE profiling information</a>
28
55
  </div>
29
56
  <h1>Profiling Information</h1>
30
57
  <tal:block condition="help">
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
67
    view (<code>++profile++show</code>), a KCacheGrind-friendly log on the
41
 
    filesystem (<code>++profile++callgrind</code>), or a PStats-friendly log
 
68
    filesystem (<code>++profile++callgrind</code>), a PStats-friendly log
42
69
    (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
 
70
    (<code>++profile++pstats</code>), or an HTML view of the SQL and the
 
71
    Python stacktrace when each SQL call was made
 
72
    (<code>++profile++sqltrace</code>). You can also combine these
45
73
    (<code>++profile++show,callgrind</code> or
46
 
    <code>++profile++show,pstats</code>).</tal:block></p>
 
74
    <code>++profile++show,pstats</code> or others,
 
75
    with each action separated with commas).</tal:block></p>
47
76
    <p>The "++profile++" path segment can usually go anywhere in the URL
48
77
    (e.g., <code>http://launchpad.dev/++profile++show</code> or
49
78
    <code>http://launchpad.dev/++profile++show/Firefox</code> or
111
140
    href="http://docs.python.org/library/profile.html#instant-user-s-manual"
112
141
    >Python documentation</a>.</p>
113
142
  </tal:block>
 
143
  <h2>SQL trace</h2>
 
144
  <tal:block condition="not:sqltrace">
 
145
    <p>Use <code>++profile++sqltrace</code> in your URL to see the SQL that
 
146
    the page runs, along with start and stop times, the database used, and the
 
147
    stacktrace for when each sql call is made.</p> <p>Note that if you do not
 
148
    want the tracebacks, <code>++profile++show</code> will include OOPS data
 
149
    at the end of the profiling information, which has what what you want.</p>
 
150
  </tal:block>
 
151
  <tal:block condition="sqltrace">
 
152
    <h3>Top 10 SQL times</h3>
 
153
    <ol>
 
154
      <li tal:repeat="info options/top_sql" tal:attributes="class info/cls">
 
155
        <a tal:attributes="href string:#sqlstep-${info/ix}">Query number
 
156
        <tal:block tal:content="info/ix"></tal:block></a> (<tal:block
 
157
        replace="info/value"></tal:block> milliseconds)
 
158
      </li>
 
159
    </ol>
 
160
    <h3>Top 10 Python times</h3>
 
161
    <ol>
 
162
      <li tal:repeat="info options/top_python" tal:attributes="class info/cls">
 
163
        <a tal:attributes="href string:#pythonstep-${info/ix}">Before query
 
164
        number <tal:block tal:content="info/ix"></tal:block></a> (<tal:block
 
165
        replace="info/value"></tal:block> milliseconds)
 
166
      </li>
 
167
    </ol>
 
168
    <h3>Repeated Python SQL Triggers</h3>
 
169
    <p tal:condition="not: options/top_triggers">None.</p>
 
170
    <div tal:condition="options/top_triggers">
 
171
      <p>Typically, these show loops.  The traceback may show extra
 
172
      information, such as from page templates, that indicate the variable
 
173
      within the loop.  If you want to add more information to identify the
 
174
      variables in the loop, in your Python add either an informational string
 
175
      with the variable name <code>__traceback_info__</code>, or add a
 
176
      <code>__traceback_supplement__</code> as used in
 
177
      lp.services.stacktrace.</p>
 
178
      <div tal:repeat="trigger options/top_triggers">
 
179
        <div>File &quot;<tal:block replace="trigger/filename"></tal:block>&quot;,
 
180
              line <tal:block replace="trigger/lineno"></tal:block></div>
 
181
        <div class="querylinks">
 
182
          <tal:block replace="trigger/count"></tal:block> related queries (<a
 
183
          href="#" class="expandall">expand all tracebacks</a>): <span
 
184
          tal:repeat="ix trigger/indexes"> <a tal:attributes="href
 
185
          string:#sqlstep-${ix}" tal:content="ix"></a> </span>
 
186
        </div>
 
187
      </div>
 
188
    </div>
 
189
    <h3>SQL (<tal:block replace="options/sql_count"></tal:block> queries)</h3>
 
190
    <p>Each sql line begins with the start time and the stop time, along with
 
191
    the name of the database on which the query ran.  Times are in
 
192
    milliseconds since request start.</p>
 
193
    <div><a href="#" id="show-all-tracebacks">Show all tracebacks</a> / <a href="#"
 
194
    id="hide-all-tracebacks">Hide all tracebacks</a></div>
 
195
    <div tal:repeat="step sqltrace_steps">
 
196
      <div tal:condition="step/python_rank|nothing" tal:attributes="class
 
197
      string: python_topten ${step/python_class}; id
 
198
      string:pythonstep-${step/id}"><strong>Top ten (# <tal:block
 
199
      replace="step/python_rank"></tal:block>):</strong> Python work took
 
200
      <span tal:replace="step/python_time" /> milliseconds in-between SQL
 
201
      calls.</div>
 
202
      <div tal:attributes="class string: sqlstep ${step/sql_class|nothing};
 
203
                           id string:sqlstep-${step/id};">
 
204
        <div class="sqlinfo">
 
205
          <div class="col1"><span><tal:block replace="step/id"></tal:block>.
 
206
          <span class="sqlstats"><span
 
207
          tal:replace="step/sql/start"></span> - <span
 
208
          tal:replace="step/sql/stop"></span> @ <tal:block
 
209
          replace="step/sql/name"></tal:block></span></span> <span
 
210
          tal:condition="step/sql_rank|nothing"><strong>Top ten (# <tal:block
 
211
          replace="step/sql_rank"></tal:block>):</strong> SQL took <span
 
212
          tal:replace="step/sql_time" /> milliseconds</span></div> <a href="#"
 
213
          class="clicktext">Click to toggle Python traceback.</a>
 
214
        </div>
 
215
        <div class="trace"><div class="inner">
 
216
          <div class="appstack" tal:define="stack step/app_stack">
 
217
            <div tal:repeat="frame stack" metal:define-macro="draw-stack">
 
218
              <div>File &quot;<tal:block replace="frame/filename"></tal:block>&quot;,
 
219
              line <tal:block replace="frame/lineno"></tal:block>, in
 
220
              <tal:block replace="frame/name"></tal:block></div>
 
221
              <div tal:condition="frame/line" tal:content="frame/line" class="line"></div>
 
222
              <div tal:define="supp frame/supplement" tal:condition="supp" class="supplement">
 
223
                <div tal:condition="supp/source_url" tal:content="supp/source_url"></div>
 
224
                <div tal:define="line supp/line; column supp/column;"
 
225
                     tal:condition="python:line or column">
 
226
                <tal:block condition="line">Line <span tal:replace="line"></span><tal:block condition="column">, </tal:block></tal:block>
 
227
                <tal:block condition="column">Column <span tal:replace="column"></span></tal:block>
 
228
                </div>
 
229
                <div tal:condition="supp/expression">Expression: <code tal:content="supp/expression"></code></div>
 
230
                <div tal:condition="supp/warnings">
 
231
                  <div tal:repeat="warning supp/warnings" class="tracebackwarning">Warning: <span tal:replace="supp/warnings"></span></div>
 
232
                </div>
 
233
                <pre tal:condition="supp/extra"
 
234
                     tal:content="supp/extra"></pre>
 
235
              </div>
 
236
              <pre tal:condition="frame/info" tal:content="frame/info" class="extrainfo"></pre>
 
237
            </div>
 
238
          </div>
 
239
          <div class="dbstack" tal:define="stack step/db_stack">
 
240
            <div metal:use-macro="template/macros/draw-stack"></div>
 
241
          </div>
 
242
        </div></div>
 
243
        <pre  tal:attributes="class string: sql ${step/sql_class|nothing}" tal:content="step/sql/statement"></pre>
 
244
      </div>
 
245
    </div>
 
246
  </tal:block>
114
247
  <h2>Profile quick view</h2>
115
248
  <tal:block condition="not:show">
116
249
    <p>Use <code>++profile++show</code> in your URL in order to see immediate
133
266
  </tal:block>
134
267
</div>
135
268
<script>
136
 
LPS.use('node', 'lp', function (Y) {
 
269
LPS.use('node', 'lp', 'transition', function (Y) {
137
270
    Y.one('div#reveal_profiling').on('click', function (e) {
138
271
        Y.one('div#profiling_info').setStyle('display', 'block');
 
272
        e.preventDefault();
139
273
    });
140
274
    Y.one('div#hide_profiling').on('click', function (e) {
141
275
        Y.one('div#profiling_info').setStyle('display', 'none');
 
276
        e.preventDefault();
 
277
    });
 
278
    function slideIn(target) {
 
279
        target.transition({
 
280
            easing: 'ease-in',
 
281
            duration: 0.75, // seconds
 
282
            height: '0px'
 
283
        }, function() {
 
284
            target.setStyle('display', 'none');
 
285
        });
 
286
    }
 
287
    function slideOut(target) {
 
288
        target.setStyles({display: 'block', height: '0px'});
 
289
        var inner = target.one('.inner');
 
290
        var height = parseInt(inner.getComputedStyle('height'));
 
291
        target.transition({
 
292
            easing: 'ease-out',
 
293
            duration: 0.75, // seconds
 
294
            height: height+'px'
 
295
        }, function() {
 
296
            target.setStyle('height', 'auto');
 
297
        });
 
298
    }
 
299
    // We use "all" on these two as a lazy way to handle the possibility
 
300
    // that the link may not be there.
 
301
    Y.all('#show-all-tracebacks').on('click', function (e) {
 
302
        // For speed, just force them all open without animation.
 
303
        Y.all('.trace').setStyles({display: 'block', height: 'auto'});
 
304
        e.preventDefault();
 
305
    });
 
306
    Y.all('#hide-all-tracebacks').on('click', function (e) {
 
307
        // For speed, just force them all closed without animation.
 
308
        Y.all('.trace').setStyle('display', 'none');
 
309
        e.preventDefault();
 
310
    });
 
311
    Y.all('.expandall').on('click', function (e) {
 
312
        var links = e.currentTarget.ancestor('.querylinks').all('span a');
 
313
        links.each(function (link) {
 
314
            var href = link.get('href');
 
315
            var identifier = href.slice(href.indexOf('#'));
 
316
            var target = Y.one(identifier).one('.trace');
 
317
            // target.setStyles({display: 'block', height: 'auto'});
 
318
            if (target.getStyle('display') !== 'block') {
 
319
                slideOut(target);
 
320
            }
 
321
        });
 
322
        e.preventDefault();
 
323
    });
 
324
    Y.on('load', function(e) {
 
325
        // We hide the tracebacks with Javascript so that, if the Javascript
 
326
        // does not load, we still can easily see the tracebacks.
 
327
        Y.all('.trace').setStyle('display', 'none');
 
328
        Y.all('.sqlinfo').on('click', function(e) {
 
329
            var trace = e.currentTarget.ancestor('.sqlstep').one('.trace');
 
330
            if (trace.getStyle('display') === 'block') {
 
331
                slideIn(trace);
 
332
            } else {
 
333
                slideOut(trace);
 
334
            }
 
335
            e.preventDefault();
 
336
        });
142
337
    });
143
338
});
144
339
</script>