Launchpad itself

Merge lp:~adeuring/launchpad/bug-504755-2 into lp:launchpad

  1. bug-504755-2
  2. Merge into devel
Proposed by Abel Deuring
Status: Merged
Approved by: Graham Binns
Approved revision: no longer in the source branch.
Merged at revision: not available
Proposed branch: lp:~adeuring/launchpad/bug-504755-2
Merge into: lp:launchpad
Diff against target: 335 lines (+115/-20)
8 files modified
lib/canonical/database/ftests/test_zopelesstransactionmanager.txt (+26/-0)
lib/canonical/database/sqlbase.py (+10/-0)
lib/canonical/launchpad/webapp/adapter.py (+37/-6)
lib/canonical/launchpad/webapp/ftests/test_adapter.txt (+19/-0)
lib/lp/bugs/doc/checkwatches-cli-switches.txt (+1/-1)
lib/lp/bugs/doc/checkwatches.txt (+5/-3)
lib/lp/bugs/scripts/checkwatches.py (+13/-7)
lib/lp/bugs/scripts/tests/test_checkwatches.py (+4/-3)
To merge this branch: bzr merge lp:~adeuring/launchpad/bug-504755-2
Reviewer Review Type Date Requested Status
Graham Binns (community) code Approve
Review via email: mp+21950@code.launchpad.net

Description of the change

This branch adds logging of transaction.commit() and transaction.abort() calls to the checkwatches script.

To do so, it registers a synchronizer with the transaction manager. The only problem: The ZopelessTransactionManager, which is used by scripts, is not a real transaction manager, but, as its docstrang says, a "shim". So I added the missing methods registerSynch() and unregisterSynch(). But since the class is just a shim, the methods simply use the transaction module to find the "real" transaction manager and its methods (un)registerSynch() to do the real work.

The logging of commit()s is started via canonical.launchpad.webapp.set_request_started(), which needed another optional parameter, the transaction manager.

With these changes, ca. two tests in lib/lp/bugs/doc/checkwatches.txt failed because they used BugWatchUpdater instances whose __init__ methods were with a transaction as a parameter instead of a transaction manager.

tests:
./bin/test -t test_zopelesstransactionmanager.txt
./bin/test -vvt test_adapter.txt
./bin/test -vvt checkwatches.txt

To post a comment you must log in.
Revision history for this message
Graham Binns (gmb) wrote :
Download full text (11.1 KiB)

This looks fine, only a couple of comments:

> === modified file 'lib/canonical/database/ftests/test_zopelesstransactionmanager.txt'
> --- lib/canonical/database/ftests/test_zopelesstransactionmanager.txt 2008-05-19 15:47:23 +0000
> +++ lib/canonical/database/ftests/test_zopelesstransactionmanager.txt 2010-03-23 16:09:52 +0000
> @@ -90,3 +90,29 @@
> >>> print c.fetchone()[0]
> read committed
> >>> ztm.uninstall()
> +
> +we can also register synchronizers with the transaction manager.
> +
> + >>> class testsynchonizer:
> + ... def newtransaction(self, txn):
> + ... print "new transaction started."
> + ...
> + ... def beforecompletion(self, txn):
> + ... print "transaction will be completed."
> + ...
> + ... def aftercompletion(self, txn):
> + ... print "transaction completed."
> + >>>
> + >>> synchronizer = testsynchonizer()
> + >>> ztm.registersynch(synchronizer)
> + >>> ztm.begin()
> + new transaction started.
> + >>> ztm.commit()
> + transaction will be completed.
> + transaction completed.
> +
> +the synchonizer can be ungeristered again.

s/ungeristered/unregistered

> +
> + >>> ztm.unregistersynch(synchronizer)
> + >>> ztm.begin()
> + >>> ztm.commit()
>
> === modified file 'lib/canonical/database/sqlbase.py'
> --- lib/canonical/database/sqlbase.py 2010-01-22 06:25:48 +0000
> +++ lib/canonical/database/sqlbase.py 2010-03-23 16:09:52 +0000
> @@ -427,6 +427,16 @@
> """abort the current transaction."""
> transaction.abort()
>
> + @staticmethod
> + def registersynch(synch):
> + """register an isynchronizer."""
> + transaction.manager.registersynch(synch)
> +
> + @staticmethod
> + def unregistersynch(synch):
> + """unregister an isynchronizer."""
> + transaction.manager.unregistersynch(synch)
> +
>
> def clear_current_connection_cache():
> """clear sqlobject's object cache. sqlobject compatibility - deprecated.
>
> === modified file 'lib/canonical/launchpad/webapp/adapter.py'
> --- lib/canonical/launchpad/webapp/adapter.py 2010-03-22 13:07:05 +0000
> +++ lib/canonical/launchpad/webapp/adapter.py 2010-03-23 16:09:52 +0000
> @@ -92,13 +92,36 @@
>
> _local = threading.local()
>
> -def set_request_started(starttime=none, request_statements=none):
> +
> +class commitlogger:
> + def __init__(self, txn):
> + self.txn = txn
> +
> + def newtransaction(self, txn):
> + pass
> +
> + def beforecompletion(self, txn):
> + pass
> +
> + def aftercompletion(self, txn):
> + now = time()
> + _log_statement(
> + now, now, none, 'transaction completed, status: %s' % txn.status)
> +
> +
> +def set_request_started(starttime=none, request_statements=none, txn=none):
> """set the start time for the request being served by the current
> thread.
>
> - if the argument is given, it is used as the start time for the
> - request, as returned by time(). if it is not given, the
> + if the argument starttime is given, it is used as the start time for
> + the request, as returned by time(). if it is not given, the...

review: Approve (code)

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'lib/canonical/database/ftests/test_zopelesstransactionmanager.txt'
2--- lib/canonical/database/ftests/test_zopelesstransactionmanager.txt 2008-05-19 15:47:23 +0000
3+++ lib/canonical/database/ftests/test_zopelesstransactionmanager.txt 2010-03-23 21:06:54 +0000
4@@ -90,3 +90,29 @@
5 >>> print c.fetchone()[0]
6 read committed
7 >>> ztm.uninstall()
8+
9+We can also register synchronizers with the transaction manager.
10+
11+ >>> class TestSynchonizer:
12+ ... def newTransaction(self, txn):
13+ ... print "New transaction started."
14+ ...
15+ ... def beforeCompletion(self, txn):
16+ ... print "Transaction will be completed."
17+ ...
18+ ... def afterCompletion(self, txn):
19+ ... print "Transaction completed."
20+ >>>
21+ >>> synchronizer = TestSynchonizer()
22+ >>> ztm.registerSynch(synchronizer)
23+ >>> ztm.begin()
24+ New transaction started.
25+ >>> ztm.commit()
26+ Transaction will be completed.
27+ Transaction completed.
28+
29+The synchonizer can be unregistered again.
30+
31+ >>> ztm.unregisterSynch(synchronizer)
32+ >>> ztm.begin()
33+ >>> ztm.commit()
34
35=== modified file 'lib/canonical/database/sqlbase.py'
36--- lib/canonical/database/sqlbase.py 2010-01-22 06:25:48 +0000
37+++ lib/canonical/database/sqlbase.py 2010-03-23 21:06:54 +0000
38@@ -427,6 +427,16 @@
39 """Abort the current transaction."""
40 transaction.abort()
41
42+ @staticmethod
43+ def registerSynch(synch):
44+ """Register an ISynchronizer."""
45+ transaction.manager.registerSynch(synch)
46+
47+ @staticmethod
48+ def unregisterSynch(synch):
49+ """Unregister an ISynchronizer."""
50+ transaction.manager.unregisterSynch(synch)
51+
52
53 def clear_current_connection_cache():
54 """Clear SQLObject's object cache. SQLObject compatibility - DEPRECATED.
55
56=== modified file 'lib/canonical/launchpad/webapp/adapter.py'
57--- lib/canonical/launchpad/webapp/adapter.py 2010-03-22 13:07:05 +0000
58+++ lib/canonical/launchpad/webapp/adapter.py 2010-03-23 21:06:54 +0000
59@@ -92,13 +92,35 @@
60
61 _local = threading.local()
62
63-def set_request_started(starttime=None, request_statements=None):
64+
65+class CommitLogger:
66+ def __init__(self, txn):
67+ self.txn = txn
68+
69+ def newTransaction(self, txn):
70+ pass
71+
72+ def beforeCompletion(self, txn):
73+ pass
74+
75+ def afterCompletion(self, txn):
76+ now = time()
77+ _log_statement(
78+ now, now, None, 'Transaction completed, status: %s' % txn.status)
79+
80+
81+def set_request_started(starttime=None, request_statements=None, txn=None):
82 """Set the start time for the request being served by the current
83 thread.
84
85- If the argument is given, it is used as the start time for the
86- request, as returned by time(). If it is not given, the
87- current time is used.
88+ :param start_time: The start time of the request. If given, it is used as
89+ the start time for the request, as returned by time(). If it is not
90+ given, the current time is used.
91+ :param request_statements; The sequence used to store the logged SQL
92+ statements.
93+ :type request_statements: mutable sequence.
94+ :param txn: The current transaction manager. If given, txn.commit() and
95+ txn.abort() calls are logged too.
96 """
97 if getattr(_local, 'request_start_time', None) is not None:
98 warnings.warn('set_request_started() called before previous request '
99@@ -112,7 +134,9 @@
100 else:
101 _local.request_statements = request_statements
102 _local.current_statement_timeout = None
103-
104+ if txn is not None:
105+ _local.commit_logger = CommitLogger(txn)
106+ txn.registerSynch(_local.commit_logger)
107
108 def clear_request_started():
109 """Clear the request timer. This function should be called when
110@@ -123,6 +147,10 @@
111
112 _local.request_start_time = None
113 _local.request_statements = []
114+ commit_logger = getattr(_local, 'commit_logger', None)
115+ if commit_logger is not None:
116+ _local.commit_logger.txn.unregisterSynch(_local.commit_logger)
117+ del _local.commit_logger
118
119
120 def summarize_requests():
121@@ -184,7 +212,10 @@
122 endtime = int((endtime - request_starttime) * 1000)
123 # A string containing no whitespace that lets us identify which Store
124 # is being used.
125- database_identifier = connection_wrapper._database.name
126+ if connection_wrapper is not None:
127+ database_identifier = connection_wrapper._database.name
128+ else:
129+ database_identifier = None
130 _local.request_statements.append(
131 (starttime, endtime, database_identifier, statement))
132
133
134=== modified file 'lib/canonical/launchpad/webapp/ftests/test_adapter.txt'
135--- lib/canonical/launchpad/webapp/ftests/test_adapter.txt 2010-03-22 13:07:05 +0000
136+++ lib/canonical/launchpad/webapp/ftests/test_adapter.txt 2010-03-23 21:06:54 +0000
137@@ -72,6 +72,25 @@
138 SELECT 3
139 >>> clear_request_started()
140
141+transaction.commit() and transaction.abort() calls are logged too,
142+if we pass the transaction manager to set_request_started(). Note
143+that aborted transactions are still in the status "Active".
144+
145+ >>> set_request_started(txn=transaction.manager)
146+ >>> store.execute('SELECT 1', noresult=True)
147+ >>> store.execute('SELECT 2', noresult=True)
148+ >>> transaction.commit()
149+ >>> store.execute('SELECT 3', noresult=True)
150+ >>> transaction.abort()
151+ >>> for starttime, endtime, db_id, statement in get_request_statements():
152+ ... print statement
153+ SELECT 1
154+ SELECT 2
155+ Transaction completed, status: Committed
156+ SELECT 3
157+ Transaction completed, status: Active
158+ >>> clear_request_started()
159+
160
161 Statement Timeout
162 =================
163
164=== modified file 'lib/lp/bugs/doc/checkwatches-cli-switches.txt'
165--- lib/lp/bugs/doc/checkwatches-cli-switches.txt 2010-03-17 18:45:27 +0000
166+++ lib/lp/bugs/doc/checkwatches-cli-switches.txt 2010-03-23 21:06:54 +0000
167@@ -55,7 +55,7 @@
168 ... super(TestCheckWatchesCronScript, self).__init__(
169 ... name, dbuser, test_args)
170 ... self.logger = FakeLogger()
171- ... self.txn = transaction
172+ ... self.txn = ZopelessTransactionManager
173
174 >>> def run_cronscript_with_args(args):
175 ... # It may seem a bit weird to do ths rather than letting the
176
177=== modified file 'lib/lp/bugs/doc/checkwatches.txt'
178--- lib/lp/bugs/doc/checkwatches.txt 2010-03-22 13:07:05 +0000
179+++ lib/lp/bugs/doc/checkwatches.txt 2010-03-23 21:06:54 +0000
180@@ -91,7 +91,7 @@
181 <BLANKLINE>
182 error-explanation=ExternalBugtracker for ... is not known.
183 ...SELECT 1 FROM BugTracker WHERE BugTracker.id = %s
184- ...
185+ ...Transaction completed, status: Active...
186 Traceback (most recent call last):
187 ...
188 BugWatchUpdateWarning: ExternalBugtracker for BugTrackerType 'SAVANE'
189@@ -139,6 +139,7 @@
190
191 >>> import socket
192 >>> import urllib2
193+ >>> from canonical.database.sqlbase import ZopelessTransactionManager
194 >>> urlopen = urllib2.urlopen
195
196 >>> transaction.commit()
197@@ -146,7 +147,7 @@
198 ... raise socket.timeout("Connection timed out.")
199 >>> try:
200 ... urllib2.urlopen = do_not_urlopen
201- ... updater = BugWatchUpdater(transaction)
202+ ... updater = BugWatchUpdater(ZopelessTransactionManager)
203 ... updater._login()
204 ... updater.updateBugTrackers(
205 ... bug_tracker_names=[example_bug_tracker.name])
206@@ -173,6 +174,7 @@
207 <BLANKLINE>
208 ...SELECT COUNT(*) FROM...
209 ...SELECT BugTracker.active, BugTracker.baseurl...
210+ ...Transaction completed, status: Committed...
211 <BLANKLINE>
212 Traceback (most recent call last):
213 ...
214@@ -254,7 +256,7 @@
215
216 >>> from lp.bugs import externalbugtracker
217 >>> from canonical.launchpad.scripts import FakeLogger
218- >>> updater = BugWatchUpdater(transaction)
219+ >>> updater = BugWatchUpdater(ZopelessTransactionManager)
220 >>> original_log = updater.log
221 >>> batch_size = externalbugtracker.Roundup.batch_size
222 >>> transaction.commit()
223
224=== modified file 'lib/lp/bugs/scripts/checkwatches.py'
225--- lib/lp/bugs/scripts/checkwatches.py 2010-03-22 16:23:28 +0000
226+++ lib/lp/bugs/scripts/checkwatches.py 2010-03-23 21:06:54 +0000
227@@ -97,7 +97,7 @@
228 _default_config_section = 'checkwatches'
229
230
231-def report_oops(message=None, properties=None, info=None):
232+def report_oops(message=None, properties=None, info=None, txn=None):
233 """Record an oops for the current exception.
234
235 This must only be called while handling an exception.
236@@ -114,6 +114,9 @@
237
238 :param info: Exception info.
239 :type info: The return value of `sys.exc_info()`.
240+
241+ :param txn: A transaction manager. If specified, further txn.commit()
242+ calls will be logged.
243 """
244 # Get the current exception info first of all.
245 if info is None:
246@@ -145,11 +148,12 @@
247 if getattr(threading.local(), 'request_start_time', None) is not None:
248 clear_request_started()
249 set_request_started(
250- request_statements=LimitedList(MAX_SQL_STATEMENTS_LOGGED))
251+ request_statements=LimitedList(MAX_SQL_STATEMENTS_LOGGED),
252+ txn=txn)
253 return request
254
255
256-def report_warning(message, properties=None, info=None):
257+def report_warning(message, properties=None, info=None, txn=None):
258 """Create and report a warning as an OOPS.
259
260 If no exception info is passed in this will create a generic
261@@ -158,6 +162,7 @@
262 :param message: See `report_oops`.
263 :param properties: See `report_oops`.
264 :param info: See `report_oops`.
265+ :param txn: See `report_oops`.
266 """
267 if info is None:
268 # Raise and catch the exception so that sys.exc_info will
269@@ -167,7 +172,7 @@
270 except BugWatchUpdateWarning:
271 return report_oops(message, properties)
272 else:
273- return report_oops(message, properties, info)
274+ return report_oops(message, properties, info, txn)
275
276
277 class BugWatchUpdater(object):
278@@ -255,7 +260,8 @@
279 try:
280 set_request_started(
281 request_statements=LimitedList(
282- MAX_SQL_STATEMENTS_LOGGED))
283+ MAX_SQL_STATEMENTS_LOGGED),
284+ txn=self.txn)
285 run = self._interactionDecorator(self.updateBugTracker)
286 return run(bug_tracker_id, batch_size)
287 finally:
288@@ -1152,13 +1158,13 @@
289
290 def warning(self, message, properties=None, info=None):
291 """Record a warning related to this bug tracker."""
292- oops_info = report_warning(message, properties, info)
293+ oops_info = report_warning(message, properties, info, self.txn)
294 # Also put it in the log.
295 self.log.warning("%s (%s)" % (message, oops_info.oopsid))
296
297 def error(self, message, properties=None, info=None):
298 """Record an error related to this external bug tracker."""
299- oops_info = report_oops(message, properties, info)
300+ oops_info = report_oops(message, properties, info, self.txn)
301
302 # Also put it in the log.
303 self.log.error("%s (%s)" % (message, oops_info.oopsid))
304
305=== modified file 'lib/lp/bugs/scripts/tests/test_checkwatches.py'
306--- lib/lp/bugs/scripts/tests/test_checkwatches.py 2010-03-15 16:14:13 +0000
307+++ lib/lp/bugs/scripts/tests/test_checkwatches.py 2010-03-23 21:06:54 +0000
308@@ -80,7 +80,7 @@
309 # Create an updater with a limited set of syncable gnome
310 # products.
311 self.updater = checkwatches.BugWatchUpdater(
312- transaction, QuietFakeLogger(), ['test-product'])
313+ transaction.manager, QuietFakeLogger(), ['test-product'])
314
315 def tearDown(self):
316 checkwatches.externalbugtracker.get_external_bugtracker = (
317@@ -112,7 +112,7 @@
318 # BugWatchUpdater.updateBugWatches() shouldn't cause
319 # checkwatches to abort.
320 updater = NoBugWatchesByRemoteBugUpdater(
321- transaction, QuietFakeLogger())
322+ transaction.manager, QuietFakeLogger())
323
324 # Create a couple of bug watches for testing purposes.
325 bug_tracker = self.factory.makeBugTracker()
326@@ -313,7 +313,8 @@
327
328 def __init__(self, output_file):
329 logger = QuietFakeLogger()
330- super(BugWatchUpdaterForThreads, self).__init__(transaction, logger)
331+ super(BugWatchUpdaterForThreads, self).__init__(
332+ transaction.manager, logger)
333 self.output_file = output_file
334
335 def _getExternalBugTrackersAndWatches(self, bug_trackers, bug_watches):