launchpad-reviewers team mailing list archive
-
launchpad-reviewers team
-
Mailing list archive
-
Message #02530
[Merge] lp:~allenap/launchpad/use-zope-tb-formatter into lp:launchpad
Gavin Panella has proposed merging lp:~allenap/launchpad/use-zope-tb-formatter into lp:launchpad.
Requested reviews:
Launchpad code reviewers (launchpad-reviewers)
Related bugs:
#714820 Many ExpatErrors from checkwatches
https://bugs.launchpad.net/bugs/714820
For more details, see:
https://code.launchpad.net/~allenap/launchpad/use-zope-tb-formatter/+merge/48843
This branch does two things:
- Adds some __traceback_info__ to Urllib2Transport, via a new function
traceback_info().
Urllib2Transport is used when talking to Bugzilla instances that do
(or might) support XML-RPC. The traceback info is set to the full
response from the remote system. Hopefully knowing what this is will
give us some insight into what is going wrong.
- Uses zope.exceptions to format logged exceptions, which means that
the traceback info will be included.
The OOPS tools already use zope.exceptions to format exceptions so
this extra info should show up in OOPS reports soon.
--
https://code.launchpad.net/~allenap/launchpad/use-zope-tb-formatter/+merge/48843
Your team Launchpad code reviewers is requested to review the proposed merge of lp:~allenap/launchpad/use-zope-tb-formatter into lp:launchpad.
=== modified file 'lib/canonical/launchpad/scripts/logger.py'
--- lib/canonical/launchpad/scripts/logger.py 2010-12-20 20:36:16 +0000
+++ lib/canonical/launchpad/scripts/logger.py 2011-02-07 20:54:15 +0000
@@ -15,13 +15,20 @@
# Don't import stuff from this module. Import it from canonical.scripts
__all__ = [
+ 'DEBUG2',
+ 'DEBUG3',
+ 'DEBUG4',
+ 'DEBUG5',
+ 'DEBUG6',
+ 'DEBUG7',
+ 'DEBUG8',
+ 'DEBUG9',
+ 'LaunchpadFormatter',
'log',
'logger',
'logger_options',
'OopsHandler',
- 'LaunchpadFormatter',
- 'DEBUG2', 'DEBUG3', 'DEBUG4', 'DEBUG5',
- 'DEBUG6', 'DEBUG7', 'DEBUG8', 'DEBUG9',
+ 'traceback_info',
]
@@ -38,10 +45,11 @@
import re
import sys
import time
-import traceback
+from traceback import format_exception_only
from pytz import utc
from zope.component import getUtility
+from zope.exceptions.log import Formatter
from canonical.base import base
from canonical.config import config
@@ -55,7 +63,6 @@
)
from lp.services.log import loglevels
-
# Reexport our custom loglevels for old callsites. These callsites
# should be importing the symbols from lp.services.log.loglevels
DEBUG2 = loglevels.DEBUG2
@@ -68,6 +75,16 @@
DEBUG9 = loglevels.DEBUG9
+def traceback_info(info):
+ """Set `__traceback_info__` in the caller's locals.
+
+ This is more aesthetically pleasing that assigning to __traceback_info__,
+ but it more importantly avoids spurious lint warnings about unused local
+ variables, and helps to avoid typos.
+ """
+ sys._getframe(1).f_locals["__traceback_info__"] = info
+
+
class OopsHandler(logging.Handler):
"""Handler to log to the OOPS system."""
@@ -91,7 +108,7 @@
self.handleError(record)
-class LaunchpadFormatter(logging.Formatter):
+class LaunchpadFormatter(Formatter):
"""logging.Formatter encoding our preferred output format."""
def __init__(self, fmt=None, datefmt=None):
@@ -124,7 +141,7 @@
Returns the URL, or the formatted exception if the Librarian is
not available.
"""
- traceback = logging.Formatter.formatException(self, ei)
+ traceback = LaunchpadFormatter.formatException(self, ei)
# Uncomment this line to stop exception storage in the librarian.
# Useful for debugging tests.
# return traceback
@@ -158,7 +175,7 @@
# information, we can stuff our own problems in there too.
return '%s\n\nException raised in formatter:\n%s\n' % (
traceback,
- logging.Formatter.formatException(self, sys.exc_info()))
+ LaunchpadFormatter.formatException(self, sys.exc_info()))
def logger_options(parser, default=logging.INFO):
@@ -408,7 +425,7 @@
def shortException(self, msg, *args):
"""Like Logger.exception, but does not print a traceback."""
exctype, value = sys.exc_info()[:2]
- report = ''.join(traceback.format_exception_only(exctype, value))
+ report = ''.join(format_exception_only(exctype, value))
# _log.error interpolates msg, so we need to escape % chars
msg += '\n' + report.rstrip('\n').replace('%', '%%')
self._log.error(msg, *args)
=== modified file 'lib/canonical/launchpad/scripts/tests/test_logger.py'
--- lib/canonical/launchpad/scripts/tests/test_logger.py 2010-10-04 19:50:45 +0000
+++ lib/canonical/launchpad/scripts/tests/test_logger.py 2011-02-07 20:54:15 +0000
@@ -6,13 +6,67 @@
__metaclass__ = type
__all__ = []
+import doctest
+from sys import exc_info
import unittest
+from testtools.matchers import DocTestMatches
+
+from canonical.launchpad.scripts.logger import (
+ LaunchpadFormatter,
+ traceback_info,
+ )
from canonical.launchpad.testing.systemdocs import LayeredDocFileSuite
from canonical.testing.layers import BaseLayer
+from lp.testing import TestCase
+
+
+DOCTEST_FLAGS = (
+ doctest.ELLIPSIS |
+ doctest.NORMALIZE_WHITESPACE |
+ doctest.REPORT_NDIFF)
+
+
+class TestTracebackInfo(TestCase):
+ """Tests of `traceback_info`."""
+
+ def test(self):
+ # The local variable __traceback_info__ is set by `traceback_info`.
+ self.assertEqual(None, locals().get("__traceback_info__"))
+ traceback_info("Pugwash")
+ self.assertEqual("Pugwash", locals().get("__traceback_info__"))
+
+
+class TestLaunchpadFormatter(TestCase):
+ """Tests of `LaunchpadFormatter`."""
+
+ def test_traceback_info(self):
+ # LaunchpadFormatter inherits from zope.exceptions.log.Formatter, so
+ # __traceback_info__ annotations are included in formatted exceptions.
+
+ traceback_info("Captain Kirk")
+
+ try:
+ 0/0
+ except ZeroDivisionError:
+ info = exc_info()
+
+ self.assertThat(
+ LaunchpadFormatter().formatException(info),
+ DocTestMatches(
+ flags=DOCTEST_FLAGS, example="""
+ Traceback (most recent call last):
+ ...
+ __traceback_info__: Captain Kirk
+ ZeroDivisionError: ...
+ """))
def test_suite():
- return unittest.TestSuite([
+ suite = unittest.TestSuite()
+ suite.addTest(
LayeredDocFileSuite(
- 'test_logger.txt', layer=BaseLayer),])
+ 'test_logger.txt', layer=BaseLayer))
+ suite.addTest(
+ unittest.TestLoader().loadTestsFromName(__name__))
+ return suite
=== modified file 'lib/lp/bugs/externalbugtracker/xmlrpc.py'
--- lib/lp/bugs/externalbugtracker/xmlrpc.py 2010-08-20 20:31:18 +0000
+++ lib/lp/bugs/externalbugtracker/xmlrpc.py 2011-02-07 20:54:15 +0000
@@ -6,11 +6,12 @@
__metaclass__ = type
__all__ = [
'UrlLib2Transport',
- 'XMLRPCRedirectHandler'
+ 'XMLRPCRedirectHandler',
]
from cookielib import Cookie
+from cStringIO import StringIO
from urllib2 import (
build_opener,
HTTPCookieProcessor,
@@ -27,6 +28,8 @@
Transport,
)
+from canonical.launchpad.scripts.logger import traceback_info
+
class XMLRPCRedirectHandler(HTTPRedirectHandler):
"""A handler for HTTP redirections of XML-RPC requests."""
@@ -105,8 +108,10 @@
headers = {'Content-type': 'text/xml'}
request = Request(url, request_body, headers)
try:
- response = self._parse_response(self.opener.open(request), None)
+ response = self.opener.open(request).read()
except HTTPError, he:
raise ProtocolError(
request.get_full_url(), he.code, he.msg, he.hdrs)
- return response
+ else:
+ traceback_info(response)
+ return self._parse_response(StringIO(response), None)
=== modified file 'lib/lp/bugs/tests/externalbugtracker-xmlrpc-transport.txt'
--- lib/lp/bugs/tests/externalbugtracker-xmlrpc-transport.txt 2010-04-09 12:42:15 +0000
+++ lib/lp/bugs/tests/externalbugtracker-xmlrpc-transport.txt 2011-02-07 20:54:15 +0000
@@ -1,4 +1,5 @@
-= XMLRPC urllib2 transport =
+XMLRPC urllib2 transport
+------------------------
When using XMLRPC for connecting to external bug trackers, we need to
use a special transport, which processes http cookies correctly, and
@@ -60,7 +61,7 @@
Cookie(version=0, name='foo', value='bar'...)]>
If an error occurs trying to make the request, an
-`xmlrpclib.ProtocolError` is raised.
+``xmlrpclib.ProtocolError`` is raised.
>>> from urllib2 import HTTPError
>>> test_handler.setError(
@@ -107,7 +108,8 @@
('http://www.example.com/xmlrpc/redirected',)
-== The XMLRPCRedirectHandler ==
+The XMLRPCRedirectHandler
+=========================
The UrlLib2Transport uses a custom HTTP redirection handler to handle
redirect responses. This is a subclass of urllib2's HTTPRedirectHandler.
@@ -189,3 +191,36 @@
>>> print redirected_request.data
None
+
+Debugging when the response cannot be parsed
+============================================
+
+``UrlLib2Transport`` annotates the stack such that the response body
+from the remote server ends up, in full, in a formatted stack trace.
+
+We patch the transport to always use the Expat response parser. The
+response parser is chosen at runtime from a number of choices, but the
+main Launchpad production environment selects Expat at present.
+
+Developer's machines could have other packages, python-reportlab-accel
+for example, that cause different response parsers to be chosen.
+
+ >>> import xmlrpclib
+
+ >>> def getparser():
+ ... target = xmlrpclib.Unmarshaller(
+ ... use_datetime=transport._use_datetime)
+ ... parser = xmlrpclib.ExpatParser(target)
+ ... return parser, target
+
+ >>> transport.getparser = getparser
+
+A malformed response body is included in the traceback:
+
+ >>> test_handler.setResponse("<params><mis></match></params>")
+ >>> transport.request('www.example.com', 'xmlrpc', "<methodCall />")
+ Traceback (most recent call last):
+ ...
+ <params><mis></match></params>
+ ...
+ ExpatError: mismatched tag: ...
=== modified file 'lib/lp/bugs/tests/externalbugtracker.py'
--- lib/lp/bugs/tests/externalbugtracker.py 2011-01-18 18:36:49 +0000
+++ lib/lp/bugs/tests/externalbugtracker.py 2011-02-07 20:54:15 +0000
@@ -31,14 +31,12 @@
commit,
ZopelessTransactionManager,
)
-from lp.bugs.model.bugtracker import BugTracker
from canonical.launchpad.ftests import (
login,
logout,
)
from canonical.launchpad.interfaces.logintoken import ILoginTokenSet
from canonical.launchpad.testing.systemdocs import ordered_dict_as_string
-from lp.bugs.xmlrpc.bug import ExternalBugTrackerTokenAPI
from canonical.testing.layers import LaunchpadZopelessLayer
from lp.bugs.externalbugtracker import (
BATCH_SIZE_UNLIMITED,
@@ -70,7 +68,9 @@
UNKNOWN_REMOTE_IMPORTANCE,
UNKNOWN_REMOTE_STATUS,
)
+from lp.bugs.model.bugtracker import BugTracker
from lp.bugs.scripts import debbugs
+from lp.bugs.xmlrpc.bug import ExternalBugTrackerTokenAPI
from lp.registry.interfaces.person import IPersonSet
@@ -1644,6 +1644,7 @@
def __init__(self):
self.redirect_url = None
self.raise_error = None
+ self.response = None
self.accessed_urls = []
def setRedirect(self, new_url):
@@ -1655,6 +1656,9 @@
self.raise_error = error
self.raise_url = url
+ def setResponse(self, response):
+ self.response = response
+
def default_open(self, req):
"""Catch all requests and return a hard-coded response.
@@ -1681,6 +1685,14 @@
self.redirect_url = None
response = self.parent.error(
'http', req, response, 302, 'Moved', headers)
+ elif self.response is not None:
+ response = StringIO(self.response)
+ info = Urlib2TransportTestInfo()
+ response.info = lambda: info
+ response.code = 200
+ response.geturl = lambda: req.get_full_url()
+ response.msg = ''
+ self.response = None
else:
xmlrpc_response = xmlrpclib.dumps(
(req.get_full_url(), ), methodresponse=True)
Follow ups
