def search(self, terms, start=0):
"""See `ISearchService`.
The `subscription_key` and `custom_config_id` are used in the
search request. Search returns 20 or fewer results for each query.
For terms that match more than 20 results, the start param can be
used over multiple queries to get successive sets of results.
:return: `ISearchResults` (PageMatches).
:raise: `SiteSearchResponseError` if the json response is incomplete or
cannot be parsed.
"""
search_url = self.create_search_url(terms, start=start)
search_headers = self.create_search_headers()
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start("bing-search-api", search_url)
try:
response = urlfetch(
search_url, headers=search_headers, use_proxy=True)
except (TimeoutError, requests.RequestException) as error:
raise SiteSearchResponseError(
"The response errored: %s" % str(error))
finally:
action.finish()
page_matches = self._parse_search_response(response.content, start)
return page_matches
def _getTimeline():
# XXX cjwatson 2016-06-29: This can be simplified once jobs have
# timeline support.
request = get_current_browser_request()
if request is None:
return None
return get_request_timeline(request)
def raw_sendmail(from_addr, to_addrs, raw_message, message_detail):
"""Send a raw RFC8222 email message.
All headers and encoding should already be done, as the message is
spooled out verbatim to the delivery agent.
You should not need to call this method directly, although it may be
necessary to pass on signed or encrypted messages.
Returns the message-id.
:param message_detail: String of detail about the message
to be recorded to help with debugging, eg the message subject.
"""
assert not isinstance(to_addrs, basestring), 'to_addrs must be a sequence'
assert isinstance(raw_message, str), 'Not a plain string'
assert raw_message.decode('ascii'), 'Not ASCII - badly encoded message'
mailer = getUtility(IMailDelivery, 'Mail')
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start("sendmail", message_detail)
try:
return mailer.send(from_addr, to_addrs, raw_message)
finally:
action.finish()
def _getPubKey(self, fingerprint):
"""See IGPGHandler for further information."""
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start('retrieving GPG key',
'Fingerprint: %s' % fingerprint)
try:
return self._grabPage('get', fingerprint)
# We record an OOPS for most errors: If the keyserver does not
# respond, callsites should show users an error message like
# "sorry, the keyserver is not responding, try again in a few
# minutes." The details of the error do not matter for users
# (and for the code in callsites), but we should be able to see
# if this problem occurs too often.
except urllib2.HTTPError as exc:
# Old versions of SKS return a 500 error when queried for a
# non-existent key. Production was upgraded in 2013/01, but
# let's leave this here for a while.
#
# We can extract the fact that the key is unknown by looking
# into the response's content.
if exc.code in (404, 500) and exc.fp is not None:
content = exc.fp.read()
no_key_message = 'No results found: No keys found'
if content.find(no_key_message) >= 0:
raise GPGKeyDoesNotExistOnServer(fingerprint)
errorlog.globalErrorUtility.raising(sys.exc_info(), request)
raise GPGKeyTemporarilyNotFoundError(fingerprint)
except (TimeoutError, urllib2.URLError) as exc:
errorlog.globalErrorUtility.raising(sys.exc_info(), request)
raise GPGKeyTemporarilyNotFoundError(fingerprint)
finally:
action.finish()
def test_stderr(self):
with override_environ(LP_DEBUG_SQL='1'):
tracer = da.LaunchpadStatementTracer()
with person_logged_in(self.person):
with stderr() as file:
tracer.connection_raw_execute(
self.connection, None, 'SELECT * FROM bar WHERE bing = 42',
())
timeline = get_request_timeline(get_current_browser_request())
action = timeline.actions[-1]
self.assertEqual('SELECT * FROM bar WHERE bing = 42',
action.detail)
self.assertEqual('SQL-stub-database', action.category)
self.assertIs(None, action.duration)
# Now we change the detail to verify that the action is the
# source of the final log.
action.detail = 'SELECT * FROM surprise'
tracer.connection_raw_execute_success(
self.connection, None, 'SELECT * FROM bar WHERE bing = 42',
())
self.assertIsNot(None, action.duration)
self.assertEndsWith(
file.getvalue(),
'@SQL-stub-database SELECT * FROM surprise\n' + "-" * 70 +
"\n")
def test_stderr(self):
with override_environ(LP_DEBUG_SQL='1'):
tracer = da.LaunchpadStatementTracer()
with person_logged_in(self.person):
with stderr() as file:
tracer.connection_raw_execute(
self.connection, None, 'SELECT * FROM bar WHERE bing = 42',
())
timeline = get_request_timeline(get_current_browser_request())
action = timeline.actions[-1]
self.assertEqual('SELECT * FROM bar WHERE bing = 42',
action.detail)
self.assertEqual('SQL-stub-database', action.category)
self.assertIs(None, action.duration)
# Now we change the detail to verify that the action is the
# source of the final log.
action.detail = 'SELECT * FROM surprise'
tracer.connection_raw_execute_success(
self.connection, None, 'SELECT * FROM bar WHERE bing = 42',
())
self.assertIsNot(None, action.duration)
self.assertEndsWith(
file.getvalue(),
'@SQL-stub-database SELECT * FROM surprise\n' + "-" * 70 +
"\n")
def search(self, terms, start=0):
"""See `ISearchService`.
The config.google.client_id is used as Google client-id in the
search request. Search returns 20 or fewer results for each query.
For terms that match more than 20 results, the start param can be
used over multiple queries to get successive sets of results.
:return: `ISearchResults` (PageMatches).
:raise: `GoogleWrongGSPVersion` if the xml cannot be parsed.
"""
search_url = self.create_search_url(terms, start=start)
from lp.services.timeout import urlfetch
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start("google-search-api", search_url)
try:
gsp_xml = urlfetch(search_url)
except (TimeoutError, urllib2.HTTPError, urllib2.URLError) as error:
# Google search service errors are not code errors. Let the
# call site choose to handle the unavailable service.
raise GoogleResponseError("The response errored: %s" % str(error))
finally:
action.finish()
page_matches = self._parse_google_search_protocol(gsp_xml)
return page_matches
def _getPubKey(self, fingerprint):
"""See IGPGHandler for further information."""
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start(
'retrieving GPG key', 'Fingerprint: %s' % fingerprint)
try:
return self._grabPage('get', fingerprint)
# We record an OOPS for most errors: If the keyserver does not
# respond, callsites should show users an error message like
# "sorry, the keyserver is not responding, try again in a few
# minutes." The details of the error do not matter for users
# (and for the code in callsites), but we should be able to see
# if this problem occurs too often.
except urllib2.HTTPError as exc:
# Old versions of SKS return a 500 error when queried for a
# non-existent key. Production was upgraded in 2013/01, but
# let's leave this here for a while.
#
# We can extract the fact that the key is unknown by looking
# into the response's content.
if exc.code in (404, 500) and exc.fp is not None:
content = exc.fp.read()
no_key_message = 'No results found: No keys found'
if content.find(no_key_message) >= 0:
raise GPGKeyDoesNotExistOnServer(fingerprint)
errorlog.globalErrorUtility.raising(sys.exc_info(), request)
raise GPGKeyTemporarilyNotFoundError(fingerprint)
except (TimeoutError, urllib2.URLError) as exc:
errorlog.globalErrorUtility.raising(sys.exc_info(), request)
raise GPGKeyTemporarilyNotFoundError(fingerprint)
finally:
action.finish()
def search(self, terms, start=0):
"""See `ISearchService`.
The config.google.client_id is used as Google client-id in the
search request. Search returns 20 or fewer results for each query.
For terms that match more than 20 results, the start param can be
used over multiple queries to get successive sets of results.
:return: `ISearchResults` (PageMatches).
:raise: `GoogleWrongGSPVersion` if the xml cannot be parsed.
"""
search_url = self.create_search_url(terms, start=start)
from lp.services.timeout import urlfetch
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start("google-search-api", search_url)
try:
gsp_xml = urlfetch(search_url)
except (TimeoutError, urllib2.HTTPError, urllib2.URLError) as error:
# Google search service errors are not code errors. Let the
# call site choose to handle the unavailable service.
raise GoogleResponseError(
"The response errored: %s" % str(error))
finally:
action.finish()
page_matches = self._parse_google_search_protocol(gsp_xml)
return page_matches
def _request(self, method, path, **kwargs):
"""Make a request to the Git hosting API."""
# Fetch the current timeout before starting the timeline action,
# since making a database query inside this action will result in an
# OverlappingActionError.
get_default_timeout_function()()
timeline = get_request_timeline(get_current_browser_request())
action = timeline.start("git-hosting-%s" % method,
"%s %s" % (path, json.dumps(kwargs)))
try:
response = urlfetch(urljoin(self.endpoint, path),
method=method,
**kwargs)
except TimeoutError:
# Re-raise this directly so that it can be handled specially by
# callers.
raise
except requests.RequestException:
raise
except Exception:
_, val, tb = sys.exc_info()
reraise(RequestExceptionWrapper,
RequestExceptionWrapper(*val.args), tb)
finally:
action.finish()
if response.content:
return response.json()
else:
return None
def test_set_recorded_to_timeline(self):
request = get_current_browser_request()
timeline = get_request_timeline(request)
self.client.set('foo', 'bar')
action = timeline.actions[-1]
self.assertEqual('memcache-set', action.category)
self.assertEqual('foo', action.detail)
def test_set_recorded_to_timeline(self):
request = get_current_browser_request()
timeline = get_request_timeline(request)
self.client.set('foo', 'bar')
action = timeline.actions[-1]
self.assertEqual('memcache-set', action.category)
self.assertEqual('foo', action.detail)
def raw_sendmail(from_addr, to_addrs, raw_message, message_detail):
"""Send a raw RFC8222 email message.
All headers and encoding should already be done, as the message is
spooled out verbatim to the delivery agent.
You should not need to call this method directly, although it may be
necessary to pass on signed or encrypted messages.
Returns the message-id.
:param message_detail: String of detail about the message
to be recorded to help with debugging, eg the message subject.
"""
assert not isinstance(to_addrs, basestring), 'to_addrs must be a sequence'
assert isinstance(raw_message, str), 'Not a plain string'
assert raw_message.decode('ascii'), 'Not ASCII - badly encoded message'
mailer = getUtility(IMailDelivery, 'Mail')
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start("sendmail", message_detail)
try:
return mailer.send(from_addr, to_addrs, raw_message)
finally:
action.finish()
def gpgme_timeline(name, detail):
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start("gpgme-%s" % name, detail, allow_nested=True)
try:
yield
finally:
action.finish()
def initialize(self):
params = self._gather_params(self.request)
requested_url = self._get_requested_url(self.request)
consumer = self._getConsumer()
timeline_action = get_request_timeline(self.request).start(
"openid-association-complete", '', allow_nested=True)
try:
self.openid_response = consumer.complete(params, requested_url)
finally:
timeline_action.finish()
def initialize(self):
params = self._gather_params(self.request)
requested_url = self._get_requested_url(self.request)
consumer = self._getConsumer()
timeline_action = get_request_timeline(self.request).start(
"openid-association-complete", '', allow_nested=True)
try:
self.openid_response = consumer.complete(params, requested_url)
finally:
timeline_action.finish()
def read(self, chunksize=None):
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start("librarian-read", self.url)
try:
if chunksize is None:
return self.file.read()
else:
return self.file.read(chunksize)
finally:
action.finish()
def assertRequest(self, url_suffix, json_data=None, method=None, **kwargs):
[request] = self.requests
self.assertThat(request, MatchesStructure.byEquality(
url=urlappend(self.endpoint, url_suffix), method=method, **kwargs))
if json_data is not None:
self.assertEqual(json_data, json.loads(request.body))
timeline = get_request_timeline(get_current_browser_request())
action = timeline.actions[-1]
self.assertEqual("git-hosting-%s" % method.lower(), action.category)
self.assertEqual(
"/" + url_suffix.split("?", 1)[0], action.detail.split(" ", 1)[0])
def test_runJobHandleErrors_oops_timeline(self):
"""The oops timeline only covers the job itself."""
timeline = get_request_timeline(get_current_browser_request())
timeline.start('test', 'sentinel').finish()
job = RaisingJobTimelineMessage('boom')
flush_database_updates()
runner = JobRunner([job])
runner.runJobHandleError(job)
self.assertEqual(1, len(self.oopses))
actions = [action[2:4] for action in self.oopses[0]['timeline']]
self.assertIn(('job', 'boom'), actions)
self.assertNotIn(('test', 'sentinel'), actions)
def test_logs_to_timeline(self):
# Completing an OpenID association *can* make an HTTP request to the
# OP, so it's a potentially long action. It is logged to the
# request timeline.
person = self.factory.makePerson()
with SRegResponse_fromSuccessResponse_stubbed():
view, html = self._createViewWithResponse(person.account)
start, stop = get_request_timeline(view.request).actions[-2:]
self.assertEqual(start.category, 'openid-association-complete-start')
self.assertEqual(start.detail, '')
self.assertEqual(stop.category, 'openid-association-complete-stop')
self.assertEqual(stop.detail, '')
def render(self):
# Reauthentication is called for by a query string parameter.
reauth_qs = self.request.query_string_params.get('reauth', ['0'])
do_reauth = int(reauth_qs[0])
if self.account is not None and not do_reauth:
return AlreadyLoggedInView(self.context, self.request)()
# Allow unauthenticated users to have sessions for the OpenID
# handshake to work.
allowUnauthenticatedSession(self.request)
consumer = self._getConsumer()
openid_vhost = config.launchpad.openid_provider_vhost
timeline_action = get_request_timeline(self.request).start(
"openid-association-begin",
allvhosts.configs[openid_vhost].rooturl,
allow_nested=True)
try:
self.openid_request = consumer.begin(
allvhosts.configs[openid_vhost].rooturl)
finally:
timeline_action.finish()
self.openid_request.addExtension(
sreg.SRegRequest(required=['email', 'fullname']))
# Force the Open ID handshake to re-authenticate, using
# pape extension's max_auth_age, if the URL indicates it.
if do_reauth:
self.openid_request.addExtension(pape.Request(max_auth_age=0))
assert not self.openid_request.shouldSendRedirect(), (
"Our fixed OpenID server should not need us to redirect.")
# Once the user authenticates with the OpenID provider they will be
# sent to the /+openid-callback page, where we log them in, but
# once that's done they must be sent back to the URL they were when
# they started the login process (i.e. the current URL without the
# '+login' bit). To do that we encode that URL as a query arg in the
# return_to URL passed to the OpenID Provider
starting_url = urllib.urlencode([('starting_url',
self.starting_url.encode('utf-8'))])
trust_root = allvhosts.configs['mainsite'].rooturl
return_to = urlappend(trust_root, '+openid-callback')
return_to = "%s?%s" % (return_to, starting_url)
form_html = self.openid_request.htmlMarkup(trust_root, return_to)
# The consumer.begin() call above will insert rows into the
# OpenIDAssociations table, but since this will be a GET request, the
# transaction would be rolled back, so we need an explicit commit
# here.
transaction.commit()
return form_html
def render(self):
# Reauthentication is called for by a query string parameter.
reauth_qs = self.request.query_string_params.get('reauth', ['0'])
do_reauth = int(reauth_qs[0])
if self.account is not None and not do_reauth:
return AlreadyLoggedInView(self.context, self.request)()
# Allow unauthenticated users to have sessions for the OpenID
# handshake to work.
allowUnauthenticatedSession(self.request)
consumer = self._getConsumer()
openid_vhost = config.launchpad.openid_provider_vhost
timeline_action = get_request_timeline(self.request).start(
"openid-association-begin",
allvhosts.configs[openid_vhost].rooturl,
allow_nested=True)
try:
self.openid_request = consumer.begin(
allvhosts.configs[openid_vhost].rooturl)
finally:
timeline_action.finish()
self.openid_request.addExtension(
sreg.SRegRequest(required=['email', 'fullname']))
# Force the Open ID handshake to re-authenticate, using
# pape extension's max_auth_age, if the URL indicates it.
if do_reauth:
self.openid_request.addExtension(pape.Request(max_auth_age=0))
assert not self.openid_request.shouldSendRedirect(), (
"Our fixed OpenID server should not need us to redirect.")
# Once the user authenticates with the OpenID provider they will be
# sent to the /+openid-callback page, where we log them in, but
# once that's done they must be sent back to the URL they were when
# they started the login process (i.e. the current URL without the
# '+login' bit). To do that we encode that URL as a query arg in the
# return_to URL passed to the OpenID Provider
starting_url = urllib.urlencode(
[('starting_url', self.starting_url.encode('utf-8'))])
trust_root = allvhosts.configs['mainsite'].rooturl
return_to = urlappend(trust_root, '+openid-callback')
return_to = "%s?%s" % (return_to, starting_url)
form_html = self.openid_request.htmlMarkup(trust_root, return_to)
# The consumer.begin() call above will insert rows into the
# OpenIDAssociations table, but since this will be a GET request, the
# transaction would be rolled back, so we need an explicit commit
# here.
transaction.commit()
return form_html
def assertRequest(self, url_suffix, **kwargs):
[request] = self.requests
self.assertThat(
request,
MatchesStructure.byEquality(url=urlappend(self.endpoint,
url_suffix),
method="GET",
**kwargs))
timeline = get_request_timeline(get_current_browser_request())
action = timeline.actions[-1]
self.assertEqual("branch-hosting-get", action.category)
self.assertEqual("/" + url_suffix.split("?", 1)[0],
action.detail.split(" ", 1)[0])
def connection_raw_execute(self, connection, raw_cursor, statement,
params):
statement_to_log = statement
if params:
statement_to_log = raw_cursor.mogrify(
statement, tuple(connection.to_database(params)))
if isinstance(statement_to_log, bytes):
statement_to_log = statement_to_log.decode('UTF-8',
errors='replace')
# Record traceback to log, if requested.
print_traceback = self._debug_sql_extra
log_sql = getattr(_local, 'sql_logging', None)
log_traceback = False
if log_sql is not None:
log_sql.append(dict(stack=None, sql=None, exception=None))
conditional = getattr(_local, 'sql_logging_tracebacks_if', None)
if callable(conditional):
try:
log_traceback = conditional(
self._normalize_whitespace(
statement_to_log.strip()).upper())
except (MemoryError, SystemExit, KeyboardInterrupt):
raise
except:
exc_type, exc_value, tb = sys.exc_info()
log_sql[-1]['exception'] = (exc_type, exc_value)
log_sql[-1]['stack'] = extract_tb(tb)
else:
log_traceback = bool(conditional)
if print_traceback or log_traceback:
stack = extract_stack()
if log_traceback:
log_sql[-1]['stack'] = stack
if print_traceback:
print_list(stack)
sys.stderr.write("." * 70 + "\n")
# store the last executed statement as an attribute on the current
# thread
threading.currentThread().lp_last_sql_statement = statement
request_starttime = getattr(_local, 'request_start_time', None)
if request_starttime is None:
if print_traceback or self._debug_sql or log_sql is not None:
# Stash some information for logging at the end of the
# SQL execution.
connection._lp_statement_info = (int(
time() * 1000), u'SQL-%s' % connection._database.name,
statement_to_log)
return
action = get_request_timeline(get_current_browser_request()).start(
u'SQL-%s' % connection._database.name, statement_to_log)
connection._lp_statement_action = action
def summarize_requests():
"""Produce human-readable summary of requests issued so far."""
secs = get_request_duration()
request = get_current_browser_request()
timeline = get_request_timeline(request)
from lp.services.webapp.errorlog import (maybe_record_user_requested_oops)
maybe_record_user_requested_oops()
if request.oopsid is None:
oops_str = ""
else:
oops_str = " %s" % request.oopsid
log = "%s queries/external actions issued in %.2f seconds%s" % (len(
timeline.actions), secs, oops_str)
return log
def connection_raw_execute(self, connection, raw_cursor,
statement, params):
statement_to_log = statement
if params:
statement_to_log = raw_cursor.mogrify(
statement, tuple(connection.to_database(params)))
# Record traceback to log, if requested.
print_traceback = self._debug_sql_extra
log_sql = getattr(_local, 'sql_logging', None)
log_traceback = False
if log_sql is not None:
log_sql.append(dict(stack=None, sql=None, exception=None))
conditional = getattr(_local, 'sql_logging_tracebacks_if', None)
if callable(conditional):
try:
log_traceback = conditional(
self._normalize_whitespace(
statement_to_log.strip()).upper())
except (MemoryError, SystemExit, KeyboardInterrupt):
raise
except:
exc_type, exc_value, tb = sys.exc_info()
log_sql[-1]['exception'] = (exc_type, exc_value)
log_sql[-1]['stack'] = extract_tb(tb)
else:
log_traceback = bool(conditional)
if print_traceback or log_traceback:
stack = extract_stack()
if log_traceback:
log_sql[-1]['stack'] = stack
if print_traceback:
print_list(stack)
sys.stderr.write("." * 70 + "\n")
# store the last executed statement as an attribute on the current
# thread
threading.currentThread().lp_last_sql_statement = statement
request_starttime = getattr(_local, 'request_start_time', None)
if request_starttime is None:
if print_traceback or self._debug_sql or log_sql is not None:
# Stash some information for logging at the end of the
# SQL execution.
connection._lp_statement_info = (
int(time() * 1000),
'SQL-%s' % connection._database.name,
statement_to_log)
return
action = get_request_timeline(get_current_browser_request()).start(
'SQL-%s' % connection._database.name, statement_to_log)
connection._lp_statement_action = action
def test_logs_to_timeline(self):
# Beginning an OpenID association makes an HTTP request to the
# OP, so it's a potentially long action. It is logged to the
# request timeline.
request = LaunchpadTestRequest()
# This is a hack to make the request.getURL(1) call issued by the view
# not raise an IndexError.
request._app_names = ['foo']
view = StubbedOpenIDLogin(object(), request)
view()
start, stop = get_request_timeline(request).actions[-2:]
self.assertEqual(start.category, 'openid-association-begin-start')
self.assertEqual(start.detail, 'http://testopenid.dev/')
self.assertEqual(stop.category, 'openid-association-begin-stop')
self.assertEqual(stop.detail, 'http://testopenid.dev/')
def summarize_requests():
"""Produce human-readable summary of requests issued so far."""
secs = get_request_duration()
request = get_current_browser_request()
timeline = get_request_timeline(request)
from lp.services.webapp.errorlog import (
maybe_record_user_requested_oops)
maybe_record_user_requested_oops()
if request.oopsid is None:
oops_str = ""
else:
oops_str = " %s" % request.oopsid
log = "%s queries/external actions issued in %.2f seconds%s" % (
len(timeline.actions), secs, oops_str)
return log
def match(self, arch, wildcard):
if (arch, wildcard) not in self._matches:
timeline = get_request_timeline(get_current_browser_request())
command = ["dpkg-architecture", "-i%s" % wildcard]
env = dict(os.environ)
env["DEB_HOST_ARCH"] = arch
action = timeline.start("dpkg-architecture",
"-i%s DEB_HOST_ARCH=%s" % (wildcard, arch),
allow_nested=True)
try:
ret = (subprocess.call(command, env=env) == 0)
finally:
action.finish()
self._matches[(arch, wildcard)] = ret
return self._matches[(arch, wildcard)]
def getFileByAlias(
self, aliasID, timeout=LIBRARIAN_SERVER_DEFAULT_TIMEOUT):
"""See `IFileDownloadClient`."""
url = self._getURLForDownload(aliasID)
if url is None:
# File has been deleted
return None
try_until = time.time() + timeout
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start("librarian-connection", url)
try:
return self._connect_read(url, try_until, aliasID)
finally:
action.finish()
def get_request_statements():
"""Get the list of executed statements in the request.
The list is composed of (starttime, endtime, db_id, statement) tuples.
Times are given in milliseconds since the start of the request.
"""
result = []
request = get_current_browser_request()
for action in get_request_timeline(request).actions:
if not action.category.startswith("SQL-"):
continue
# Can't show incomplete requests in this API
if action.duration is None:
continue
result.append(action.logTuple())
return result
def get_request_statements():
"""Get the list of executed statements in the request.
The list is composed of (starttime, endtime, db_id, statement) tuples.
Times are given in milliseconds since the start of the request.
"""
result = []
request = get_current_browser_request()
for action in get_request_timeline(request).actions:
if not action.category.startswith("SQL-"):
continue
# Can't show incomplete requests in this API
if action.duration is None:
continue
result.append(action.logTuple())
return result
def _request(self,
method,
branch_id,
quoted_tail,
as_json=False,
**kwargs):
"""Make a request to the Loggerhead API."""
# Fetch the current timeout before starting the timeline action,
# since making a database query inside this action will result in an
# OverlappingActionError.
get_default_timeout_function()()
timeline = get_request_timeline(get_current_browser_request())
components = [BRANCH_ID_ALIAS_PREFIX, str(branch_id)]
if as_json:
components.append("+json")
components.append(quoted_tail)
path = "/" + "/".join(components)
action = timeline.start("branch-hosting-%s" % method,
"%s %s" % (path, json.dumps(kwargs)))
try:
response = urlfetch(urljoin(self.endpoint, path),
method=method,
**kwargs)
except TimeoutError:
# Re-raise this directly so that it can be handled specially by
# callers.
raise
except requests.RequestException:
raise
except Exception:
_, val, tb = sys.exc_info()
reraise(RequestExceptionWrapper,
RequestExceptionWrapper(*val.args), tb)
finally:
action.finish()
if as_json:
if response.content:
return response.json()
else:
return None
else:
return response.content
def raising(self, info, request=None):
"""See IErrorReportingUtility.raising()"""
context = dict(exc_info=info)
if request is not None:
context['http_request'] = request
# In principle the timeline is per-request, but see bug=623199 -
# at this point the request is optional, but get_request_timeline
# does not care; when it starts caring, we will always have a
# request object (or some annotations containing object).
# RBC 20100901
timeline = get_request_timeline(request)
if timeline is not None:
context['timeline'] = timeline
report = self._oops_config.create(context)
if self._oops_config.publish(report) is None:
return
if request:
request.oopsid = report.get('id')
request.oops = report
return report
def raising(self, info, request=None):
"""See IErrorReportingUtility.raising()"""
context = dict(exc_info=info)
if request is not None:
context['http_request'] = request
# In principle the timeline is per-request, but see bug=623199 -
# at this point the request is optional, but get_request_timeline
# does not care; when it starts caring, we will always have a
# request object (or some annotations containing object).
# RBC 20100901
timeline = get_request_timeline(request)
if timeline is not None:
context['timeline'] = timeline
report = self._oops_config.create(context)
if self._oops_config.publish(report) is None:
return
if request:
request.oopsid = report.get('id')
request.oops = report
return report
def test_requestPackageUploadPermission(self):
snappy_series = self.factory.makeSnappySeries(name="rolling")
responses.add(
"POST", "http://sca.example/dev/api/acl/",
json={"macaroon": "dummy"})
macaroon = self.client.requestPackageUploadPermission(
snappy_series, "test-snap")
self.assertThat(responses.calls[-1].request, RequestMatches(
url=Equals("http://sca.example/dev/api/acl/"),
method=Equals("POST"),
json_data={
"packages": [{"name": "test-snap", "series": "rolling"}],
"permissions": ["package_upload"],
}))
self.assertEqual("dummy", macaroon)
request = get_current_browser_request()
start, stop = get_request_timeline(request).actions[-2:]
self.assertEqual("request-snap-upload-macaroon-start", start.category)
self.assertEqual("rolling/test-snap", start.detail)
self.assertEqual("request-snap-upload-macaroon-stop", stop.category)
self.assertEqual("rolling/test-snap", stop.detail)
def test_logger(self):
tracer = da.LaunchpadStatementTracer()
with person_logged_in(self.person):
with StormStatementRecorder() as logger:
tracer.connection_raw_execute(
self.connection, None, 'SELECT * FROM bar WHERE bing = 42',
())
timeline = get_request_timeline(get_current_browser_request())
action = timeline.actions[-1]
self.assertEqual('SELECT * FROM bar WHERE bing = 42',
action.detail)
self.assertEqual('SQL-stub-database', action.category)
self.assertIs(None, action.duration)
# Now we change the detail to verify that the action is the
# source of the final log.
action.detail = 'SELECT * FROM surprise'
tracer.connection_raw_execute_success(
self.connection, None, 'SELECT * FROM bar WHERE bing = 42',
())
self.assertIsNot(None, action.duration)
self.assertEqual('SELECT * FROM surprise',
logger.query_data[0]['sql'][3])
def test_logger(self):
tracer = da.LaunchpadStatementTracer()
with person_logged_in(self.person):
with StormStatementRecorder() as logger:
tracer.connection_raw_execute(
self.connection, None, 'SELECT * FROM bar WHERE bing = 42',
())
timeline = get_request_timeline(get_current_browser_request())
action = timeline.actions[-1]
self.assertEqual('SELECT * FROM bar WHERE bing = 42',
action.detail)
self.assertEqual('SQL-stub-database', action.category)
self.assertIs(None, action.duration)
# Now we change the detail to verify that the action is the
# source of the final log.
action.detail = 'SELECT * FROM surprise'
tracer.connection_raw_execute_success(
self.connection, None, 'SELECT * FROM bar WHERE bing = 42',
())
self.assertIsNot(None, action.duration)
self.assertEqual('SELECT * FROM surprise',
logger.query_data[0]['sql'][3])
def read(self, chunksize=None):
request = get_current_browser_request()
timeline = get_request_timeline(request)
action = timeline.start("librarian-read", self.url)
try:
if chunksize is None:
s = self.file.read()
else:
if self.length is not None:
chunksize = min(chunksize, self.length)
s = self.file.read(chunksize)
if self.length is not None:
self.length -= len(s)
# httplib doesn't quite do all the checking we need: in
# particular, it won't fail on a short bounded-size read
# from a non-chunked-transfer-coding resource. Check this
# manually.
if not s and chunksize != 0 and self.length:
raise httplib.IncompleteRead(s, expected=self.length)
return s
finally:
action.finish()
def requestPackageUploadPermission(cls, snappy_series, snap_name):
assert config.snappy.store_url is not None
request_url = urlappend(config.snappy.store_url, "dev/api/acl/")
request = get_current_browser_request()
timeline_action = get_request_timeline(request).start(
"request-snap-upload-macaroon",
"%s/%s" % (snappy_series.name, snap_name), allow_nested=True)
try:
response = urlfetch(
request_url, method="POST",
json={
"packages": [
{"name": snap_name, "series": snappy_series.name}],
"permissions": ["package_upload"],
})
response_data = response.json()
if "macaroon" not in response_data:
raise BadRequestPackageUploadResponse(response.text)
return response_data["macaroon"]
except requests.HTTPError as e:
raise cls._makeSnapStoreError(BadRequestPackageUploadResponse, e)
finally:
timeline_action.finish()
def store_sql_statements_and_request_duration(event):
actions = get_request_timeline(get_current_browser_request()).actions
event.request.setInWSGIEnvironment(
'launchpad.nonpythonactions', len(actions))
event.request.setInWSGIEnvironment(
'launchpad.requestduration', get_request_duration())
def store_sql_statements_and_request_duration(event):
actions = get_request_timeline(get_current_browser_request()).actions
event.request.setInWSGIEnvironment('launchpad.nonpythonactions',
len(actions))
event.request.setInWSGIEnvironment('launchpad.requestduration',
get_request_duration())
def setUp(self):
Fixture.setUp(self)
webapp.adapter.set_request_started(time.time())
self.timeline = get_request_timeline(get_current_browser_request())
self.addCleanup(webapp.adapter.clear_request_started)
def get_timeline_actions():
"""Return an iterable of timeline actions."""
timeline = get_request_timeline(get_current_browser_request())
return timeline.actions[:IN_PAGE_TIMELINE_CAP]
def test_set_timeline(self):
req = TestRequest()
timeline = Timeline()
set_request_timeline(req, timeline)
self.assertEqual(timeline, get_request_timeline(req))
def test_same_timeline_repeated_calls(self):
req = TestRequest()
timeline = get_request_timeline(req)
self.assertEqual(timeline, get_request_timeline(req))
def test_new_request_get_request_timeline_uses_webapp(self):
req = TestRequest()
timeline = get_request_timeline(req)
self.assertIsInstance(timeline, Timeline)
self.assertTrue(webapp.adapter._local.request_timeline is timeline)
def disabled_test_new_request_get_request_timeline_works(self):
req = TestRequest()
timeline = get_request_timeline(req)
self.assertIsInstance(timeline, Timeline)
def __get_timeline_action(self, suffix, obj, operation, actorobj):
data = "Object: %s; Operation: %s, Actor: %s" % (
obj, operation, actorobj)
timeline = get_request_timeline(get_current_browser_request())
return timeline.start("auditor-%s" % suffix, data)
def assertAction(self, category, data):
timeline = get_request_timeline(get_current_browser_request())
action = timeline.actions[-1]
self.assertEqual(category, action.category)
self.assertEqual(data, action.detail)
def __get_timeline_action(self, suffix, key):
request = get_current_browser_request()
timeline = get_request_timeline(request)
return timeline.start("memcache-%s" % suffix, key)
def setUp(self):
Fixture.setUp(self)
webapp.adapter.set_request_started(time.time())
self.timeline = get_request_timeline(get_current_browser_request())
self.addCleanup(webapp.adapter.clear_request_started)
def afterCompletion(self, txn):
action = get_request_timeline(get_current_browser_request()).start(
"SQL-nostore", 'Transaction completed, status: %s' % txn.status)
action.finish()