Debugging stories/pagetests

Debugging stories (a.k.a. pagetests) can be kind of a pain because they build up state as they go. So if a test fails down deep in the doctest, and you want to see what the page really looks like at that point, you'd normally have to manually click through each step in the doctest until you get to the place that's broken.

But there's an easier way!

Just add this at the point where your pagetest is failing:

    >>> stop()

This is just a convenience wrapper around pdb.set_trace() except that it also redirects stdout back to your console. When your pagetest hits this line, you'll be dropped into the debugger. Now, go to a different shell and type:

    % make LPCONFIG=testrunner run

(Note from deryck: To get the above make run command working, I had to use the value in os.environ['LPCONFIG'] obtained at the pdb prompt, rather than just "testrunner")

This starts up the appserver, except that it will use the testrunner configuration. What's cool about that is that this configuration attaches to the same database as the pagetest you're now stopped inside of. Meaning, all that state your doctest has built up, is available to your browser. So just hit the URL of the page that your doctest is failing on, and see it in all it's wondrous, albeit borked, glory.

Additionally, it is also possible to connect directly to the database the page test is using.

    % psql -d launchpad_ftest

However, uncommitted transactions will not be visible in the database. So if there is something particular you are trying to query, like a bug subscription, you may need to add the following to the page test.

    >>> transaction.commit()

Debugging memory leaks

The app servers and the Librarian install a signal handler to dump their memory using meliae. To make use of that you just have to send the 44 signal to the appropriate process. This will create a file named /tmp/launchpad-memory.dump (or /tmp/librarian-memory.dump, for the Librarian), which you can debug later.

In general, though, the leaks will happen in production, so the LOSAs will give us a memory dump. Assuming you've got a memory.dump file, this is how you load it:

    $ ./bin/py
    >>> from meliae import loader
    >>> om = loader.load('memory.dump')
    >>> s = om.summarize(); s

This will give you a nice summary of the kinds of objects that consume the most memory. Something like

Total 704144 objects, 768 types, Total size = 129.5MiB (135823229 bytes)
 Index   Count   %      Size   % Cum     Max Kind
     0  108751  15  68190568  50  50 3146008 dict
     1  192992  27  16136424  11  62    6904 tuple
     2  162136  23  14850362  10  73   11103 str
     ...

You can then use that information to navigate the object tree as described in John Meinel's excellent post, and hopefully find what's leaking.

Debugging With GDB

Some kinds of bugs (segfaults, hung processes, out-of-control daemons) are hard to debug from within Python. See Debugging/GDB for how to debug them.

Special URLs

Launchpad provides special URLs that can be used to help with debugging.

Some of those can combined, like: ++debug++tal,source

Examples

https://launchpad.dev/++oops++

https://launchpad.dev/++debug++tal

https://launchpad.dev/++debug++source

https://launchpad.dev/++debug++error - XXX: returns an OOPS

https://launchpad.dev/++form++ - XXX: returns a 404

Tracing SQL statements through STORM

from storm.tracer import debug; debug(True)

This will cause all statements run by Storm to be written to stderr. debug(False) disables this behaviour.

This is useful when optimising pages to run fewer queries, as you can see exactly when and what is executed rather than pulled from cache.

Alternative to this is to set LP_DEBUG_SQL=1 environment variable before running make harness or make run (or LP_DEBUG_SQL_EXTRA=1 to get tracebacks for every query execution).

If you find the above handy but want more control turning it on and off, in the debugger you can do the following:

from storm.tracer import get_tracers
get_tracers()[0]._debug_sql = True
get_tracers()[0]._debug_sql_extra = True

Make sure the LaunchpadStatementTracer is the first in the results of get_tracers and modify as needed.

Tracing SQL statements with PostgreSQL

Statement logging can be configured in postgresql.conf, by setting log_statement to one of none, ddl, mod or all (docs). The server needs to be reloaded (by SIGHUP or pg_ctl reload) for changes to take effect.

It can also be set for a session, user or database:

  SET log_statement TO 'all'; -- (docs)

  ALTER ROLE launchpad SET log_statement TO 'all'; -- (docs)

  ALTER DATABASE launchpad_dev SET log_statement TO 'all'; -- (docs)

Once enabled, statements will be logged to /var/log/postgresql/postgresql-*-main.log.

Getting past "LocationError: 'json'" in TAL template tracebacks

If you're testing with a new TAL template (.pt file) and you get nasty-looking tracebacks that says something about

  LocationError: (<lazr.restful.tales.WebLayerAPI object at 0xd932ccc>, 'json')

then try visiting the corresponding URL in the web services API. For example, if https://bugs.launchpad.dev/redfish gets an unwieldy traceback, then try https://launchpad.dev/api/beta/redfish instead; you'll often get a much more comprehensible error trace that way.

Using iharness for digging error tracebacks

If you are reading this, most probably you have noticed that when things get wrong, ZOPE and TAL will rather give you a pointless LocationError without to much information about what is causing it.

To find out what exactly went wrong you can use make iharness and investigate that specific LocationError

Let's say that you got this error for language_translation_statistics:

LocationError: (<zope.browserpage.metaconfigure.SimpleViewClass
from PATH_TO_TEMPLATE/template.pt object at 0xcf60fec>,
'language_translation_statistics')

To start the testing/debugging environment (the harness) run:

make iharness

Next you will have to import your classed and get your object. In our example we were trying to get the PerLanguageStatisticsView for ubuntu['hoary'] series.

from canonical.launchpad.webapp.servers import LaunchpadTestRequest
from lp.our.module import  PerLanguageStatisticsView

#create and initialize the view
ubuntu = getUtility(ILaunchpadCelebrities).ubuntu
view = PerLanguageStatisticsView (ubuntu['hoary'], LaunchpadTestRequest())
view.initialize()

#request the view key
key = view.language_translation_statistics

Now you should see a more meaningful message.

Profiling page requests

You can generate KCacheGrind profiles of requests on your local system.

On your developer machine, try going to https://launchpad.dev/++profile++ or https://launchpad.dev/++profile++/~mark/+archive/ppa . Inserting ++profile++ in the URL like this will give you instructions on how to use the feature.

Right now, you can use it to generate immediate profiles in the browser (++profile++show), profiles on the filesystem ready for kcachegrind (++profile++log), or both (++profile++show,log).

If you want to use this on staging or qastaging, ask a LOSA to enable it for you, and to disable it again when you're done. Robert's further idea is to constrain this with feature flags (https://dev.launchpad.net/LEP/FeatureFlags) to, say, Canonical Launchpad developers, and then add an ability to download profiles (++profile++download, for instance). Maybe then we could open it up to staging, at least.

You can also turn on a configuration variable to profile every request. Edit configs/development/launchpad-lazr.conf and add the following section:

[profiling]
profile_requests: True

Then start the development server and make ONE request to the URL you wish to profile:

$ make run
... server starts...
$ curl -k https://launchpad.dev/ -o /dev/null
# or
$ wget --no-check-certificate https://launchpad.dev

You can now load the resulting *.prof file into KCacheGrind

$ kcachegrind 2010-07-20_10\:01\:46.680-RootObject\:index.html-OOPS-1662X1-Dummy-2.prof

The doc for these features is lib/canonical/launchpad/doc/profiling.txt .

Debugging production OpenID problems

You can use the production OpenID provider to debug problems that can't be reproduced with the test provider by changing configs/development/launchpad-lazr.conf thusly:

 [vhost.testopenid]
-hostname: testopenid.dev
+hostname: login.launchpad.net

Debugging security proxy problems

Ever wondered which attributes are protected on an instance and by which permission? You can use debug_proxy to get the information you need.

Example make harness session:

francis@Casteneda:~/canonical/launchpad/bug-365098$ make harness
bin/harness
execute_zcml_for_scripts()...
Reading $PYTHONSTARTUP...
Initializing storm...
Creating the factory...

>>> from lp.registry.interfaces.distribution import IDistributionSet
>>> ubuntu = getUtility(IDistributionSet).getByName('ubuntu')
>>> evolution = ubuntu.currentseries.getSourcePackage('evolution')
>>> from lazr.restful.debug import debug_proxy
>>> debug_proxy(evolution)
'zope.security._proxy._Proxy (using zope.security.checker.Checker)\n    
public: __eq__, __getitem__, __hash__, __ne__, _getOfficialTagClause, 
all_bugtasks, bug_reported_acknowledgement, bug_reporting_guidelines, 
bugtargetdisplayname, bugtargetname, bugtasks, closed_bugtasks, createBug, 
critical_bugtasks, currentrelease, deletePackaging, development_version, 
direct_packaging, displayname, distinctreleases, distribution, 
distribution_sourcepackage, distroseries, enable_bugfiling_duplicate_search, 
format, getBranch, getBranches, getBugCounts, getBugTaskWeightFunction, 
getBuildRecords, getCurrentTemplatesCollection, getCurrentTranslationFiles, 
getCurrentTranslationTemplates, getFirstEntryToImport, 
getLatestTranslationsUploads, getMergeProposals, getPocketPath, 
getSharingDetailPermissions, getSharingPartner, getSuiteSourcePackage, 
getTemplatesAndLanguageCounts, getTemplatesCollection, 
getTranslationImportQueueEntries, getTranslationTemplateByName, 
getTranslationTemplateFormats, getTranslationTemplates, getUsedBugTags, 
getUsedBugTagsWithOpenCounts, get_default_archive, has_bugtasks, 
has_current_translation_templates, has_obsolete_translation_templates, 
has_sharing_translation_templates, has_translation_files, 
has_translation_templates, high_bugtasks, id, inprogress_bugtasks, 
latest_published_component, latest_published_component_name, linkedBranches, 
linked_branches, max_bug_heat, name, newCodeImport, new_bugtasks, 
official_bug_tags, open_bugtasks, packaging, path, product, productseries, 
published_by_pocket, recalculateBugHeatCache, releases, searchTasks, 
setBranch, setMaxBugHeat, setPackaging, 
setPackagingReturnSharingDetailPermissions, shouldimport, sourcepackagename, 
summary, title, unassigned_bugtasks\n'

CategoryTipsAndTricks CategoryTesting