launchpad-reviewers team mailing list archive
-
launchpad-reviewers team
-
Mailing list archive
-
Message #05053
[Merge] lp:~gary/launchpad/bug856048 into lp:launchpad
Gary Poster has proposed merging lp:~gary/launchpad/bug856048 into lp:launchpad.
Requested reviews:
Launchpad code reviewers (launchpad-reviewers)
Related bugs:
Bug #856048 in Launchpad itself: "SQLLogger and StormStatementRecorder duplicate functionality"
https://bugs.launchpad.net/launchpad/+bug/856048
For more details, see:
https://code.launchpad.net/~gary/launchpad/bug856048/+merge/76597
Merge SQLLogger and StormStatementRecorder.
Per a comment from Robert, I'm getting rid of my recently introduced SQLLogger by merging it with StormStatementRecorder (which I had forgotten about and not found again). This meant slightly adjusting a few tests (which meant addressing a few pieces of unrelated lint in these files).
The new StormStatementRecorder is now simpler and has a few more features. In particular:
* It collects accurate timings and database names.
* It can collect tracebacks never (default), always or conditionally.
* printing it gives you a view of what happened, including any gathered tracebacks, making it useful for interactive data-gathering work.
Lint is happy.
Thank you
Gary
--
https://code.launchpad.net/~gary/launchpad/bug856048/+merge/76597
Your team Launchpad code reviewers is requested to review the proposed merge of lp:~gary/launchpad/bug856048 into lp:launchpad.
=== modified file 'lib/canonical/launchpad/webapp/adapter.py'
--- lib/canonical/launchpad/webapp/adapter.py 2011-09-19 13:23:38 +0000
+++ lib/canonical/launchpad/webapp/adapter.py 2011-09-22 14:51:54 +0000
@@ -10,7 +10,6 @@
import logging
import os
import re
-import StringIO
import sys
import thread
import threading
@@ -97,7 +96,6 @@
'get_store_name',
'print_queries',
'soft_timeout_expired',
- 'SQLLogger',
'start_sql_logging',
'stop_sql_logging',
'StoreSelector',
@@ -365,8 +363,10 @@
warnings.warn('SQL logging already started')
return
_local.sql_logging_tracebacks_if = tracebacks_if
- _local.sql_logging = []
+ result = []
+ _local.sql_logging = result
_local.sql_logging_start = int(time() * 1000)
+ return result
def stop_sql_logging():
@@ -380,29 +380,6 @@
return result
-class SQLLogger:
-
- def __init__(self, tracebacks_if=False):
- self.tracebacks_if = tracebacks_if
-
- queries = None
-
- def __enter__(self):
- self.queries = None
- start_sql_logging(self.tracebacks_if)
-
- def __exit__(self, exc_type, exc_value, tb):
- self.queries = stop_sql_logging()
-
- def __str__(self):
- if self.queries is None:
- return '(no queries)'
- else:
- out = StringIO.StringIO()
- print_queries(self.queries, file=out)
- return out.getvalue()
-
-
def print_queries(queries, file=None):
if file is None:
file = sys.stdout
=== modified file 'lib/canonical/launchpad/webapp/tests/test_statementtracer.py'
--- lib/canonical/launchpad/webapp/tests/test_statementtracer.py 2011-09-13 05:23:16 +0000
+++ lib/canonical/launchpad/webapp/tests/test_statementtracer.py 2011-09-22 14:51:54 +0000
@@ -17,6 +17,7 @@
from lp.services.timeline.requesttimeline import get_request_timeline
from lp.testing import (
person_logged_in,
+ StormStatementRecorder,
TestCase,
TestCaseWithFactory,
)
@@ -217,16 +218,23 @@
"-" * 70 + "\n")
def test_context_manager(self):
- logger = da.SQLLogger()
- with logger:
+ with StormStatementRecorder() as logger:
self.execute()
- self.assertEqual(1, len(logger.queries))
- self.assertIs(None, logger.queries[0]['stack'])
- self.assertIs(None, logger.queries[0]['exception'])
- self.assertEqual(
- (1, 2, 'SQL-stub-database', 'SELECT * FROM bar WHERE bing = 42'),
- logger.queries[0]['sql'])
+ self.assertEqual(1, len(logger.query_data))
+ self.assertIs(None, logger.query_data[0]['stack'])
+ self.assertIs(None, logger.query_data[0]['exception'])
+ self.assertEqual(
+ (1, 2, 'SQL-stub-database', 'SELECT * FROM bar WHERE bing = 42'),
+ logger.query_data[0]['sql'])
+ self.assertEqual(
+ (1, 2, 'SQL-stub-database', 'SELECT * FROM bar WHERE bing = 42'),
+ logger.queries[0])
+ self.assertEqual(
+ 'SELECT * FROM bar WHERE bing = 42',
+ logger.statements[0])
+ self.assertEqual(1, logger.count)
with stdout() as file:
+ # Show that calling str does not actually print (bugfix).
result = str(logger)
self.assertEqual('', file.getvalue())
self.assertEqual(
@@ -235,20 +243,18 @@
result)
def test_context_manager_with_stacktrace(self):
- logger = da.SQLLogger(tracebacks_if=True)
- with logger:
+ with StormStatementRecorder(tracebacks_if=True) as logger:
self.execute()
- self.assertEqual(1, len(logger.queries))
- self.assertIsNot(None, logger.queries[0]['stack'])
+ self.assertEqual(1, len(logger.query_data))
+ self.assertIsNot(None, logger.query_data[0]['stack'])
def test_sql_parameters(self):
- logger = da.SQLLogger()
- with logger:
+ with StormStatementRecorder() as logger:
self.execute(statement='SELECT * FROM bar WHERE bing = %s',
params=(142,))
self.assertEqual(
(1, 2, 'SQL-stub-database', 'SELECT * FROM bar WHERE bing = 142'),
- logger.queries[0]['sql'])
+ logger.query_data[0]['sql'])
class TestLoggingWithinRequest(TestCaseWithFactory):
@@ -266,9 +272,8 @@
def test_logger(self):
tracer = da.LaunchpadStatementTracer()
- logger = da.SQLLogger()
with person_logged_in(self.person):
- with logger:
+ with StormStatementRecorder() as logger:
tracer.connection_raw_execute(
self.connection, None,
'SELECT * FROM bar WHERE bing = 42', ())
@@ -287,7 +292,7 @@
'SELECT * FROM bar WHERE bing = 42', ())
self.assertIsNot(None, action.duration)
self.assertEqual(
- 'SELECT * FROM surprise', logger.queries[0]['sql'][3])
+ 'SELECT * FROM surprise', logger.query_data[0]['sql'][3])
def test_stderr(self):
with override_environ(LP_DEBUG_SQL='1'):
=== modified file 'lib/lp/bugs/browser/tests/test_expose.py'
--- lib/lp/bugs/browser/tests/test_expose.py 2011-06-03 20:52:27 +0000
+++ lib/lp/bugs/browser/tests/test_expose.py 2011-09-22 14:51:54 +0000
@@ -124,7 +124,7 @@
# the team. (If the team has a preferredemail, muting is not
# possible).
context = self.factory.makeProduct(owner=self.user)
- team1 = self.factory.makeTeam(name='team-1', owner=self.user)
+ self.factory.makeTeam(name='team-1', owner=self.user)
team2 = self.factory.makeTeam(name='team-2', owner=self.user)
self.factory.makeEmail('foo@xxxxxxxxxxx',
team2,
@@ -186,7 +186,7 @@
absoluteURL=fake_absoluteURL)
statements_for_admininstrated_teams = [
statement for statement in recorder.statements
- if statement.startswith("'SELECT *")]
+ if statement.startswith("SELECT *")]
self.assertEqual(1, len(statements_for_admininstrated_teams))
# Calling the function a second time does not require an
@@ -197,7 +197,7 @@
absoluteURL=fake_absoluteURL)
statements_for_admininstrated_teams = [
statement for statement in recorder.statements
- if statement.startswith("'SELECT *")]
+ if statement.startswith("SELECT *")]
self.assertEqual(0, len(statements_for_admininstrated_teams))
def test_teams_owned_but_not_joined_are_not_included(self):
@@ -313,13 +313,13 @@
sub = target.addBugSubscription(team, team.teamowner)
expose_user_subscriptions_to_js(user, [sub], request)
info = IJSONRequestCache(request).objects['subscription_info']
- self.assertEqual(len(info), 1) # One target.
+ self.assertEqual(len(info), 1) # One target.
target_info = info[0]
self.assertEqual(target_info['target_title'], target.title)
self.assertEqual(
target_info['target_url'], canonical_url(
target, rootsite='mainsite'))
- self.assertEqual(len(target_info['filters']), 1) # One filter.
+ self.assertEqual(len(target_info['filters']), 1) # One filter.
filter_info = target_info['filters'][0]
self.assertEqual(filter_info['filter'], sub.bug_filters[0])
self.assertTrue(filter_info['subscriber_is_team'])
@@ -409,7 +409,7 @@
expose_user_subscriptions_to_js(user, [sub], request)
statements_for_admininstrated_teams = [
statement for statement in recorder.statements
- if statement.startswith("'SELECT *")]
+ if statement.startswith("SELECT *")]
self.assertEqual(1, len(statements_for_admininstrated_teams))
# Calling the function a second time does not require an
@@ -419,5 +419,5 @@
expose_user_subscriptions_to_js(user, [sub], request)
statements_for_admininstrated_teams = [
statement for statement in recorder.statements
- if statement.startswith("'SELECT *")]
+ if statement.startswith("SELECT *")]
self.assertEqual(0, len(statements_for_admininstrated_teams))
=== modified file 'lib/lp/bugs/model/tests/test_personsubscriptioninfo.py'
--- lib/lp/bugs/model/tests/test_personsubscriptioninfo.py 2011-09-01 16:30:29 +0000
+++ lib/lp/bugs/model/tests/test_personsubscriptioninfo.py 2011-09-22 14:51:54 +0000
@@ -8,7 +8,6 @@
from testtools.matchers import LessThan
from zope.security.proxy import removeSecurityProxy
-from canonical.launchpad.webapp.adapter import SQLLogger
from canonical.testing import DatabaseFunctionalLayer
from lp.bugs.interfaces.personsubscriptioninfo import (
IRealSubscriptionInfo,
@@ -20,9 +19,13 @@
from lp.registry.interfaces.teammembership import TeamMembershipStatus
from lp.testing import (
person_logged_in,
+ StormStatementRecorder,
TestCaseWithFactory,
)
-from lp.testing.matchers import Provides
+from lp.testing.matchers import (
+ HasQueryCount,
+ Provides,
+ )
class TestPersonSubscriptionInfo(TestCaseWithFactory):
@@ -509,12 +512,11 @@
team.addMember(self.subscriber, team.teamowner,
status=TeamMembershipStatus.ADMIN)
self.makeDuplicates(count=1, subscriber=team)
- logger = SQLLogger()
- with logger:
+ with StormStatementRecorder() as recorder:
self.subscriptions.reload()
# This should produce a very small number of queries.
- count_with_one_subscribed_duplicate = len(logger.queries)
- self.assertThat(count_with_one_subscribed_duplicate, LessThan(5))
+ self.assertThat(recorder, HasQueryCount(LessThan(5)))
+ count_with_one_subscribed_duplicate = recorder.count
# It should have the correct result.
self.assertCollectionsAreEmpty(except_='from_duplicate')
self.assertCollectionContents(
@@ -522,10 +524,10 @@
# If we increase the number of duplicates subscribed via the team that
# the user administers...
self.makeDuplicates(count=4, subscriber=team)
- with logger:
+ with StormStatementRecorder() as recorder:
self.subscriptions.reload()
# ...then the query count should remain the same.
- count_with_five_subscribed_duplicates = len(logger.queries)
+ count_with_five_subscribed_duplicates = recorder.count
self.assertEqual(
count_with_one_subscribed_duplicate,
count_with_five_subscribed_duplicates)
=== modified file 'lib/lp/bugs/tests/test_duplicate_handling.py'
--- lib/lp/bugs/tests/test_duplicate_handling.py 2011-08-12 11:37:08 +0000
+++ lib/lp/bugs/tests/test_duplicate_handling.py 2011-09-22 14:51:54 +0000
@@ -138,7 +138,7 @@
target_heat_cache_statements = [
statement for statement in recorder.statements
if statement.startswith(
- "'SELECT MAX(Bug.heat), SUM(Bug.heat), COUNT(Bug.id)")]
+ "SELECT MAX(Bug.heat), SUM(Bug.heat), COUNT(Bug.id)")]
return len(target_heat_cache_statements)
def test_move_duplicates_efficient_target_heat_cache_calculation(self):
=== modified file 'lib/lp/testing/__init__.py'
--- lib/lp/testing/__init__.py 2011-09-05 15:42:27 +0000
+++ lib/lp/testing/__init__.py 2011-09-22 14:51:54 +0000
@@ -88,12 +88,7 @@
import oops_datedir_repo.serializer_rfc822
import pytz
import simplejson
-from storm.expr import Variable
from storm.store import Store
-from storm.tracer import (
- install_tracer,
- remove_tracer_type,
- )
import subunit
import testtools
from testtools.content import Content
@@ -119,7 +114,10 @@
errorlog,
)
from canonical.launchpad.webapp.adapter import (
+ print_queries,
set_permit_timeout_from_features,
+ start_sql_logging,
+ stop_sql_logging,
)
from canonical.launchpad.webapp.errorlog import ErrorReportEvent
from canonical.launchpad.webapp.interaction import ANONYMOUS
@@ -269,53 +267,43 @@
do somestuff
self.assertThat(recorder, HasQueryCount(LessThan(42)))
- Note that due to the storm API used, only one of these recorders may be in
- place at a time: all will be removed when the first one is removed (by
- calling __exit__ or leaving the scope of a with statement).
+ This also can be useful for investigation, such as in make harness.
+ Try printing it after you have collected some queries. You can
+ even collect tracebacks, passing True to "tracebacks_if" for tracebacks
+ of every SQL query, or a callable that takes the SQL query string and
+ returns a boolean decision as to whether a traceback is desired.
"""
-
- def __init__(self):
- self.statements = []
+ # Note that tests for this are in canonical.launchpad.webapp.tests.
+ # test_statementtracer, because this is really just a small wrapper of
+ # the functionality found there.
+
+ def __init__(self, tracebacks_if=False):
+ self.tracebacks_if = tracebacks_if
+ self.query_data = []
+
+ @property
+ def queries(self):
+ return [record['sql'] for record in self.query_data]
@property
def count(self):
- return len(self.statements)
+ return len(self.query_data)
@property
- def queries(self):
- """The statements executed as per get_request_statements."""
- # Perhaps we could just consolidate this code with the request tracer
- # code and not need a custom tracer at all - if we provided a context
- # factory to the tracer, which in the production tracers would
- # use the adapter magic, and in test created ones would log to a list.
- # We would need to be able to remove just one tracer though, which I
- # haven't looked into yet. RBC 20100831
- result = []
- for statement in self.statements:
- result.append((0, 0, 'unknown', statement))
- return result
+ def statements(self):
+ return [record['sql'][3] for record in self.query_data]
def __enter__(self):
- """Context manager protocol - return this object as the context."""
- install_tracer(self)
+ self.query_data = start_sql_logging(self.tracebacks_if)
return self
- def __exit__(self, _ignored, _ignored2, _ignored3):
- """Content manager protocol - do not swallow exceptions."""
- remove_tracer_type(StormStatementRecorder)
- return False
-
- def connection_raw_execute(self, ignored, raw_cursor, statement, params):
- """Increment the counter. We don't care about the args."""
-
- raw_params = []
- for param in params:
- if isinstance(param, Variable):
- raw_params.append(param.get())
- else:
- raw_params.append(param)
- raw_params = tuple(raw_params)
- self.statements.append("%r, %r" % (statement, raw_params))
+ def __exit__(self, exc_type, exc_value, tb):
+ stop_sql_logging()
+
+ def __str__(self):
+ out = StringIO()
+ print_queries(self.query_data, file=out)
+ return out.getvalue()
def record_statements(function, *args, **kwargs):
