Merge lp://staging/~gary/launchpad/sqlprofiler into lp://staging/launchpad

Proposed by Gary Poster
Status: Merged
Approved by: Graham Binns
Approved revision: no longer in the source branch.
Merged at revision: 13771
Proposed branch: lp://staging/~gary/launchpad/sqlprofiler
Merge into: lp://staging/launchpad
Diff against target: 1168 lines (+905/-29)
6 files modified
lib/canonical/launchpad/webapp/adapter.py (+42/-9)
lib/lp/services/profile/profile.pt (+202/-7)
lib/lp/services/profile/profile.py (+111/-4)
lib/lp/services/profile/tests.py (+36/-9)
lib/lp/services/stacktrace.py (+227/-0)
lib/lp/services/tests/test_stacktrace.py (+287/-0)
To merge this branch: bzr merge lp://staging/~gary/launchpad/sqlprofiler
Reviewer Review Type Date Requested Status
Graham Binns (community) code Approve
Review via email: mp+72491@code.staging.launchpad.net

Commit message

[r=gmb][bug=832208,832215] Add ++profile++sqltrace, and extended frame information to LP_DEBUG_SQL_EXTRA.

Description of the change

This code, like other recent work on ++profile++, has fallen out of analysis work I've done for bug 724025. I worked a bit on extra-work time to polish it up.

This is a big branch, at over 1100 lines. It would be relatively easy to divide it up in two, and I will do so if requested. On the other hand, it is so easy to divide in two that I'm hoping a reviewer who might have had to look at both branches anyway would just run with the existing MP.

This branch makes two feature additions for developers.

First, when you use existing SQL profiling using LP_DEBUG_SQL_EXTRA, the traceback now includes extra information provided by code that follows the patterns from the zope.exceptions package. Practically, this means that tracebacks will show you the information about page template rendering, such as what template, what line and column, and what TAL expression caused the sql call that you see. It also means that you can use the zope.exceptions pattern to add information to your own parsing code and loops to give more information when you analyze these tracebacks.

Second, the ++profile++ page now includes a sqltrace option. This has a number of advantages over using the LP_DEBUG_SQL_EXTRA environmental variable approach. First, generating the tracebacks is not cheap, and it is nice to be able to selectively decide when you want them when you are working. Second, many of our pages now have multiple JS requests to assemble them; when using the environmental variable and multiple threads on the server, requests cause interleaving of the results on stderr. Third, we can get the results of this analysis on qastaging or staging with no or minimal LOSA help. (The minimal help may be necessary to increase the timeout of the page you are examining, using feature flags).

The ++profile++ changes are more feature-full than I intended because of some cool additional ideas from Benji, and some weekend hacking time from me. The page lets you expand tracebacks, and gives a bit of analysis of the results with some convenient controls and links. It certainly now points clearly to some of the problems I have identified on the branch I have been working on.

A third, small change is that the LP_DEBUG_SQL_EXTRA stderr display now includes the start and stop time of the request in milliseconds, as you find it in the OOPS tools.

lint complains as usual about the ++profile++ template, but it's spurious IMO. It is otherwise happy.

./lib/lp/services/profile/profile.pt
      26: junk after document element

I did a pretty good job at tests for the underlying feature: a new stacktrace module that replaces some of the stdlib traceback module functions. It's a shame zope.exceptions is not factored in such a way as to not require a new module. I've toyed with the idea of making a new and updated package and releasing it on PyPI. For now, it's fine where it is, I think. I originally called it traceback.py, but I didn't want to mask the standard library traceback module for other lp.services modules, so I changed it to stacktrace.

In contrast, the tests for the new ++profile++ features displaying the stacktraces are only one step above smoketests. I thought it was OK in the context of a developer analysis page, and with the underlying machinery well tested.

The changes to adapter.py are not any more tested than the previous sql profiling code was: not at all.

If I were to divide this up into two branches, I would have one branch for the new stacktrace module and its use with LP_DEBUG_SQL_EXTRA, and another branch for the ++profile++ work.

Thank you

To post a comment you must log in.
Revision history for this message
Graham Binns (gmb) wrote :

Hi Gary,

This branch looks fine, though this:

674 +def _get_frame(f):
675 + "if the frame is None, make one."
676 + if f is None:
677 + try:
678 + raise ZeroDivisionError
679 + except ZeroDivisionError:
680 + f = sys.exc_info()[2].tb_frame.f_back.f_back
681 + return f

Gave me pause. It looks a bit hackish; I'm assuming that there's a reason to do it this way?

Anyways, r=me on the assumption that you know something that I don't (the likelihood of which tends towards 1).

review: Approve (code)
Revision history for this message
Gary Poster (gary) wrote :

Thank you, Graham!

The _get_frame code mirrors what the standard library's traceback module does, and I refactored some of that module for the stacktrace module. I suspect the traceback module uses that pattern because it does not want to rely on sys._getframe, which IIRC is a cPython implementation detail and not part of the official language description. Jython doesn't implement it, I think, for example. The traceback approach sticks to official APIs.

We are firmly in cPython ATM, and PyPy supports it if we ever wanted to try and switch, so I could use sys._getframe. I do in the tests, largely because it is easier to spell. That said, I'm kind of inclined to leave this as is; I have small dreams of trying to get a simplified version of this stuff in the stdlib some day, or at least as a separate library.

Gary

Revision history for this message
Graham Binns (gmb) wrote :

On 23 August 2011 17:46, Gary Poster <email address hidden> wrote:
> That said, I'm kind of inclined to leave this as is; I have small dreams of trying to get a simplified version of this stuff in the stdlib some day, or at least as a separate library.

Well, who am I to crush your dreams? ;)

That's fine, thanks for the explanation.

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
The diff is not available at this time. You can reload the page or download it.