Merge lp:~cjwatson/launchpad/remove-tickcount into lp:launchpad

Proposed by Colin Watson on 2019-09-27
Status: Rejected
Rejected by: Colin Watson on 2019-10-07
Proposed branch: lp:~cjwatson/launchpad/remove-tickcount
Merge into: lp:launchpad
Diff against target: 601 lines (+214/-116)
3 files modified
lib/lp/services/webapp/doc/webapp-publication.txt (+129/-75)
lib/lp/services/webapp/publication.py (+78/-34)
lib/lp/services/webapp/servers.py (+7/-7)
To merge this branch: bzr merge lp:~cjwatson/launchpad/remove-tickcount
Reviewer Review Type Date Requested Status
Launchpad code reviewers 2019-09-27 Pending
Review via email: mp+373347@code.launchpad.net

Commit message

Remove tickcount and track traversal/publication durations instead.

Description of the change

tickcount can't work on Python 3, so in the long term we don't have much choice here. We do want to be able to spot contention, but tracking thread time should be enough here. (Unfortunately, as far as I can tell this is only possible with Python >= 3.3.)

This does change the access log format slightly (logging durations rather than ticks), but as far as I can tell nothing cares.

Unmerged revisions

19064. By Colin Watson on 2019-09-27

Remove tickcount and track traversal/publication durations instead.

tickcount can't work on Python 3, so in the long term we don't have much
choice here. We do want to be able to spot contention, but tracking thread
time should be enough here. (Unfortunately, as far as I can tell this is
only possible with Python >= 3.3.)

This does change the access log format slightly (logging durations rather
than ticks), but as far as I can tell nothing cares.

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'lib/lp/services/webapp/doc/webapp-publication.txt'
2--- lib/lp/services/webapp/doc/webapp-publication.txt 2019-05-22 14:57:45 +0000
3+++ lib/lp/services/webapp/doc/webapp-publication.txt 2019-09-27 22:43:03 +0000
4@@ -621,52 +621,62 @@
5 TestContext:TestView
6
7
8-Tick counts
9------------
10+Durations
11+---------
12
13 Similarly to our page IDs, our publication implementation will store the
14-tick counts for the traversal and object publication processes in WSGI
15+durations for the traversal and object publication processes in WSGI
16 variables which aren't set originally.
17
18- >>> import tickcount
19+ >>> import time
20 >>> request, publication = get_request_and_publication()
21 >>> request.setPrincipal(auth_utility.unauthenticatedPrincipal())
22 >>> logout()
23
24-For traversal we start counting the ticks during the beforeTraversal()
25-hook and stop the count in afterTraversal(). The tick count is then
26-available as launchpad.traversalticks in the WSGI environment.
27+For traversal we start counting the duration during the beforeTraversal()
28+hook and stop the count in afterTraversal(). The duration is then available
29+as launchpad.traversalduration in the WSGI environment. On Python >= 3.3,
30+there is also launchpad.traversalthreadduration with the time spent in the
31+current thread.
32
33- >>> 'launchpad.traversalticks' in request._orig_env
34+ >>> 'launchpad.traversalduration' in request._orig_env
35+ False
36+ >>> 'launchpad.traversalthreadduration' in request._orig_env
37 False
38 >>> publication.beforeTraversal(request)
39- >>> tickcount.difference(
40- ... request._traversalticks_start, tickcount.tickcount()) > 0
41- True
42-
43 >>> publication.afterTraversal(request, None)
44- >>> request._orig_env['launchpad.traversalticks'] < 200
45- True
46-
47-For publication we start counting the ticks during the callObject()
48-hook and stop the count in afterCall(). The tick count is then
49-available as launchpad.publicationticks in the WSGI environment.
50-
51- >>> 'launchpad.publicationticks' in request._orig_env
52+ >>> 'launchpad.traversalduration' in request._orig_env
53+ True
54+ >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
55+ ... 'launchpad.traversalthreadduration' in request._orig_env
56+ ... else:
57+ ... True
58+ True
59+
60+For publication we start counting the duration during the callObject()
61+hook and stop the count in afterCall(). The duration is then available as
62+launchpad.publicationduration in the WSGI environment. On Python >= 3.3,
63+there is also launchpad.publicationthreadduration with the time spent in the
64+current thread.
65+
66+ >>> 'launchpad.publicationduration' in request._orig_env
67+ False
68+ >>> 'launchpad.publicationthreadduration' in request._orig_env
69 False
70 >>> publication.callObject(request, TestView(TestContext(), request))
71 u'Result'
72- >>> tickcount.difference(
73- ... request._publicationticks_start, tickcount.tickcount()) > 0
74- True
75-
76 >>> publication.afterCall(request, None)
77- >>> request._orig_env['launchpad.publicationticks'] < 60
78+ >>> 'launchpad.publicationduration' in request._orig_env
79+ True
80+ >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
81+ ... 'launchpad.publicationthreadduration' in request._orig_env
82+ ... else:
83+ ... True
84 True
85 >>> publication.endRequest(request, None)
86
87 If an exception is raised during traversal or object publication, we'll
88-store the ticks up to the point in which the exception is raised. This
89+store the durations up to the point in which the exception is raised. This
90 is done inside the handleException() hook. (The hook also sets and resets
91 the request timer from lp.services.webapp.adapter, so you'll notice
92 some calls to prepare that code to what handleException expects.)
93@@ -687,26 +697,37 @@
94 >>> set_request_started()
95 >>> publication.handleException(
96 ... None, request, exc_info, retry_allowed=False)
97- >>> 'launchpad.traversalticks' in request._orig_env
98- False
99- >>> 'launchpad.publicationticks' in request._orig_env
100+ >>> 'launchpad.traversalduration' in request._orig_env
101+ False
102+ >>> 'launchpad.traversalthreadduration' in request._orig_env
103+ False
104+ >>> 'launchpad.publicationduration' in request._orig_env
105+ False
106+ >>> 'launchpad.publicationthreadduration' in request._orig_env
107 False
108 >>> clear_request_started()
109
110 If we started the traversal, but haven't finished it, we'll only have
111-the ticks for the traversal and not for the publication.
112+the duration for the traversal and not for the publication.
113
114 >>> publication.beforeTraversal(request)
115 >>> publication.handleException(
116 ... None, request, exc_info, retry_allowed=False)
117- >>> request._orig_env['launchpad.traversalticks'] < 200
118- True
119- >>> 'launchpad.publicationticks' in request._orig_env
120+ >>> 'launchpad.traversalduration' in request._orig_env
121+ True
122+ >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
123+ ... 'launchpad.traversalthreadduration' in request._orig_env
124+ ... else:
125+ ... True
126+ True
127+ >>> 'launchpad.publicationduration' in request._orig_env
128+ False
129+ >>> 'launchpad.publicationthreadduration' in request._orig_env
130 False
131 >>> clear_request_started()
132
133 If we started the publication (which means the traversal has been
134-completed), we'll have the ticks for the traversal and the ticks for
135+completed), we'll have the duration for the traversal and the duration for
136 the publication, up to the point where it was forcefully stopped.
137
138 >>> publication.afterTraversal(request, None)
139@@ -715,22 +736,34 @@
140 >>> set_request_started()
141 >>> publication.handleException(
142 ... None, request, exc_info, retry_allowed=False)
143- >>> request._orig_env['launchpad.traversalticks'] < 500
144- True
145- >>> request._orig_env['launchpad.publicationticks'] < 50
146+ >>> 'launchpad.traversalduration' in request._orig_env
147+ True
148+ >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
149+ ... 'launchpad.traversalthreadduration' in request._orig_env
150+ ... else:
151+ ... True
152+ True
153+ >>> 'launchpad.publicationduration' in request._orig_env
154+ True
155+ >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
156+ ... 'launchpad.publicationthreadduration' in request._orig_env
157+ ... else:
158+ ... True
159 True
160 >>> publication.endRequest(request, None)
161 >>> logger.setLevel(old_level)
162
163 When a Retry or DisconnectionError exception is raised and the request
164 supports retry, it will be retried with a copy of the WSGI environment.
165-If that happens, though, we'll remove the [publication,traversal]ticks
166-variables from there.
167+If that happens, though, we'll remove the
168+{publication,traversal}{,thread}duration variables from there.
169
170 >>> request, publication = get_request_and_publication()
171 >>> request.setPrincipal(auth_utility.unauthenticatedPrincipal())
172- >>> request._orig_env['launchpad.traversalticks'] = 500
173- >>> request._orig_env['launchpad.publicationticks'] = 500
174+ >>> request._orig_env['launchpad.traversalduration'] = 0.5
175+ >>> request._orig_env['launchpad.traversalthreadduration'] = 0.4
176+ >>> request._orig_env['launchpad.publicationduration'] = 0.5
177+ >>> request._orig_env['launchpad.publicationthreadduration'] = 0.4
178 >>> request.supportsRetry()
179 True
180 >>> from zope.publisher.interfaces import Retry
181@@ -744,15 +777,21 @@
182 ...
183 Retry: foo
184
185- >>> 'launchpad.publicationticks' in request._orig_env
186- False
187- >>> 'launchpad.traversalticks' in request._orig_env
188+ >>> 'launchpad.publicationduration' in request._orig_env
189+ False
190+ >>> 'launchpad.publicationthreadduration' in request._orig_env
191+ False
192+ >>> 'launchpad.traversalduration' in request._orig_env
193+ False
194+ >>> 'launchpad.traversalthreadduration' in request._orig_env
195 False
196
197 >>> request, publication = get_request_and_publication()
198 >>> request.setPrincipal(auth_utility.unauthenticatedPrincipal())
199- >>> request._orig_env['launchpad.traversalticks'] = 500
200- >>> request._orig_env['launchpad.publicationticks'] = 500
201+ >>> request._orig_env['launchpad.traversalduration'] = 0.5
202+ >>> request._orig_env['launchpad.traversalthreadduration'] = 0.4
203+ >>> request._orig_env['launchpad.publicationduration'] = 0.5
204+ >>> request._orig_env['launchpad.publicationthreadduration'] = 0.4
205 >>> request.supportsRetry()
206 True
207 >>> from storm.exceptions import DisconnectionError
208@@ -766,19 +805,25 @@
209 ...
210 Retry: foo DisconnectionError
211
212- >>> 'launchpad.publicationticks' in request._orig_env
213- False
214- >>> 'launchpad.traversalticks' in request._orig_env
215+ >>> 'launchpad.publicationduration' in request._orig_env
216+ False
217+ >>> 'launchpad.publicationthreadduration' in request._orig_env
218+ False
219+ >>> 'launchpad.traversalduration' in request._orig_env
220+ False
221+ >>> 'launchpad.traversalthreadduration' in request._orig_env
222 False
223
224 Of course, any request can only be retried a certain number of times and
225-when we reach that number of retries we don't pop the tick conts from the
226+when we reach that number of retries we don't pop the durations from the
227 WSGI env.
228
229 >>> request, publication = get_request_and_publication()
230 >>> request.setPrincipal(auth_utility.unauthenticatedPrincipal())
231- >>> request._orig_env['launchpad.traversalticks'] = 500
232- >>> request._orig_env['launchpad.publicationticks'] = 500
233+ >>> request._orig_env['launchpad.traversalduration'] = 0.5
234+ >>> request._orig_env['launchpad.traversalthreadduration'] = 0.4
235+ >>> request._orig_env['launchpad.publicationduration'] = 0.5
236+ >>> request._orig_env['launchpad.publicationthreadduration'] = 0.4
237 >>> request.supportsRetry = lambda: False
238 >>> request.supportsRetry()
239 False
240@@ -792,10 +837,14 @@
241 ...
242 Retry: foo
243
244- >>> request._orig_env['launchpad.publicationticks']
245- 500
246- >>> request._orig_env['launchpad.traversalticks']
247- 500
248+ >>> request._orig_env['launchpad.publicationduration']
249+ 0.5
250+ >>> request._orig_env['launchpad.publicationthreadduration']
251+ 0.4
252+ >>> request._orig_env['launchpad.traversalduration']
253+ 0.5
254+ >>> request._orig_env['launchpad.traversalthreadduration']
255+ 0.4
256
257 (A bit of cleanup so the test can continue)
258
259@@ -818,11 +867,12 @@
260 >>> print request.principal
261 None
262
263- # Our afterCall() implementation expects to find a
264- # _publicationticks_start in its request, which is set by
265+ # Our afterCall() implementation expects to find _publication_start and
266+ # _publication_thread_start in its request, which are set by
267 # callObject(). Since we don't want to callObject() here, we'll
268 # have to change the request manually.
269- >>> request._publicationticks_start = 1345
270+ >>> request._publication_start = 1.345
271+ >>> request._publication_thread_start = None
272 >>> publication.afterCall(request, None)
273 >>> txn.user
274 ''
275@@ -883,11 +933,12 @@
276
277 >>> request, publication = get_request_and_publication(method='GET')
278
279- # Our afterCall() implementation expects to find a
280- # _publicationticks_start in its request, which is set by
281+ # Our afterCall() implementation expects to find _publication_start and
282+ # _publication_thread_start in its request, which are set by
283 # callObject(). Since we don't want to callObject() here, we'll
284 # have to change the request manually.
285- >>> request._publicationticks_start = 1345
286+ >>> request._publication_start = 1.345
287+ >>> request._publication_thread_start = None
288 >>> publication.afterCall(request, None)
289 >>> txn = transaction.begin()
290 >>> foo_bar = get_foo_bar_person()
291@@ -901,11 +952,12 @@
292
293 >>> request, publication = get_request_and_publication(method='POST')
294
295- # Our afterCall() implementation expects to find a
296- # _publicationticks_start in its request, which is set by
297+ # Our afterCall() implementation expects to find _publication_start and
298+ # _publication_thread_start in its request, which are set by
299 # callObject(). Since we don't want to callObject() here, we'll
300 # have to change the request manually.
301- >>> request._publicationticks_start = 1345
302+ >>> request._publication_start = 1.345
303+ >>> request._publication_thread_start = None
304 >>> publication.afterCall(request, None)
305 >>> txn = transaction.begin()
306 >>> print get_foo_bar_person().description
307@@ -934,11 +986,12 @@
308 >>> txn.isDoomed()
309 True
310
311- # Our afterCall() implementation expects to find a
312- # _publicationticks_start in its request, which is set by
313+ # Our afterCall() implementation expects to find _publication_start and
314+ # _publication_thread_start in its request, which are set by
315 # callObject(). Since we don't want to callObject() here, we'll
316 # have to change the request manually.
317- >>> request._publicationticks_start = 1345
318+ >>> request._publication_start = 1.345
319+ >>> request._publication_thread_start = None
320
321 >>> publication.afterCall(request, None)
322 Aborted
323@@ -976,11 +1029,12 @@
324 >>> response = request.response
325 >>> response.setResult('Content that will disappear.')
326
327- # Our afterCall() implementation expects to find a
328- # _publicationticks_start in its request, which is set by
329+ # Our afterCall() implementation expects to find _publication_start and
330+ # _publication_thread_start in its request, which are set by
331 # callObject(). Since we don't want to callObject() here, we'll
332 # have to change the request manually.
333- >>> request._publicationticks_start = 1345
334+ >>> request._publication_start = 1.345
335+ >>> request._publication_thread_start = None
336 >>> publication.afterCall(request, None)
337 >>> request.response.consumeBody()
338 ''
339@@ -992,11 +1046,12 @@
340 >>> response = request.response
341 >>> response.setResult('Some boring content.')
342
343- # Our afterCall() implementation expects to find a
344- # _publicationticks_start in its request, which is set by
345+ # Our afterCall() implementation expects to find _publication_start and
346+ # _publication_thread_start in its request, which are set by
347 # callObject(). Since we don't want to callObject() here, we'll
348 # have to change the request manually.
349- >>> request._publicationticks_start = 1345
350+ >>> request._publication_start = 1.345
351+ >>> request._publication_thread_start = None
352 >>> publication.afterCall(request, None)
353 >>> print request.response.consumeBody()
354 Some boring content.
355@@ -1060,7 +1115,6 @@
356 principal's access_level and scope will match what was specified in the
357 token.
358
359- >>> import time
360 >>> from lp.registry.interfaces.product import IProductSet
361 >>> from lp.services.database.policy import MasterDatabasePolicy
362 >>> from lp.services.database.interfaces import IStoreSelector
363
364=== modified file 'lib/lp/services/webapp/publication.py'
365--- lib/lp/services/webapp/publication.py 2015-12-07 21:03:40 +0000
366+++ lib/lp/services/webapp/publication.py 2019-09-27 22:43:03 +0000
367@@ -1,4 +1,4 @@
368-# Copyright 2009-2011 Canonical Ltd. This software is licensed under the
369+# Copyright 2009-2019 Canonical Ltd. This software is licensed under the
370 # GNU Affero General Public License version 3 (see the file LICENSE).
371
372 __metaclass__ = type
373@@ -11,6 +11,7 @@
374 import sys
375 import thread
376 import threading
377+import time
378 import traceback
379 import urllib
380
381@@ -26,7 +27,6 @@
382 IntegrityError,
383 )
384 from storm.zope.interfaces import IZStorm
385-import tickcount
386 import transaction
387 from zc.zservertracelog.interfaces import ITraceLog
388 import zope.app.publication.browser
389@@ -192,6 +192,17 @@
390 return self
391
392
393+def _get_thread_time():
394+ """Get the CPU time spent in the current thread.
395+
396+ This requires Python >= 3.3, and otherwise returns None.
397+ """
398+ if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
399+ return time.clock_gettime(time.CLOCK_THREAD_CPUTIME_ID)
400+ else:
401+ return None
402+
403+
404 class LaunchpadBrowserPublication(
405 zope.app.publication.browser.BrowserPublication):
406 """Subclass of z.a.publication.BrowserPublication that removes ZODB.
407@@ -240,7 +251,8 @@
408
409 def beforeTraversal(self, request):
410 notify(StartRequestEvent(request))
411- request._traversalticks_start = tickcount.tickcount()
412+ request._traversal_start = time.time()
413+ request._traversal_thread_start = _get_thread_time()
414 threadid = thread.get_ident()
415 threadrequestfile = open_for_writing(
416 'logs/thread-%s.request' % threadid, 'w')
417@@ -416,7 +428,8 @@
418 It also sets the launchpad.userid and launchpad.pageid WSGI
419 environment variables.
420 """
421- request._publicationticks_start = tickcount.tickcount()
422+ request._publication_start = time.time()
423+ request._publication_thread_start = _get_thread_time()
424 if request.response.getStatus() in [301, 302, 303, 307]:
425 return ''
426
427@@ -470,12 +483,17 @@
428 Because of this we cannot chain to the superclass and implement
429 the whole behaviour here.
430 """
431- assert hasattr(request, '_publicationticks_start'), (
432- 'request._publicationticks_start, which should have been set by '
433+ assert hasattr(request, '_publication_start'), (
434+ 'request._publication_start, which should have been set by '
435 'callObject(), was not found.')
436- ticks = tickcount.difference(
437- request._publicationticks_start, tickcount.tickcount())
438- request.setInWSGIEnvironment('launchpad.publicationticks', ticks)
439+ publication_duration = time.time() - request._publication_start
440+ if request._publication_thread_start is not None:
441+ publication_thread_duration = (
442+ _get_thread_time() - request._publication_thread_start)
443+ else:
444+ publication_thread_duration = None
445+ request.setInWSGIEnvironment(
446+ 'launchpad.publicationduration', publication_duration)
447
448 # Calculate SQL statement statistics.
449 sql_statements = da.get_request_statements()
450@@ -483,10 +501,16 @@
451 endtime - starttime
452 for starttime, endtime, id, statement, tb in sql_statements)
453
454- # Log publication tickcount, sql statement count, and sql time
455- # to the tracelog.
456- tracelog(request, 't', '%d %d %d' % (
457- ticks, len(sql_statements), sql_milliseconds))
458+ # Log publication duration (in milliseconds), sql statement count,
459+ # and sql time (in milliseconds) to the tracelog. If we have the
460+ # publication time spent in this thread, then log that too (in
461+ # milliseconds).
462+ tracelog_entry = '%d %d %d' % (
463+ publication_duration * 1000,
464+ len(sql_statements), sql_milliseconds)
465+ if publication_thread_duration is not None:
466+ tracelog_entry += ' %d' % (publication_thread_duration * 1000)
467+ tracelog(request, 't', tracelog_entry)
468
469 # Annotate the transaction with user data. That was done by
470 # zope.app.publication.zopepublication.ZopePublication.
471@@ -547,12 +571,17 @@
472 # Log the URL including vhost information to the ZServer tracelog.
473 tracelog(request, 'u', request.getURL())
474
475- assert hasattr(request, '_traversalticks_start'), (
476- 'request._traversalticks_start, which should have been set by '
477+ assert hasattr(request, '_traversal_start'), (
478+ 'request._traversal_start, which should have been set by '
479 'beforeTraversal(), was not found.')
480- ticks = tickcount.difference(
481- request._traversalticks_start, tickcount.tickcount())
482- request.setInWSGIEnvironment('launchpad.traversalticks', ticks)
483+ traversal_duration = time.time() - request._traversal_start
484+ request.setInWSGIEnvironment(
485+ 'launchpad.traversalduration', traversal_duration)
486+ if request._traversal_thread_start is not None:
487+ traversal_thread_duration = (
488+ _get_thread_time() - request._traversal_thread_start)
489+ request.setInWSGIEnvironment(
490+ 'launchpad.traversalthreadduration', traversal_thread_duration)
491
492 def _maybePlacefullyAuthenticate(self, request, ob):
493 """ This should never be called because we've excised it in
494@@ -569,22 +598,35 @@
495 db_policy = None
496
497 orig_env = request._orig_env
498- ticks = tickcount.tickcount()
499- if (hasattr(request, '_publicationticks_start') and
500- ('launchpad.publicationticks' not in orig_env)):
501+ now = time.time()
502+ thread_now = _get_thread_time()
503+ if (hasattr(request, '_publication_start') and
504+ ('launchpad.publicationduration' not in orig_env)):
505 # The traversal process has been started but hasn't completed.
506- assert 'launchpad.traversalticks' in orig_env, (
507+ assert 'launchpad.traversalduration' in orig_env, (
508 'We reached the publication process so we must have finished '
509 'the traversal.')
510- ticks = tickcount.difference(
511- request._publicationticks_start, ticks)
512- request.setInWSGIEnvironment('launchpad.publicationticks', ticks)
513- elif (hasattr(request, '_traversalticks_start') and
514- ('launchpad.traversalticks' not in orig_env)):
515+ publication_duration = now - request._publication_start
516+ request.setInWSGIEnvironment(
517+ 'launchpad.publicationduration', publication_duration)
518+ if thread_now is not None:
519+ publication_thread_duration = (
520+ thread_now - request._publication_thread_start)
521+ request.setInWSGIEnvironment(
522+ 'launchpad.publicationthreadduration',
523+ publication_thread_duration)
524+ elif (hasattr(request, '_traversal_start') and
525+ ('launchpad.traversalduration' not in orig_env)):
526 # The traversal process has been started but hasn't completed.
527- ticks = tickcount.difference(
528- request._traversalticks_start, ticks)
529- request.setInWSGIEnvironment('launchpad.traversalticks', ticks)
530+ traversal_duration = now - request._traversal_start
531+ request.setInWSGIEnvironment(
532+ 'launchpad.traversalduration', traversal_duration)
533+ if thread_now is not None:
534+ traversal_thread_duration = (
535+ thread_now - request._traversal_thread_start)
536+ request.setInWSGIEnvironment(
537+ 'launchpad.traversalthreadduration',
538+ traversal_thread_duration)
539 else:
540 # The exception wasn't raised in the middle of the traversal nor
541 # the publication, so there's nothing we need to do here.
542@@ -639,10 +681,12 @@
543 # is a normal part of operation.
544 if should_retry(exc_info):
545 if request.supportsRetry():
546- # Remove variables used for counting ticks as this request is
547- # going to be retried.
548- orig_env.pop('launchpad.traversalticks', None)
549- orig_env.pop('launchpad.publicationticks', None)
550+ # Remove variables used for counting publication/traversal
551+ # durations as this request is going to be retried.
552+ orig_env.pop('launchpad.traversalduration', None)
553+ orig_env.pop('launchpad.traversalthreadduration', None)
554+ orig_env.pop('launchpad.publicationduration', None)
555+ orig_env.pop('launchpad.publicationthreadduration', None)
556 # Our endRequest needs to know if a retry is pending or not.
557 request._wants_retry = True
558 # Abort any in-progress transaction and reset any
559
560=== modified file 'lib/lp/services/webapp/servers.py'
561--- lib/lp/services/webapp/servers.py 2019-09-11 13:25:14 +0000
562+++ lib/lp/services/webapp/servers.py 2019-09-27 22:43:03 +0000
563@@ -1,4 +1,4 @@
564-# Copyright 2009-2018 Canonical Ltd. This software is licensed under the
565+# Copyright 2009-2019 Canonical Ltd. This software is licensed under the
566 # GNU Affero General Public License version 3 (see the file LICENSE).
567
568 """Definition of the internet servers that Launchpad uses."""
569@@ -1067,8 +1067,8 @@
570 response bytes written
571 number of nonpython statements (sql, email, memcache, rabbit etc)
572 request duration
573- number of ticks during traversal
574- number of ticks during publication
575+ traversal duration
576+ publication duration
577 launchpad user id
578 launchpad page id
579 REFERER
580@@ -1088,8 +1088,8 @@
581 pageid = cgi_env.get('launchpad.pageid', '')
582 nonpython_actions = cgi_env.get('launchpad.nonpythonactions', 0)
583 request_duration = cgi_env.get('launchpad.requestduration', 0)
584- traversal_ticks = cgi_env.get('launchpad.traversalticks', 0)
585- publication_ticks = cgi_env.get('launchpad.publicationticks', 0)
586+ traversal_duration = cgi_env.get('launchpad.traversalduration', 0)
587+ publication_duration = cgi_env.get('launchpad.publicationduration', 0)
588 referer = request_headers.get('REFERER', '')
589 user_agent = request_headers.get('USER_AGENT', '')
590
591@@ -1106,8 +1106,8 @@
592 bytes_written,
593 nonpython_actions,
594 request_duration,
595- traversal_ticks,
596- publication_ticks,
597+ traversal_duration,
598+ publication_duration,
599 userid,
600 pageid,
601 referer,