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
=== modified file 'lib/canonical/configure.zcml'
--- lib/canonical/configure.zcml 2010-07-12 08:34:29 +0000
+++ lib/canonical/configure.zcml 2010-07-14 08:59:50 +0000
@@ -20,6 +20,7 @@
20 <include package="lp.services.openid" />20 <include package="lp.services.openid" />
21 <include package="lp.services.job" />21 <include package="lp.services.job" />
22 <include package="lp.services.memcache" />22 <include package="lp.services.memcache" />
23 <include package="lp.services.profile" />
23 <include package="lp.services.scripts" />24 <include package="lp.services.scripts" />
24 <include package="lp.services.worlddata" />25 <include package="lp.services.worlddata" />
25 <include package="lp.services.salesforce" />26 <include package="lp.services.salesforce" />
2627
=== modified file 'lib/canonical/launchpad/doc/profiling.txt'
--- lib/canonical/launchpad/doc/profiling.txt 2010-04-14 23:53:16 +0000
+++ lib/canonical/launchpad/doc/profiling.txt 2010-07-14 08:59:50 +0000
@@ -69,7 +69,7 @@
69 >>> print PageTestLayer.profiler69 >>> print PageTestLayer.profiler
70 None70 None
7171
72And no stats file is written when the layer is tore down.72And no stats file is written when the layer is torn down.
7373
74 >>> PageTestLayer.tearDown()74 >>> PageTestLayer.tearDown()
75 >>> os.path.exists(pagetests_profile)75 >>> os.path.exists(pagetests_profile)
7676
=== modified file 'lib/canonical/launchpad/webapp/publication.py'
--- lib/canonical/launchpad/webapp/publication.py 2010-06-17 11:35:12 +0000
+++ lib/canonical/launchpad/webapp/publication.py 2010-07-14 08:59:50 +0000
@@ -7,7 +7,6 @@
7 'LaunchpadBrowserPublication',7 'LaunchpadBrowserPublication',
8 ]8 ]
99
10import os
11import re10import re
12import sys11import sys
13import thread12import thread
@@ -15,9 +14,6 @@
15import traceback14import traceback
16import urllib15import urllib
1716
18from cProfile import Profile
19from datetime import datetime
20
21import tickcount17import tickcount
22import transaction18import transaction
2319
@@ -29,7 +25,8 @@
29from zc.zservertracelog.interfaces import ITraceLog25from zc.zservertracelog.interfaces import ITraceLog
30import zope.app.publication.browser26import zope.app.publication.browser
31from zope.app import zapi # used to get at the adapters service27from zope.app import zapi # used to get at the adapters service
32from zope.app.publication.interfaces import BeforeTraverseEvent28from zope.app.publication.interfaces import (
29 BeforeTraverseEvent, StartRequestEvent)
33from zope.app.security.interfaces import IUnauthenticatedPrincipal30from zope.app.security.interfaces import IUnauthenticatedPrincipal
34from zope.component import getUtility, queryMultiAdapter31from zope.component import getUtility, queryMultiAdapter
35from zope.error.interfaces import IErrorReportingUtility32from zope.error.interfaces import IErrorReportingUtility
@@ -45,8 +42,7 @@
45import canonical.launchpad.layers as layers42import canonical.launchpad.layers as layers
46import canonical.launchpad.webapp.adapter as da43import canonical.launchpad.webapp.adapter as da
4744
48from canonical.config import config, dbconfig45from canonical.config import config
49from canonical.mem import memory, resident
50from canonical.launchpad.interfaces.launchpad import ILaunchpadCelebrities46from canonical.launchpad.interfaces.launchpad import ILaunchpadCelebrities
51from canonical.launchpad.interfaces.oauth import IOAuthSignedRequest47from canonical.launchpad.interfaces.oauth import IOAuthSignedRequest
52from canonical.launchpad.readonly import is_read_only48from canonical.launchpad.readonly import is_read_only
@@ -54,10 +50,9 @@
54 IPerson, IPersonSet, ITeam)50 IPerson, IPersonSet, ITeam)
55from canonical.launchpad.webapp.interfaces import (51from canonical.launchpad.webapp.interfaces import (
56 IDatabasePolicy, ILaunchpadRoot, INotificationResponse, IOpenLaunchBag,52 IDatabasePolicy, ILaunchpadRoot, INotificationResponse, IOpenLaunchBag,
57 IPlacelessAuthUtility, IPrimaryContext, IStoreSelector, MAIN_STORE,53 IPlacelessAuthUtility, IPrimaryContext, IStoreSelector,
58 MASTER_FLAVOR, OffsiteFormPostError, NoReferrerError, SLAVE_FLAVOR)54 MASTER_FLAVOR, OffsiteFormPostError, NoReferrerError)
59from canonical.launchpad.webapp.dbpolicy import (55from canonical.launchpad.webapp.dbpolicy import LaunchpadDatabasePolicy
60 DatabaseBlockedPolicy, LaunchpadDatabasePolicy)
61from canonical.launchpad.webapp.menu import structured56from canonical.launchpad.webapp.menu import structured
62from canonical.launchpad.webapp.opstats import OpStats57from canonical.launchpad.webapp.opstats import OpStats
63from lazr.uri import URI, InvalidURIError58from lazr.uri import URI, InvalidURIError
@@ -67,10 +62,6 @@
67METHOD_WRAPPER_TYPE = type({}.__setitem__)62METHOD_WRAPPER_TYPE = type({}.__setitem__)
6863
6964
70class ProfilingOops(Exception):
71 """Fake exception used to log OOPS information when profiling pages."""
72
73
74class LoginRoot:65class LoginRoot:
75 """Object that provides IPublishTraverse to return only itself.66 """Object that provides IPublishTraverse to return only itself.
7667
@@ -144,7 +135,7 @@
144 # revisited.135 # revisited.
145136
146 def beforeTraversal(self, request):137 def beforeTraversal(self, request):
147 self.startProfilingHook()138 notify(StartRequestEvent(request))
148 request._traversalticks_start = tickcount.tickcount()139 request._traversalticks_start = tickcount.tickcount()
149 threadid = thread.get_ident()140 threadid = thread.get_ident()
150 threadrequestfile = open('thread-%s.request' % threadid, 'w')141 threadrequestfile = open('thread-%s.request' % threadid, 'w')
@@ -654,8 +645,6 @@
654 superclass = zope.app.publication.browser.BrowserPublication645 superclass = zope.app.publication.browser.BrowserPublication
655 superclass.endRequest(self, request, object)646 superclass.endRequest(self, request, object)
656647
657 self.endProfilingHook(request)
658
659 da.clear_request_started()648 da.clear_request_started()
660649
661 # Maintain operational statistics.650 # Maintain operational statistics.
@@ -710,62 +699,6 @@
710 if thread_name != 'MainThread' or name.endswith('-slave'):699 if thread_name != 'MainThread' or name.endswith('-slave'):
711 store.reset()700 store.reset()
712701
713 def startProfilingHook(self):
714 """Handle profiling.
715
716 If requests profiling start a profiler. If memory profiling is
717 requested, save the VSS and RSS.
718 """
719 if config.profiling.profile_requests:
720 self.thread_locals.profiler = Profile()
721 self.thread_locals.profiler.enable()
722
723 if config.profiling.memory_profile_log:
724 self.thread_locals.memory_profile_start = (memory(), resident())
725
726 def endProfilingHook(self, request):
727 """If profiling is turned on, save profile data for the request."""
728 # Create a timestamp including milliseconds.
729 now = datetime.fromtimestamp(da.get_request_start_time())
730 timestamp = "%s.%d" % (
731 now.strftime('%Y-%m-%d_%H:%M:%S'), int(now.microsecond/1000.0))
732 pageid = request._orig_env.get('launchpad.pageid', 'Unknown')
733 oopsid = getattr(request, 'oopsid', None)
734
735 if config.profiling.profile_requests:
736 profiler = self.thread_locals.profiler
737 profiler.disable()
738
739 if oopsid is None:
740 # Log an OOPS to get a log of the SQL queries, and other
741 # useful information, together with the profiling
742 # information.
743 info = (ProfilingOops, None, None)
744 error_utility = getUtility(IErrorReportingUtility)
745 error_utility.raising(info, request)
746 oopsid = request.oopsid
747 filename = '%s-%s-%s-%s.prof' % (
748 timestamp, pageid, oopsid,
749 threading.currentThread().getName())
750
751 profiler.dump_stats(
752 os.path.join(config.profiling.profile_dir, filename))
753
754 # Free some memory.
755 self.thread_locals.profiler = None
756
757 # Dump memory profiling info.
758 if config.profiling.memory_profile_log:
759 log = file(config.profiling.memory_profile_log, 'a')
760 vss_start, rss_start = self.thread_locals.memory_profile_start
761 vss_end, rss_end = memory(), resident()
762 if oopsid is None:
763 oopsid = '-'
764 log.write('%s %s %s %f %d %d %d %d\n' % (
765 timestamp, pageid, oopsid, da.get_request_duration(),
766 vss_start, rss_start, vss_end, rss_end))
767 log.close()
768
769702
770class InvalidThreadsConfiguration(Exception):703class InvalidThreadsConfiguration(Exception):
771 """Exception thrown when the number of threads isn't set correctly."""704 """Exception thrown when the number of threads isn't set correctly."""
772705
=== added directory 'lib/lp/services/profile'
=== added file 'lib/lp/services/profile/__init__.py'
--- lib/lp/services/profile/__init__.py 1970-01-01 00:00:00 +0000
+++ lib/lp/services/profile/__init__.py 2010-07-14 08:59:50 +0000
@@ -0,0 +1,7 @@
1# Copyright 2010 Canonical Ltd. This software is licensed under the
2# GNU Affero General Public License version 3 (see the file LICENSE).
3
4"""lp.services.profile - profiling for zope applications.
5
6Tests for this package are currently services stories.
7"""
08
=== added file 'lib/lp/services/profile/configure.zcml'
--- lib/lp/services/profile/configure.zcml 1970-01-01 00:00:00 +0000
+++ lib/lp/services/profile/configure.zcml 2010-07-14 08:59:50 +0000
@@ -0,0 +1,19 @@
1<!-- Copyright 2010 Canonical Ltd. This software is licensed under the
2 GNU Affero General Public License version 3 (see the file LICENSE).
3-->
4
5<configure
6 xmlns="http://namespaces.zope.org/zope"
7 xmlns:browser="http://namespaces.zope.org/browser">
8
9 <subscriber
10 for="zope.app.publication.interfaces.IStartRequestEvent"
11 handler="lp.services.profile.profile.start_request"
12 />
13
14 <subscriber
15 for="zope.app.publication.interfaces.IEndRequestEvent"
16 handler="lp.services.profile.profile.end_request"
17 />
18
19</configure>
020
=== added file 'lib/lp/services/profile/profile.py'
--- lib/lp/services/profile/profile.py 1970-01-01 00:00:00 +0000
+++ lib/lp/services/profile/profile.py 2010-07-14 08:59:50 +0000
@@ -0,0 +1,87 @@
1# Copyright 2010 Canonical Ltd. This software is licensed under the
2# GNU Affero General Public License version 3 (see the file LICENSE).
3
4"""Profile requests when enabled."""
5
6__all__ = []
7
8__metaclass__ = type
9
10from datetime import datetime
11import os
12import threading
13
14from bzrlib.lsprof import Profiler
15from zope.error.interfaces import IErrorReportingUtility
16from zope.component import getUtility
17
18from canonical.config import config
19import canonical.launchpad.webapp.adapter as da
20from canonical.mem import memory, resident
21
22
23class ProfilingOops(Exception):
24 """Fake exception used to log OOPS information when profiling pages."""
25
26
27_profilers = threading.local()
28
29
30def start_request(event):
31 """Handle profiling.
32
33 If profiling is enabled, start a profiler for this thread. If memory
34 profiling is requested, save the VSS and RSS.
35 """
36 if config.profiling.profile_requests:
37 _profilers.profiler = Profiler()
38 _profilers.profiler.start()
39
40 if config.profiling.memory_profile_log:
41 _profilers.memory_profile_start = (memory(), resident())
42
43
44def end_request(event):
45 """If profiling is turned on, save profile data for the request."""
46 request = event.request
47 # Create a timestamp including milliseconds.
48 now = datetime.fromtimestamp(da.get_request_start_time())
49 timestamp = "%s.%d" % (
50 now.strftime('%Y-%m-%d_%H:%M:%S'), int(now.microsecond/1000.0))
51 pageid = request._orig_env.get('launchpad.pageid', 'Unknown')
52 oopsid = getattr(request, 'oopsid', None)
53 if config.profiling.profile_requests:
54 profiler = _profilers.profiler
55 _profilers.profiler = None
56 prof_stats = profiler.stop()
57
58 if oopsid is None:
59 # Log an OOPS to get a log of the SQL queries, and other
60 # useful information, together with the profiling
61 # information.
62 info = (ProfilingOops, None, None)
63 error_utility = getUtility(IErrorReportingUtility)
64 error_utility.raising(info, request)
65 oopsid = request.oopsid
66 filename = '%s-%s-%s-%s.prof' % (
67 timestamp, pageid, oopsid,
68 threading.currentThread().getName())
69
70 dump_path = os.path.join(config.profiling.profile_dir, filename)
71 prof_stats.save(dump_path, format="callgrind")
72
73 # Free some memory.
74 _profilers.profiler = None
75
76 # Dump memory profiling info.
77 if config.profiling.memory_profile_log:
78 log = file(config.profiling.memory_profile_log, 'a')
79 vss_start, rss_start = _profilers.memory_profile_start
80 vss_end, rss_end = memory(), resident()
81 if oopsid is None:
82 oopsid = '-'
83 log.write('%s %s %s %f %d %d %d %d\n' % (
84 timestamp, pageid, oopsid, da.get_request_duration(),
85 vss_start, rss_start, vss_end, rss_end))
86 log.close()
87