Merge lp:~lifeless/launchpad/bug-627701 into lp:launchpad

Proposed by Robert Collins
Status: Merged
Approved by: Jonathan Lange
Approved revision: no longer in the source branch.
Merged at revision: 11668
Proposed branch: lp:~lifeless/launchpad/bug-627701
Merge into: lp:launchpad
Diff against target: 285 lines (+125/-20)
5 files modified
lib/canonical/launchpad/doc/timeout.txt (+38/-5)
lib/canonical/launchpad/webapp/adapter.py (+48/-10)
lib/canonical/launchpad/webapp/ftests/test_adapter.py (+19/-1)
lib/canonical/launchpad/webapp/publication.py (+17/-0)
lib/lp/services/features/flags.py (+3/-4)
To merge this branch: bzr merge lp:~lifeless/launchpad/bug-627701
Reviewer Review Type Date Requested Status
Jonathan Lange (community) Approve
Review via email: mp+37094@code.launchpad.net

Commit message

Permit controlling timeouts via feature flags.

Description of the change

Permit controlling timeouts via feature flags - a collaboration between Diogo and I.

To post a comment you must log in.
Revision history for this message
Jonathan Lange (jml) wrote :

 * Line 137 of the diff. If getFeatureFlag raises, then timeout_str is never set and the "if timeout_str" check will fail with a NameError. This leads me to believe the code was not TDDd.

 * The documentation in timeout.txt doesn't make it clear how you would use this feature flag for the purposes stated in the text (e.g. pages for which there are a few specific users). As far as I can tell from the test, it's a global thing. It would be nice to point to some place the reader could learn more.

review: Needs Fixing
Revision history for this message
Robert Collins (lifeless) wrote :

if getFeatureFlag raises, timeout_str is not evaluated. The finally only guards the reentrancy check.

I'll add some more to the prose to point folk at feature flags info.

Revision history for this message
Jonathan Lange (jml) wrote :

I misread the code. Approved to land with the documentation point addressed.

review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'lib/canonical/launchpad/doc/timeout.txt'
2--- lib/canonical/launchpad/doc/timeout.txt 2010-09-13 04:45:59 +0000
3+++ lib/canonical/launchpad/doc/timeout.txt 2010-10-03 01:22:47 +0000
4@@ -37,20 +37,19 @@
5 (Set the request to have started a few seconds in the past.)
6
7 >>> import time
8- >>> from canonical.launchpad.webapp.adapter import set_request_started
9- >>> now = time.time()
10- >>> set_request_started(now-5)
11+ >>> from canonical.launchpad.webapp import adapter
12+ >>> adapter.set_request_started(time.time()-5)
13
14 So the computed timeout should be more or less 5 seconds (10-5).
15
16- >>> timeout_func() - now <= 5
17+ >>> timeout_func() <= 5
18 True
19
20 If the timeout is already expired, a RequestExpired error is raised:
21
22 >>> from canonical.launchpad.webapp.adapter import clear_request_started
23 >>> clear_request_started()
24- >>> set_request_started(now-12)
25+ >>> adapter.set_request_started(time.time()-12)
26 >>> timeout_func()
27 Traceback (most recent call last):
28 ...
29@@ -79,6 +78,40 @@
30
31 >>> wait_a_little()
32
33+= Overriding hard timeouts via FeatureFlags =
34+
35+It's possible to use FeatureFlags to control the hard timeout. This is used to
36+deal with pages that suddenly start performing badly, which are being optimised
37+but should not hold back the overall timeout decrease, or for which there are
38+only a few specific users and we are willing to have them run for longer
39+periods. For more information on feature flags see lp.services.features.
40+
41+ >>> from canonical.launchpad.webapp.servers import LaunchpadTestRequest
42+ >>> from lp.services.features.model import FeatureFlag, getFeatureStore
43+ >>> from lp.services.features.webapp import ScopesFromRequest
44+ >>> from lp.services.features.flags import FeatureController
45+ >>> from lp.services.features import per_thread
46+
47+Install the feature flag to increase the timeout value.
48+
49+ >>> config.push('flagstimeout', dedent('''\
50+ ... [database]
51+ ... db_statement_timeout = 10000'''))
52+
53+ >>> empty_request = LaunchpadTestRequest()
54+ >>> per_thread.features = FeatureController(
55+ ... ScopesFromRequest(empty_request).lookup)
56+ >>> ignore = getFeatureStore().add(FeatureFlag(
57+ ... scope=u'default', flag=u'hard_timeout', value=u'20000',
58+ ... priority=1))
59+
60+Now the request can take 20 seconds to complete.
61+
62+ >>> clear_request_started()
63+ >>> adapter.set_request_started(time.time())
64+ >>> adapter.set_permit_timeout_from_features(True)
65+ >>> abs(adapter._get_request_timeout()-20000) < 0.001
66+ True
67
68 == Clean up ===
69
70
71=== modified file 'lib/canonical/launchpad/webapp/adapter.py'
72--- lib/canonical/launchpad/webapp/adapter.py 2010-09-14 04:52:39 +0000
73+++ lib/canonical/launchpad/webapp/adapter.py 2010-10-03 01:22:47 +0000
74@@ -6,7 +6,7 @@
75
76 __metaclass__ = type
77
78-import datetime
79+import logging
80 import os
81 import re
82 import sys
83@@ -47,7 +47,6 @@
84 from canonical.config import (
85 config,
86 DatabaseConfig,
87- dbconfig,
88 )
89 from canonical.database.interfaces import IRequestExpired
90 from canonical.launchpad.interfaces import (
91@@ -67,6 +66,7 @@
92 from canonical.launchpad.webapp.opstats import OpStats
93 from canonical.lazr.utils import get_current_browser_request, safe_hasattr
94 from canonical.lazr.timeout import set_default_timeout_function
95+from lp.services import features
96 from lp.services.timeline.timeline import Timeline
97 from lp.services.timeline.requesttimeline import (
98 get_request_timeline,
99@@ -82,8 +82,6 @@
100 'get_request_start_time',
101 'get_request_duration',
102 'get_store_name',
103- 'hard_timeout_expired',
104- 'launchpad_default_timeout',
105 'soft_timeout_expired',
106 'StoreSelector',
107 ]
108@@ -182,13 +180,16 @@
109 if txn is not None:
110 _local.commit_logger = CommitLogger(txn)
111 txn.registerSynch(_local.commit_logger)
112+ set_permit_timeout_from_features(False)
113+
114
115 def clear_request_started():
116 """Clear the request timer. This function should be called when
117 the request completes.
118 """
119 if getattr(_local, 'request_start_time', None) is None:
120- warnings.warn('clear_request_started() called outside of a request')
121+ warnings.warn('clear_request_started() called outside of a request',
122+ stacklevel=2)
123 _local.request_start_time = None
124 request = get_current_browser_request()
125 set_request_timeline(request, Timeline())
126@@ -257,10 +258,50 @@
127 return now - starttime
128
129
130+def set_permit_timeout_from_features(enabled):
131+ """Control request timeouts being obtained from the 'hard_timeout' flag.
132+
133+ Until we've fully setup a page to render - routed the request to the right
134+ object, setup a participation etc, feature flags cannot be completely used;
135+ and because doing feature flag lookups will trigger DB access, attempting
136+ to do a DB lookup will cause a nested DB lookup (the one being done, and
137+ the flags lookup). To resolve all of this, timeouts start as a config file
138+ only setting, and are then overridden once the request is ready to execute.
139+
140+ :param enabled: If True permit looking up request timeouts in feature
141+ flags.
142+ """
143+ _local._permit_feature_timeout = enabled
144+
145+
146+def _get_request_timeout(timeout=None):
147+ """Get the timeout value in ms for the current request.
148+
149+ :param timeout: A custom timeout in ms.
150+ :return None or a time in ms representing the budget to grant the request.
151+ """
152+ if not getattr(_local, 'enable_timeout', True):
153+ return None
154+ if timeout is None:
155+ timeout = config.database.db_statement_timeout
156+ if getattr(_local, '_permit_feature_timeout', False):
157+ set_permit_timeout_from_features(False)
158+ try:
159+ timeout_str = features.getFeatureFlag('hard_timeout')
160+ finally:
161+ set_permit_timeout_from_features(True)
162+ if timeout_str:
163+ try:
164+ timeout = float(timeout_str)
165+ except ValueError:
166+ logging.error('invalid hard timeout flag %r', timeout_str)
167+ return timeout
168+
169+
170 def get_request_remaining_seconds(no_exception=False, now=None, timeout=None):
171 """Return how many seconds are remaining in the current request budget.
172
173- If timouts are disabled, None is returned.
174+ If timeouts are disabled, None is returned.
175
176 :param no_exception: If True, do not raise an error if the request
177 is out of time. Instead return a float e.g. -2.0 for 2 seconds over
178@@ -269,10 +310,7 @@
179 :param timeout: A custom timeout in ms.
180 :return: None or a float representing the remaining time budget.
181 """
182- if not getattr(_local, 'enable_timeout', True):
183- return None
184- if timeout is None:
185- timeout = config.database.db_statement_timeout
186+ timeout = _get_request_timeout(timeout=timeout)
187 if not timeout:
188 return None
189 duration = get_request_duration(now)
190
191=== modified file 'lib/canonical/launchpad/webapp/ftests/test_adapter.py'
192--- lib/canonical/launchpad/webapp/ftests/test_adapter.py 2010-08-20 20:31:18 +0000
193+++ lib/canonical/launchpad/webapp/ftests/test_adapter.py 2010-10-03 01:22:47 +0000
194@@ -7,11 +7,28 @@
195 import unittest
196
197 from canonical.launchpad.testing.systemdocs import LayeredDocFileSuite
198+from canonical.launchpad.webapp import adapter
199 from canonical.testing import LaunchpadFunctionalLayer
200+from lp.testing import TestCase
201+
202+
203+class TestTimeout(TestCase):
204+
205+ def test_set_permit_timeout_from_features(self):
206+ adapter.set_permit_timeout_from_features(True)
207+ self.assertTrue(adapter._local._permit_feature_timeout)
208+ adapter.set_permit_timeout_from_features(False)
209+ self.assertFalse(adapter._local._permit_feature_timeout)
210+
211+ def test_set_request_started_disables_flag_timeout(self):
212+ adapter.set_request_started()
213+ self.addCleanup(adapter.clear_request_started)
214+ self.assertFalse(adapter._local._permit_feature_timeout)
215
216
217 def test_suite():
218- return unittest.TestSuite([
219+ suite = unittest.TestLoader().loadTestsFromName(__name__)
220+ suite.addTests([
221 LayeredDocFileSuite(
222 'test_adapter.txt',
223 layer=LaunchpadFunctionalLayer),
224@@ -24,3 +41,4 @@
225 'test_adapter_permissions.txt',
226 layer=LaunchpadFunctionalLayer),
227 ])
228+ return suite
229
230=== modified file 'lib/canonical/launchpad/webapp/publication.py'
231--- lib/canonical/launchpad/webapp/publication.py 2010-09-13 06:50:12 +0000
232+++ lib/canonical/launchpad/webapp/publication.py 2010-10-03 01:22:47 +0000
233@@ -83,6 +83,8 @@
234 IPersonSet,
235 ITeam,
236 )
237+from lp.services import features
238+from lp.services.features.flags import NullFeatureController
239
240
241 METHOD_WRAPPER_TYPE = type({}.__setitem__)
242@@ -454,6 +456,21 @@
243 # And spit the pageid out to our tracelog.
244 tracelog(request, 'p', pageid)
245
246+ # For opstats, where we really don't want to have any DB access at all,
247+ # ensure that all flag lookups will stop early.
248+ if pageid in ('RootObject:OpStats', 'RootObject:+opstats'):
249+ request.features = NullFeatureController()
250+ features.per_thread.features = request.features
251+
252+ # Calculate the hard timeout: needed because featureflags can be used
253+ # to control the hard timeout, and they trigger DB access, but our
254+ # DB tracers are not safe for reentrant use, so we must do this
255+ # outside of the SQL stack. We must also do it after traversal so that
256+ # the view is known and can be used in scope resolution. As we actually
257+ # stash the pageid after afterTraversal, we need to do this even later.
258+ da.set_permit_timeout_from_features(True)
259+ da._get_request_timeout()
260+
261 if isinstance(removeSecurityProxy(ob), METHOD_WRAPPER_TYPE):
262 # this is a direct call on a C-defined method such as __repr__ or
263 # dict.__setitem__. Apparently publishing this is possible and
264
265=== modified file 'lib/lp/services/features/flags.py'
266--- lib/lp/services/features/flags.py 2010-09-27 08:13:49 +0000
267+++ lib/lp/services/features/flags.py 2010-10-03 01:22:47 +0000
268@@ -8,6 +8,7 @@
269
270
271 from lp.services.features.rulesource import (
272+ NullFeatureRuleSource,
273 StormFeatureRuleSource,
274 )
275
276@@ -151,7 +152,5 @@
277 """For use in testing: everything is turned off"""
278
279 def __init__(self):
280- FeatureController.__init__(self, lambda scope: None)
281-
282- def _loadRules(self):
283- return []
284+ FeatureController.__init__(self, lambda scope: None,
285+ NullFeatureRuleSource())