Launchpad itself

Merge lp:~lifeless/launchpad/lsprof into lp:launchpad

  1. lsprof
  2. Merge into devel
Proposed by Robert Collins
Status: Merged
Approved by: Robert Collins
Approved revision: no longer in the source branch.
Merged at revision: 11157
Proposed branch: lp:~lifeless/launchpad/lsprof
Merge into: lp:launchpad
Prerequisite: lp:~lifeless/launchpad/lognamer
Diff against target: 301 lines (+122/-75)
6 files modified
lib/canonical/configure.zcml (+1/-0)
lib/canonical/launchpad/doc/profiling.txt (+1/-1)
lib/canonical/launchpad/webapp/publication.py (+7/-74)
lib/lp/services/profile/__init__.py (+7/-0)
lib/lp/services/profile/configure.zcml (+19/-0)
lib/lp/services/profile/profile.py (+87/-0)
To merge this branch: bzr merge lp:~lifeless/launchpad/lsprof
Reviewer Review Type Date Requested Status
Curtis Hovey (community) code Approve
Review via email: mp+28583@code.launchpad.net

Description of the change

Move our existing profiling code to be hook based, which makes it more orthogonal, easier to reason about.

To post a comment you must log in.
Revision history for this message
Curtis Hovey (sinzui) wrote :

Thanks for extracting the profiling behaviour. I have a few remarks.

> === modified file 'lib/canonical/launchpad/webapp/configure.zcml'
> --- lib/canonical/launchpad/webapp/configure.zcml 2010-06-08 15:57:09 +0000
> +++ lib/canonical/launchpad/webapp/configure.zcml 2010-06-27 09:23:29 +0000
> @@ -13,6 +13,8 @@
> <include file="errorlog.zcml" />
> -->
> <include file="bug-5133.zcml" />
> + <!-- Would be nice to turn this off in production -->
> + <include file="profile.zcml" />

Each env gets its own config. ./configs/testrunner-appserver has ZCML
that registers YUI unittest hooks for example. I think this rule could
be in ./configs/development, and in ~launchpad-pqm/production-configs in
staging and dogfood.

> === added file 'lib/canonical/launchpad/webapp/profile.py'
> --- lib/canonical/launchpad/webapp/profile.py 1970-01-01 00:00:00 +0000
> +++ lib/canonical/launchpad/webapp/profile.py 2010-06-27 09:23:29 +0000

We do not want to add to this deprecated location. I think this would
be better located at lib/lp/services/profile

> === added file 'lib/canonical/launchpad/webapp/profile.zcml'
> --- lib/canonical/launchpad/webapp/profile.zcml 1970-01-01 00:00:00 +0000
> +++ lib/canonical/launchpad/webapp/profile.zcml 2010-06-27 09:23:29 +0000

As above.

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

I'll move it to your preferred location.

What rules does testing load - the development set?

-Rob

Revision history for this message
Curtis Hovey (sinzui) wrote :

I am not sure I know what you mean by testing. Each environment has its own ZCML configuration (Which is also bad since there is a lot of duplication).

Everyone can see development and testrunner configs in the launchpad tree.

The production configs for staging, dogfood, edge, etc ..., are in
    https://edge.launchpad.net/lp-production-configs

To enable profiling just on staging and dogfood requires an update to their respective directories in that branch.

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

Yes, I can see that. I meant in the testrunner, because if its not
enabled in the test runner... it can't be tested :)

Anyhow, I think we may still want this on on production, so for now
I'm just going to leave it always configured - I do appreciate the
info though, particularly as I had a comment there.

I'll delete the comment to avoid confusion.

Rob

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

Ok, I've moved the code as requested.

However, I don't know if it still meets the requirement of lp.services that
'packages in this namespace can only use general LAZR or library functionality.'

profile.py imports the canonical config, webapp adapter (for request
timing) and canonical.mem.

Do they need to be moved across first, before this is safe to port across?

-Rob

Revision history for this message
Curtis Hovey (sinzui) wrote :

Canonical.config and webapp adapter should move in our lifetime. They do not need to move now. There are many modules in lp.services using these.

I thought the import rules was removed because it was blocking refactoring. It certainly is being ignored. I think it is unrealistic. The attempt to make all webapp into lazr proved too daunting and I do not think there is any interest in it now. Just getting canonical.launchpad to die will raise a rally of cheers and beers.

review: Approve (code)
Revision history for this message
Robert Collins (lifeless) wrote :

Ok, cool, I'll get both of these landed.

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'lib/canonical/configure.zcml'
2--- lib/canonical/configure.zcml 2010-07-12 08:34:29 +0000
3+++ lib/canonical/configure.zcml 2010-07-14 08:59:50 +0000
4@@ -20,6 +20,7 @@
5 <include package="lp.services.openid" />
6 <include package="lp.services.job" />
7 <include package="lp.services.memcache" />
8+ <include package="lp.services.profile" />
9 <include package="lp.services.scripts" />
10 <include package="lp.services.worlddata" />
11 <include package="lp.services.salesforce" />
12
13=== modified file 'lib/canonical/launchpad/doc/profiling.txt'
14--- lib/canonical/launchpad/doc/profiling.txt 2010-04-14 23:53:16 +0000
15+++ lib/canonical/launchpad/doc/profiling.txt 2010-07-14 08:59:50 +0000
16@@ -69,7 +69,7 @@
17 >>> print PageTestLayer.profiler
18 None
19
20-And no stats file is written when the layer is tore down.
21+And no stats file is written when the layer is torn down.
22
23 >>> PageTestLayer.tearDown()
24 >>> os.path.exists(pagetests_profile)
25
26=== modified file 'lib/canonical/launchpad/webapp/publication.py'
27--- lib/canonical/launchpad/webapp/publication.py 2010-06-17 11:35:12 +0000
28+++ lib/canonical/launchpad/webapp/publication.py 2010-07-14 08:59:50 +0000
29@@ -7,7 +7,6 @@
30 'LaunchpadBrowserPublication',
31 ]
32
33-import os
34 import re
35 import sys
36 import thread
37@@ -15,9 +14,6 @@
38 import traceback
39 import urllib
40
41-from cProfile import Profile
42-from datetime import datetime
43-
44 import tickcount
45 import transaction
46
47@@ -29,7 +25,8 @@
48 from zc.zservertracelog.interfaces import ITraceLog
49 import zope.app.publication.browser
50 from zope.app import zapi # used to get at the adapters service
51-from zope.app.publication.interfaces import BeforeTraverseEvent
52+from zope.app.publication.interfaces import (
53+ BeforeTraverseEvent, StartRequestEvent)
54 from zope.app.security.interfaces import IUnauthenticatedPrincipal
55 from zope.component import getUtility, queryMultiAdapter
56 from zope.error.interfaces import IErrorReportingUtility
57@@ -45,8 +42,7 @@
58 import canonical.launchpad.layers as layers
59 import canonical.launchpad.webapp.adapter as da
60
61-from canonical.config import config, dbconfig
62-from canonical.mem import memory, resident
63+from canonical.config import config
64 from canonical.launchpad.interfaces.launchpad import ILaunchpadCelebrities
65 from canonical.launchpad.interfaces.oauth import IOAuthSignedRequest
66 from canonical.launchpad.readonly import is_read_only
67@@ -54,10 +50,9 @@
68 IPerson, IPersonSet, ITeam)
69 from canonical.launchpad.webapp.interfaces import (
70 IDatabasePolicy, ILaunchpadRoot, INotificationResponse, IOpenLaunchBag,
71- IPlacelessAuthUtility, IPrimaryContext, IStoreSelector, MAIN_STORE,
72- MASTER_FLAVOR, OffsiteFormPostError, NoReferrerError, SLAVE_FLAVOR)
73-from canonical.launchpad.webapp.dbpolicy import (
74- DatabaseBlockedPolicy, LaunchpadDatabasePolicy)
75+ IPlacelessAuthUtility, IPrimaryContext, IStoreSelector,
76+ MASTER_FLAVOR, OffsiteFormPostError, NoReferrerError)
77+from canonical.launchpad.webapp.dbpolicy import LaunchpadDatabasePolicy
78 from canonical.launchpad.webapp.menu import structured
79 from canonical.launchpad.webapp.opstats import OpStats
80 from lazr.uri import URI, InvalidURIError
81@@ -67,10 +62,6 @@
82 METHOD_WRAPPER_TYPE = type({}.__setitem__)
83
84
85-class ProfilingOops(Exception):
86- """Fake exception used to log OOPS information when profiling pages."""
87-
88-
89 class LoginRoot:
90 """Object that provides IPublishTraverse to return only itself.
91
92@@ -144,7 +135,7 @@
93 # revisited.
94
95 def beforeTraversal(self, request):
96- self.startProfilingHook()
97+ notify(StartRequestEvent(request))
98 request._traversalticks_start = tickcount.tickcount()
99 threadid = thread.get_ident()
100 threadrequestfile = open('thread-%s.request' % threadid, 'w')
101@@ -654,8 +645,6 @@
102 superclass = zope.app.publication.browser.BrowserPublication
103 superclass.endRequest(self, request, object)
104
105- self.endProfilingHook(request)
106-
107 da.clear_request_started()
108
109 # Maintain operational statistics.
110@@ -710,62 +699,6 @@
111 if thread_name != 'MainThread' or name.endswith('-slave'):
112 store.reset()
113
114- def startProfilingHook(self):
115- """Handle profiling.
116-
117- If requests profiling start a profiler. If memory profiling is
118- requested, save the VSS and RSS.
119- """
120- if config.profiling.profile_requests:
121- self.thread_locals.profiler = Profile()
122- self.thread_locals.profiler.enable()
123-
124- if config.profiling.memory_profile_log:
125- self.thread_locals.memory_profile_start = (memory(), resident())
126-
127- def endProfilingHook(self, request):
128- """If profiling is turned on, save profile data for the request."""
129- # Create a timestamp including milliseconds.
130- now = datetime.fromtimestamp(da.get_request_start_time())
131- timestamp = "%s.%d" % (
132- now.strftime('%Y-%m-%d_%H:%M:%S'), int(now.microsecond/1000.0))
133- pageid = request._orig_env.get('launchpad.pageid', 'Unknown')
134- oopsid = getattr(request, 'oopsid', None)
135-
136- if config.profiling.profile_requests:
137- profiler = self.thread_locals.profiler
138- profiler.disable()
139-
140- if oopsid is None:
141- # Log an OOPS to get a log of the SQL queries, and other
142- # useful information, together with the profiling
143- # information.
144- info = (ProfilingOops, None, None)
145- error_utility = getUtility(IErrorReportingUtility)
146- error_utility.raising(info, request)
147- oopsid = request.oopsid
148- filename = '%s-%s-%s-%s.prof' % (
149- timestamp, pageid, oopsid,
150- threading.currentThread().getName())
151-
152- profiler.dump_stats(
153- os.path.join(config.profiling.profile_dir, filename))
154-
155- # Free some memory.
156- self.thread_locals.profiler = None
157-
158- # Dump memory profiling info.
159- if config.profiling.memory_profile_log:
160- log = file(config.profiling.memory_profile_log, 'a')
161- vss_start, rss_start = self.thread_locals.memory_profile_start
162- vss_end, rss_end = memory(), resident()
163- if oopsid is None:
164- oopsid = '-'
165- log.write('%s %s %s %f %d %d %d %d\n' % (
166- timestamp, pageid, oopsid, da.get_request_duration(),
167- vss_start, rss_start, vss_end, rss_end))
168- log.close()
169-
170
171 class InvalidThreadsConfiguration(Exception):
172 """Exception thrown when the number of threads isn't set correctly."""
173
174=== added directory 'lib/lp/services/profile'
175=== added file 'lib/lp/services/profile/__init__.py'
176--- lib/lp/services/profile/__init__.py 1970-01-01 00:00:00 +0000
177+++ lib/lp/services/profile/__init__.py 2010-07-14 08:59:50 +0000
178@@ -0,0 +1,7 @@
179+# Copyright 2010 Canonical Ltd. This software is licensed under the
180+# GNU Affero General Public License version 3 (see the file LICENSE).
181+
182+"""lp.services.profile - profiling for zope applications.
183+
184+Tests for this package are currently services stories.
185+"""
186
187=== added file 'lib/lp/services/profile/configure.zcml'
188--- lib/lp/services/profile/configure.zcml 1970-01-01 00:00:00 +0000
189+++ lib/lp/services/profile/configure.zcml 2010-07-14 08:59:50 +0000
190@@ -0,0 +1,19 @@
191+<!-- Copyright 2010 Canonical Ltd. This software is licensed under the
192+ GNU Affero General Public License version 3 (see the file LICENSE).
193+-->
194+
195+<configure
196+ xmlns="http://namespaces.zope.org/zope"
197+ xmlns:browser="http://namespaces.zope.org/browser">
198+
199+ <subscriber
200+ for="zope.app.publication.interfaces.IStartRequestEvent"
201+ handler="lp.services.profile.profile.start_request"
202+ />
203+
204+ <subscriber
205+ for="zope.app.publication.interfaces.IEndRequestEvent"
206+ handler="lp.services.profile.profile.end_request"
207+ />
208+
209+</configure>
210
211=== added file 'lib/lp/services/profile/profile.py'
212--- lib/lp/services/profile/profile.py 1970-01-01 00:00:00 +0000
213+++ lib/lp/services/profile/profile.py 2010-07-14 08:59:50 +0000
214@@ -0,0 +1,87 @@
215+# Copyright 2010 Canonical Ltd. This software is licensed under the
216+# GNU Affero General Public License version 3 (see the file LICENSE).
217+
218+"""Profile requests when enabled."""
219+
220+__all__ = []
221+
222+__metaclass__ = type
223+
224+from datetime import datetime
225+import os
226+import threading
227+
228+from bzrlib.lsprof import Profiler
229+from zope.error.interfaces import IErrorReportingUtility
230+from zope.component import getUtility
231+
232+from canonical.config import config
233+import canonical.launchpad.webapp.adapter as da
234+from canonical.mem import memory, resident
235+
236+
237+class ProfilingOops(Exception):
238+ """Fake exception used to log OOPS information when profiling pages."""
239+
240+
241+_profilers = threading.local()
242+
243+
244+def start_request(event):
245+ """Handle profiling.
246+
247+ If profiling is enabled, start a profiler for this thread. If memory
248+ profiling is requested, save the VSS and RSS.
249+ """
250+ if config.profiling.profile_requests:
251+ _profilers.profiler = Profiler()
252+ _profilers.profiler.start()
253+
254+ if config.profiling.memory_profile_log:
255+ _profilers.memory_profile_start = (memory(), resident())
256+
257+
258+def end_request(event):
259+ """If profiling is turned on, save profile data for the request."""
260+ request = event.request
261+ # Create a timestamp including milliseconds.
262+ now = datetime.fromtimestamp(da.get_request_start_time())
263+ timestamp = "%s.%d" % (
264+ now.strftime('%Y-%m-%d_%H:%M:%S'), int(now.microsecond/1000.0))
265+ pageid = request._orig_env.get('launchpad.pageid', 'Unknown')
266+ oopsid = getattr(request, 'oopsid', None)
267+ if config.profiling.profile_requests:
268+ profiler = _profilers.profiler
269+ _profilers.profiler = None
270+ prof_stats = profiler.stop()
271+
272+ if oopsid is None:
273+ # Log an OOPS to get a log of the SQL queries, and other
274+ # useful information, together with the profiling
275+ # information.
276+ info = (ProfilingOops, None, None)
277+ error_utility = getUtility(IErrorReportingUtility)
278+ error_utility.raising(info, request)
279+ oopsid = request.oopsid
280+ filename = '%s-%s-%s-%s.prof' % (
281+ timestamp, pageid, oopsid,
282+ threading.currentThread().getName())
283+
284+ dump_path = os.path.join(config.profiling.profile_dir, filename)
285+ prof_stats.save(dump_path, format="callgrind")
286+
287+ # Free some memory.
288+ _profilers.profiler = None
289+
290+ # Dump memory profiling info.
291+ if config.profiling.memory_profile_log:
292+ log = file(config.profiling.memory_profile_log, 'a')
293+ vss_start, rss_start = _profilers.memory_profile_start
294+ vss_end, rss_end = memory(), resident()
295+ if oopsid is None:
296+ oopsid = '-'
297+ log.write('%s %s %s %f %d %d %d %d\n' % (
298+ timestamp, pageid, oopsid, da.get_request_duration(),
299+ vss_start, rss_start, vss_end, rss_end))
300+ log.close()
301+