Profiling Tab 0.1

[dmclain]

I've been using some custom middleware for a while to get some rough profiling information and wanted to get something into the debug toolbar for convenience. Last night I finally got around to it, and this is the result.

The good

• Uses cProfile for low overhead profiling
• A table of the most expensive calls showing every function call that took over 1/16 of the cumulative running time
• Color coded bars to indicate which function calls are taking the most time
• Indentation to indicate call depth
• Javascript to toggle display of a functions subcalls
• File paths shortened to provide easier reading

The Bad

• Some of what is profiled is the debug toolbar itself (the SQL pane shows up a lot for me, especially the use of realpath, replacing it with abspath gives a dramatic performance improvement)
• The titles on the table are the same inscrutable acronyms from lsprof output
• No internationalization (I'm one of those terrible monolinguists, aka an American)
• I make some assumptions that might not necessarily be true about file paths including chopping off '/site-packages/' and everything before it and chopping off settings.PROJECT_ROOT, which might cause a crash if PROJECT_ROOT isn't set.
• Only tested on OSX

The Ugly

• Once you're about 4 function calls deep its kinda rough trying to figure out what function called a particular function
• I'm not super familiar with cProfile's internals, which are apparently a thing wrapper on lsprof. The method of figuring out how expensive subcalls are is kinda messy, all the stats tell you is "When function C was called by function B, it cost this much" and "When B was called by A, it cost this much" so if you have A->B->C and D->B->C, the B->C information is actually the same. This can lead to subcalls apparently taking more time than their callers.

[dcramer]

settings.PROJECT_ROOT is not defined in all scopes, you should be able to pull in the root urlconf or something similar to potentially default this setting

(I'm merging this into my branch right now to ensure some compatibility)

[dcramer]

Also, tons of lint violations :)

[dcramer]

And there's a loose print statement

[dcramer]

I'm going to overhaul some of the UX on this on my fork as well to bring it up to date with some changes I was doing to the SQL panel, possibly add in timeline support, and just other general enhancements. Like the concept so far though :)

[dcramer]

There's also an issue on first load that profile doesnt load correctly

[dmclain]

Thanks dcramer, would love to see what somebody with some decent UX chops could do. What tool are you using to lint? I'm a fairly recent convert to python/django from java and am still trying to figure out the best way to do things. In retrospect there was probably a lot of cleanup I should have done before pushing this into the world.

[dcramer]

Linting: I use SublimeLint for Sublime Text 2, and a bundle I wrote for TextMate: http://justcramer.com/2010/11/30/integrating-pyflakes-into-textmate/

[dcramer]

Something else I want to note, we might be able to integrate line_profiler (which is a fair bit nicer for this kind of profiling) as an alternative

Here's an example in django-devserver: dcramer/django-devserver#29

[dmclain]

I've actually got a local only branch that combines line_profiler output with the cProfiler output. The issues on that pull requests are essentially identical to this one. Figuring out what function/functions to profile needs to be done before they're run since they need to be explicitly set.

In the process_view function there's a pointer to the view function, but if the user is using any decorators, you end up profiling the decoration. I've got a terribly hacky method of recursively unrolling decoration closures, but that doesn't solve the problem of any subfunctions that ought to be profiled.

[dmclain]

If anybody wants to take a look at the code that integrates line_profiler it's at https://github.com/dmclain/django-debug-toolbar/tree/line_profiler_int

[dcramer]

This is now merged in (though GitHub doesnt seem to think so)