Merge lp:~stub/launchpad/page-performance-report into lp:launchpad

[Stuart Bishop]

Emit the pageid to the ZServer tracelogs.

Emit the pageid to the ZServer tracelogs.

We will use this to improve our page performance reports. The report itself will not land this cycle, but it would be good to get the information into the production logs so we have real data to test the improved report against.

[Jeroen T. Vermeulen (jtv)]

Fixed some things interactively: removed a redundant comment, extracted a function so as to keep the surrounding if/elif block clear. Thanks for those, and the drive-by HTML cleanup.

Next thing to do for this is a bit of testing.

[Jeroen T. Vermeulen (jtv)]

Since this is ongoing work, not operational yet, and some parts of it need to be landed I'm okay with landing this as a whole. The two conditions are that (1) you ensure that things that used to work don't suddenly blow up, and (2) there be a bug about the missing tests.

review: Approve (code)

[Stuart Bishop (stub)]

review: Abstain

[Stuart Bishop (stub)]

This should have landed a few hours before PQM closed, but ec2 silently ate the branch (twice!)

[Curtis Hovey (sinzui)]

I am sorry that I missed your original request. You have my RC to land this.

review: Approve (release-critical)

=== modified file 'lib/canonical/launchpad/webapp/publication.py'
--- lib/canonical/launchpad/webapp/publication.py	2010-04-14 07:38:55 +0000
+++ lib/canonical/launchpad/webapp/publication.py	2010-05-26 10:08:35 +0000
@@ -413,8 +413,12 @@
         # The view name used in the pageid usually comes from ZCML and so
         # it will be a unicode string although it shouldn't.  To avoid
         # problems we encode it into ASCII.
-        request.setInWSGIEnvironment(
-            'launchpad.pageid', pageid.encode('ASCII'))
+        pageid = pageid.encode('US-ASCII')
+
+        request.setInWSGIEnvironment('launchpad.pageid', pageid)
+
+        # And spit the pageid out to our tracelog.
+        tracelog(request, 'p', pageid)
 
         if isinstance(removeSecurityProxy(ob), METHOD_WRAPPER_TYPE):
             # this is a direct call on a C-defined method such as __repr__ or
@@ -435,7 +439,6 @@
         Because of this we cannot chain to the superclass and implement
         the whole behaviour here.
         """
-        orig_env = request._orig_env
         assert hasattr(request, '_publicationticks_start'), (
             'request._publicationticks_start, which should have been set by '
             'callObject(), was not found.')
@@ -497,9 +500,7 @@
         _maybePlacefullyAuthenticate.
         """
         # Log the URL including vhost information to the ZServer tracelog.
-        tracelog = ITraceLog(request, None)
-        if tracelog is not None:
-            tracelog.log(request.getURL())
+        tracelog(request, 'u', request.getURL())
 
         assert hasattr(request, '_traversalticks_start'), (
             'request._traversalticks_start, which should have been set by '
@@ -788,3 +789,16 @@
     return (
         user_agent is not None
         and _browser_re.search(user_agent) is not None)
+
+
+def tracelog(request, prefix, msg):
+    """Emit a message to the ITraceLog, or do nothing if there is none.
+
+    The message will be prefixed by ``prefix`` to make writing parsers
+    easier. ``prefix`` should be unique and contain no spaces, and
+    preferably a single character to save space.
+    """
+    tracelog = ITraceLog(request, None)
+    if tracelog is not None:
+        tracelog.log('%s %s' % (prefix, msg.encode('US-ASCII')))
+

=== modified file 'lib/lp/scripts/utilities/pageperformancereport.py'
--- lib/lp/scripts/utilities/pageperformancereport.py	2010-02-03 14:52:44 +0000
+++ lib/lp/scripts/utilities/pageperformancereport.py	2010-05-26 10:08:35 +0000
@@ -19,7 +19,7 @@
 
 import numpy
 import simplejson as json
-from zc.zservertracelog.tracereport import Request, parsedt
+from zc.zservertracelog.tracereport import Request
 
 from canonical.config import config
 from canonical.launchpad.scripts.logger import log
@@ -193,7 +193,7 @@
         for line in smart_open(tracefile):
             line = line.rstrip()
             try:
-                record = line.split(' ',7)
+                record = line.split(' ', 7)
                 try:
                     record_type, request_id, date, time_ = record[:4]
                 except ValueError:
@@ -232,13 +232,20 @@
                 if request is None: # Just ignore partial records.
                     continue
 
-                if record_type == '-': # Extension record from Launchpad.
-                    # Launchpad outputs the full URL to the tracelog,
-                    # including protocol & hostname. Use this in favor of
-                    # the ZServer logged path.
-                    require_args(1)
+                # Old stype extension record from Launchpad. Just
+                # contains the URL.
+                if record_type == '-' and len(args) == 1:
                     request.url = args[0]
 
+                # New style extension record with a prefix.
+                elif record_type == '-':
+                    # Launchpad outputs several things as tracelog
+                    # extension records. We include a prefix to tell
+                    # them apart.
+                    require_args(2)
+
+                    parse_extension_record(request, args)
+
                 elif record_type == 'I': # Got request input.
                     require_args(1)
                     request.I(dt, args[0])
@@ -266,6 +273,18 @@
                     "Malformed line %s %s (%s)" % (repr(line), repr(args), x))
 
 
+def parse_extension_record(self, request, args):
+    """Decode a ZServer extension records and annotate request."""
+    prefix = args[0]
+    if prefix == 'u':
+        request.url = args[1]
+    elif prefix == 'p':
+        request.pageid = args[1]
+    else:
+        raise MalformedLine(
+            "Unknown extension prefix %s" % prefix)
+
+
 def print_html_report(categories):
 
     print dedent('''\
@@ -318,7 +337,7 @@
         histograms.append(histogram)
         print dedent("""\
             <tr class="%s">
-            <th class="category-title">%s <div class="regexp">%s</span></th>
+            <th class="category-title">%s <span class="regexp">%s</span></th>
             <td class="mean">%.2f s</td>
             <td class="median">%.2f s</td>
             <td class="standard-deviation">%.2f s</td>
@@ -331,6 +350,9 @@
                 html_quote(category.title), html_quote(category.regexp),
                 mean, median, standard_deviation, i))
 
+    print "</tbody></table>"
+
+
     print dedent("""\
         <script language="javascript" type="text/javascript">
         $(function () {