← Back to team overview

launchpad-reviewers team mailing list archive

[Merge] ~cjwatson/launchpad:remove-pagetests-access-logging into launchpad:master

 

Colin Watson has proposed merging ~cjwatson/launchpad:remove-pagetests-access-logging into launchpad:master with ~cjwatson/launchpad:remove-launchpad-conf as a prerequisite.

Commit message:
Remove access logging in pagetests

Requested reviews:
  Launchpad code reviewers (launchpad-reviewers)

For more details, see:
https://code.launchpad.net/~cjwatson/launchpad/+git/launchpad/+merge/405907

Talisker will do well enough for this when it's needed; the amount of code required for bespoke access logging here didn't pull its weight.

This also allows us to remove some WSGI environment logging in favour of the newer arrangements that use the Talisker logging context.
-- 
Your team Launchpad code reviewers is requested to review the proposed merge of ~cjwatson/launchpad:remove-pagetests-access-logging into launchpad:master.
diff --git a/lib/lp/app/stories/basics/xx-pagetest-logging.txt b/lib/lp/app/stories/basics/xx-pagetest-logging.txt
deleted file mode 100644
index b700a8b..0000000
--- a/lib/lp/app/stories/basics/xx-pagetest-logging.txt
+++ /dev/null
@@ -1,11 +0,0 @@
-= Logging requests during pagetests =
-
-When running our pagetests we log all HTTP requests into the
-pagetests-access.log file.
-
-    >>> browser.open('http://launchpad.test/')
-
-    >>> log = open(page_log_location).read()
-    >>> print(log.strip().split('\n')[-1])
-    127.0.0.88 - ... "launchpad.test" [...] "GET / HTTP/1.1" 200 ...
-    "Anonymous" "RootObject:index.html" "" "Python-urllib/..."
diff --git a/lib/lp/services/webapp/adapter.py b/lib/lp/services/webapp/adapter.py
index d2d1d86..beb0eba 100644
--- a/lib/lp/services/webapp/adapter.py
+++ b/lib/lp/services/webapp/adapter.py
@@ -263,15 +263,9 @@ def get_timeline_actions():
     return timeline.actions[:IN_PAGE_TIMELINE_CAP]
 
 
-def store_sql_statements_and_request_duration(event):
+def store_sql_statements(event):
     actions = get_request_timeline(get_current_browser_request()).actions
-    event.request.setInWSGIEnvironment(
-        'launchpad.nonpythonactions', len(actions))
     logging_context.push(nonpython_actions=len(actions))
-    event.request.setInWSGIEnvironment(
-        'launchpad.requestduration', get_request_duration())
-    # Talisker already tracks the request duration itself, so there's no
-    # need to push that onto the logging context here.
 
 
 def get_request_statements():
diff --git a/lib/lp/services/webapp/doc/webapp-publication.txt b/lib/lp/services/webapp/doc/webapp-publication.txt
index ce008d1..75497a1 100644
--- a/lib/lp/services/webapp/doc/webapp-publication.txt
+++ b/lib/lp/services/webapp/doc/webapp-publication.txt
@@ -638,8 +638,8 @@ Durations
 ---------
 
 Similarly to our page IDs, our publication implementation will store the
-durations for the traversal and object publication processes in WSGI
-variables which aren't set originally.
+durations for the traversal and object publication processes in the Talisker
+logging context.
 
     >>> import time
     >>> _ = Context.new()
@@ -649,30 +649,19 @@ variables which aren't set originally.
 
 For traversal we start counting the duration during the beforeTraversal()
 hook and stop the count in afterTraversal().  The duration is then available
-as launchpad.traversalduration in the WSGI environment.  On Python >= 3.3,
-there is also launchpad.traversalthreadduration with the time spent in the
+as traversal_duration_ms in the Talisker logging context.  On Python >= 3.3,
+there is also traversal_thread_duration_ms with the time spent in the
 current thread.
 
-    >>> 'launchpad.traversalduration' in request._orig_env
-    False
     >>> 'traversal_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.traversalthreadduration' in request._orig_env
-    False
     >>> 'traversal_thread_duration_ms' in logging_context.flat
     False
     >>> publication.beforeTraversal(request)
     >>> publication.afterTraversal(request, None)
-    >>> 'launchpad.traversalduration' in request._orig_env
-    True
     >>> 'traversal_duration_ms' in logging_context.flat
     True
     >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
-    ...     'launchpad.traversalthreadduration' in request._orig_env
-    ... else:
-    ...     True
-    True
-    >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
     ...     'traversal_thread_duration_ms' in logging_context.flat
     ... else:
     ...     True
@@ -680,32 +669,21 @@ current thread.
 
 For publication we start counting the duration during the callObject()
 hook and stop the count in afterCall().  The duration is then available as
-launchpad.publicationduration in the WSGI environment.  On Python >= 3.3,
-there is also launchpad.publicationthreadduration with the time spent in the
+publication_duration_ms in the Talisker logging context.  On Python >= 3.3,
+there is also publication_thread_duration_ms with the time spent in the
 current thread.
 
-    >>> 'launchpad.publicationduration' in request._orig_env
-    False
     >>> 'publication_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.publicationthreadduration' in request._orig_env
-    False
     >>> 'publication_thread_duration_ms' in logging_context.flat
     False
     >>> print(publication.callObject(
     ...     request, TestView(TestContext(), request)))
     Result
     >>> publication.afterCall(request, None)
-    >>> 'launchpad.publicationduration' in request._orig_env
-    True
     >>> 'publication_duration_ms' in logging_context.flat
     True
     >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
-    ...     'launchpad.publicationthreadduration' in request._orig_env
-    ... else:
-    ...     True
-    True
-    >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
     ...     'publication_thread_duration_ms' in logging_context.flat
     ... else:
     ...     True
@@ -733,20 +711,12 @@ there's nothing to store.
     >>> set_request_started()
     >>> publication.handleException(
     ...     None, request, exc_info, retry_allowed=False)
-    >>> 'launchpad.traversalduration' in request._orig_env
-    False
     >>> 'traversal_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.traversalthreadduration' in request._orig_env
-    False
     >>> 'traversal_thread_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.publicationduration' in request._orig_env
-    False
     >>> 'publication_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.publicationthreadduration' in request._orig_env
-    False
     >>> 'publication_thread_duration_ms' in logging_context.flat
     False
     >>> clear_request_started()
@@ -757,26 +727,15 @@ the duration for the traversal and not for the publication.
     >>> publication.beforeTraversal(request)
     >>> publication.handleException(
     ...     None, request, exc_info, retry_allowed=False)
-    >>> 'launchpad.traversalduration' in request._orig_env
-    True
     >>> 'traversal_duration_ms' in logging_context.flat
     True
     >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
-    ...     'launchpad.traversalthreadduration' in request._orig_env
-    ... else:
-    ...     True
-    True
-    >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
     ...     'traversal_thread_duration_ms' in logging_context.flat
     ... else:
     ...     True
     True
-    >>> 'launchpad.publicationduration' in request._orig_env
-    False
     >>> 'publication_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.publicationthreadduration' in request._orig_env
-    False
     >>> 'publication_thread_duration_ms' in logging_context.flat
     False
     >>> clear_request_started()
@@ -792,30 +751,16 @@ the publication, up to the point where it was forcefully stopped.
     >>> set_request_started()
     >>> publication.handleException(
     ...     None, request, exc_info, retry_allowed=False)
-    >>> 'launchpad.traversalduration' in request._orig_env
-    True
     >>> 'traversal_duration_ms' in logging_context.flat
     True
     >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
-    ...     'launchpad.traversalthreadduration' in request._orig_env
-    ... else:
-    ...     True
-    True
-    >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
     ...     'traversal_thread_duration_ms' in logging_context.flat
     ... else:
     ...     True
     True
-    >>> 'launchpad.publicationduration' in request._orig_env
-    True
     >>> 'publication_duration_ms' in logging_context.flat
     True
     >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
-    ...     'launchpad.publicationthreadduration' in request._orig_env
-    ... else:
-    ...     True
-    True
-    >>> if hasattr(time, 'CLOCK_THREAD_CPUTIME_ID'):
     ...     'publication_thread_duration_ms' in logging_context.flat
     ... else:
     ...     True
@@ -833,10 +778,6 @@ the Talisker logging context.
     >>> request, publication = get_request_and_publication()
     >>> publication.initializeLoggingContext(request)
     >>> request.setPrincipal(auth_utility.unauthenticatedPrincipal())
-    >>> request._orig_env['launchpad.traversalduration'] = 0.5
-    >>> request._orig_env['launchpad.traversalthreadduration'] = 0.4
-    >>> request._orig_env['launchpad.publicationduration'] = 0.5
-    >>> request._orig_env['launchpad.publicationthreadduration'] = 0.4
     >>> _ = logging_context.push(
     ...     traversal_duration_ms=500, traversal_thread_duration_ms=400,
     ...     publication_duration_ms=500, publication_thread_duration_ms=400)
@@ -854,20 +795,12 @@ the Talisker logging context.
     ...
     zope.publisher.interfaces.Retry: foo
 
-    >>> 'launchpad.publicationduration' in request._orig_env
-    False
     >>> 'publication_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.publicationthreadduration' in request._orig_env
-    False
     >>> 'publication_thread_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.traversalduration' in request._orig_env
-    False
     >>> 'traversal_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.traversalthreadduration' in request._orig_env
-    False
     >>> 'traversal_thread_duration_ms' in logging_context.flat
     False
 
@@ -875,10 +808,6 @@ the Talisker logging context.
     >>> request, publication = get_request_and_publication()
     >>> publication.initializeLoggingContext(request)
     >>> request.setPrincipal(auth_utility.unauthenticatedPrincipal())
-    >>> request._orig_env['launchpad.traversalduration'] = 0.5
-    >>> request._orig_env['launchpad.traversalthreadduration'] = 0.4
-    >>> request._orig_env['launchpad.publicationduration'] = 0.5
-    >>> request._orig_env['launchpad.publicationthreadduration'] = 0.4
     >>> _ = logging_context.push(
     ...     traversal_duration_ms=500, traversal_thread_duration_ms=400,
     ...     publication_duration_ms=500, publication_thread_duration_ms=400)
@@ -896,20 +825,12 @@ the Talisker logging context.
     ...
     zope.publisher.interfaces.Retry: foo DisconnectionError
 
-    >>> 'launchpad.publicationduration' in request._orig_env
-    False
     >>> 'publication_duration_ms' in logging_context.flat
     False
     >>> 'publication_thread_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.publicationthreadduration' in request._orig_env
-    False
-    >>> 'launchpad.traversalduration' in request._orig_env
-    False
     >>> 'traversal_duration_ms' in logging_context.flat
     False
-    >>> 'launchpad.traversalthreadduration' in request._orig_env
-    False
     >>> 'traversal_thread_duration_ms' in logging_context.flat
     False
 
@@ -921,10 +842,6 @@ WSGI env.
     >>> request, publication = get_request_and_publication()
     >>> publication.initializeLoggingContext(request)
     >>> request.setPrincipal(auth_utility.unauthenticatedPrincipal())
-    >>> request._orig_env['launchpad.traversalduration'] = 0.5
-    >>> request._orig_env['launchpad.traversalthreadduration'] = 0.4
-    >>> request._orig_env['launchpad.publicationduration'] = 0.5
-    >>> request._orig_env['launchpad.publicationthreadduration'] = 0.4
     >>> _ = logging_context.push(
     ...     traversal_duration_ms=500, traversal_thread_duration_ms=400,
     ...     publication_duration_ms=500, publication_thread_duration_ms=400)
@@ -942,20 +859,12 @@ WSGI env.
     ...
     zope.publisher.interfaces.Retry: foo
 
-    >>> request._orig_env['launchpad.publicationduration']
-    0.5
     >>> logging_context.flat['publication_duration_ms']
     500
-    >>> request._orig_env['launchpad.publicationthreadduration']
-    0.4
     >>> logging_context.flat['publication_thread_duration_ms']
     400
-    >>> request._orig_env['launchpad.traversalduration']
-    0.5
     >>> logging_context.flat['traversal_duration_ms']
     500
-    >>> request._orig_env['launchpad.traversalthreadduration']
-    0.4
     >>> logging_context.flat['traversal_thread_duration_ms']
     400
 
diff --git a/lib/lp/services/webapp/publication.py b/lib/lp/services/webapp/publication.py
index da0b2d2..c012a1c 100644
--- a/lib/lp/services/webapp/publication.py
+++ b/lib/lp/services/webapp/publication.py
@@ -429,19 +429,17 @@ class LaunchpadBrowserPublication(
     def callObject(self, request, ob):
         """See `zope.publisher.interfaces.IPublication`.
 
-        Our implementation make sure that no result is returned on
+        Our implementation makes sure that no result is returned on
         redirect.
 
-        It also sets the launchpad.userid and launchpad.pageid WSGI
-        environment variables.
+        It also sets the launchpad.pageid WSGI environment variable, and
+        ensures that the userid and pageid are logged.
         """
         request._publication_start = time.time()
         request._publication_thread_start = _get_thread_time()
         if request.response.getStatus() in [301, 302, 303, 307]:
             return ''
 
-        request.setInWSGIEnvironment(
-            'launchpad.userid', request.principal.id)
         logging_context.push(userid=request.principal.id)
 
         # pageid is calculated at `afterTraversal`, but can be missing
@@ -497,14 +495,9 @@ class LaunchpadBrowserPublication(
                 _get_thread_time() - request._publication_thread_start)
         else:
             publication_thread_duration = None
-        request.setInWSGIEnvironment(
-            'launchpad.publicationduration', publication_duration)
         logging_context.push(
             publication_duration_ms=round(publication_duration * 1000, 3))
         if publication_thread_duration is not None:
-            request.setInWSGIEnvironment(
-                'launchpad.publicationthreadduration',
-                publication_thread_duration)
             logging_context.push(
                 publication_thread_duration_ms=round(
                     publication_thread_duration * 1000, 3))
@@ -610,15 +603,11 @@ class LaunchpadBrowserPublication(
             'request._traversal_start, which should have been set by '
             'beforeTraversal(), was not found.')
         traversal_duration = time.time() - request._traversal_start
-        request.setInWSGIEnvironment(
-            'launchpad.traversalduration', traversal_duration)
         logging_context.push(
             traversal_duration_ms=round(traversal_duration * 1000, 3))
         if request._traversal_thread_start is not None:
             traversal_thread_duration = (
                 _get_thread_time() - request._traversal_thread_start)
-            request.setInWSGIEnvironment(
-                'launchpad.traversalthreadduration', traversal_thread_duration)
             logging_context.push(
                 traversal_thread_duration_ms=round(
                     traversal_thread_duration * 1000, 3))
@@ -648,22 +637,17 @@ class LaunchpadBrowserPublication(
         now = time.time()
         thread_now = _get_thread_time()
         if (hasattr(request, '_publication_start') and
-            ('launchpad.publicationduration' not in orig_env)):
+                'publication_duration_ms' not in logging_context.flat):
             # The traversal process has been started but hasn't completed.
-            assert 'launchpad.traversalduration' in orig_env, (
+            assert 'traversal_duration_ms' in logging_context.flat, (
                 'We reached the publication process so we must have finished '
                 'the traversal.')
             publication_duration = now - request._publication_start
-            request.setInWSGIEnvironment(
-                'launchpad.publicationduration', publication_duration)
             logging_context.push(
                 publication_duration_ms=round(publication_duration * 1000, 3))
             if thread_now is not None:
                 publication_thread_duration = (
                     thread_now - request._publication_thread_start)
-                request.setInWSGIEnvironment(
-                    'launchpad.publicationthreadduration',
-                    publication_thread_duration)
                 logging_context.push(
                     publication_thread_duration_ms=round(
                         publication_thread_duration * 1000, 3))
@@ -676,19 +660,14 @@ class LaunchpadBrowserPublication(
                         request._orig_env.get('launchpad.pageid')),
                     })
         elif (hasattr(request, '_traversal_start') and
-              ('launchpad.traversalduration' not in orig_env)):
+              'traversal_duration_ms' not in logging_context.flat):
             # The traversal process has been started but hasn't completed.
             traversal_duration = now - request._traversal_start
-            request.setInWSGIEnvironment(
-                'launchpad.traversalduration', traversal_duration)
             logging_context.push(
                 traversal_duration_ms=round(traversal_duration * 1000, 3))
             if thread_now is not None:
                 traversal_thread_duration = (
                     thread_now - request._traversal_thread_start)
-                request.setInWSGIEnvironment(
-                    'launchpad.traversalthreadduration',
-                    traversal_thread_duration)
                 logging_context.push(
                     traversal_thread_duration_ms=round(
                         traversal_thread_duration * 1000, 3))
@@ -758,12 +737,6 @@ class LaunchpadBrowserPublication(
         # is a normal part of operation.
         if should_retry(exc_info):
             if request.supportsRetry():
-                # Remove variables used for counting publication/traversal
-                # durations as this request is going to be retried.
-                orig_env.pop('launchpad.traversalduration', None)
-                orig_env.pop('launchpad.traversalthreadduration', None)
-                orig_env.pop('launchpad.publicationduration', None)
-                orig_env.pop('launchpad.publicationthreadduration', None)
                 # If we made it as far as beforeTraversal, then unwind the
                 # Talisker logging context to its state on entering that
                 # method.
diff --git a/lib/lp/services/webapp/servers.py b/lib/lp/services/webapp/servers.py
index 6a7def3..5693f92 100644
--- a/lib/lp/services/webapp/servers.py
+++ b/lib/lp/services/webapp/servers.py
@@ -56,7 +56,6 @@ from zope.security.proxy import (
     isinstance as zope_isinstance,
     removeSecurityProxy,
     )
-from zope.server.http.commonaccesslogger import CommonAccessLogger
 from zope.session.interfaces import ISession
 
 from lp.app import versioninfo
@@ -1071,69 +1070,6 @@ class DebugLayerRequestFactory(HTTPPublicationRequestFactory):
         return request
 
 
-class LaunchpadAccessLogger(CommonAccessLogger):
-
-    def log(self, task):
-        """Receives a completed task and logs it in launchpad log format.
-
-        task IP address
-        X_FORWARDED_FOR
-        HOST
-        datetime task started
-        request string  (1st line of request)
-        response status
-        response bytes written
-        number of nonpython statements (sql, email, memcache, rabbit etc)
-        request duration
-        traversal duration
-        publication duration
-        launchpad user id
-        launchpad page id
-        REFERER
-        USER_AGENT
-
-        """
-        request_headers = task.request_data.headers
-        cgi_env = task.getCGIEnvironment()
-
-        x_forwarded_for = request_headers.get('X_FORWARDED_FOR', '')
-        host = request_headers.get('HOST', '')
-        start_time = self.log_date_string(task.start_time)
-        first_line = task.request_data.first_line
-        status = task.status
-        bytes_written = task.bytes_written
-        userid = cgi_env.get('launchpad.userid', '')
-        pageid = cgi_env.get('launchpad.pageid', '')
-        nonpython_actions = cgi_env.get('launchpad.nonpythonactions', 0)
-        request_duration = cgi_env.get('launchpad.requestduration', 0)
-        traversal_duration = cgi_env.get('launchpad.traversalduration', 0)
-        publication_duration = cgi_env.get('launchpad.publicationduration', 0)
-        referer = request_headers.get('REFERER', '')
-        user_agent = request_headers.get('USER_AGENT', '')
-
-        log_template = (' - "%s" "%s" [%s] "%s" %s %d %d %s %s '
-                        '%s "%s" "%s" "%s" "%s"\n')
-        self.output.logRequest(
-            task.channel.addr[0],
-            log_template % (
-                x_forwarded_for,
-                host,
-                start_time,
-                first_line,
-                status,
-                bytes_written,
-                nonpython_actions,
-                request_duration,
-                traversal_duration,
-                publication_duration,
-                userid,
-                pageid,
-                referer,
-                user_agent,
-                )
-           )
-
-
 # ---- mainsite
 
 class MainLaunchpadPublication(LaunchpadBrowserPublication):
diff --git a/lib/lp/services/webapp/tests/test_servers.py b/lib/lp/services/webapp/tests/test_servers.py
index 11bdf60..ab0f26a 100644
--- a/lib/lp/services/webapp/tests/test_servers.py
+++ b/lib/lp/services/webapp/tests/test_servers.py
@@ -450,8 +450,8 @@ class LaunchpadBrowserResponseHeaderInjection(TestCase):
     """Test that LaunchpadBrowserResponse rejects header injection attempts.
 
     Applications should reject data that they cannot safely serialise, but
-    zope.server and most WSGI containers don't complain when header names or
-    values contain CR or LF. So we reject them before they're added.
+    most WSGI containers don't complain when header names or values contain
+    CR or LF, so we reject them before they're added.
     """
 
     def test_setHeader_good(self):
diff --git a/lib/lp/testing/layers.py b/lib/lp/testing/layers.py
index d20d15c..aae25dc 100644
--- a/lib/lp/testing/layers.py
+++ b/lib/lp/testing/layers.py
@@ -53,7 +53,6 @@ import datetime
 import errno
 from functools import partial
 import gc
-import logging
 import os
 import select
 import signal
@@ -75,22 +74,17 @@ from fixtures import (
     MonkeyPatch,
     )
 import psycopg2
-import six
 from six.moves.urllib.error import (
     HTTPError,
     URLError,
     )
-from six.moves.urllib.parse import (
-    quote,
-    urlparse,
-    )
+from six.moves.urllib.parse import urlparse
 from six.moves.urllib.request import urlopen
 from talisker.context import Context
 import transaction
 from webob.request import environ_from_url as orig_environ_from_url
 import wsgi_intercept
 from wsgi_intercept import httplib2_intercept
-from zope.app.publication.httpfactory import HTTPPublicationRequestFactory
 from zope.app.wsgi import WSGIPublisherApplication
 from zope.component import (
     getUtility,
@@ -105,7 +99,6 @@ from zope.security.management import (
     endInteraction,
     getSecurityPolicy,
     )
-from zope.server.logger.pythonlogger import PythonLogger
 from zope.testbrowser.browser import HostNotAllowed
 import zope.testbrowser.wsgi
 from zope.testbrowser.wsgi import AuthorizationMiddleware
@@ -150,7 +143,6 @@ from lp.services.timeout import (
 from lp.services.webapp.authorization import LaunchpadPermissiveSecurityPolicy
 from lp.services.webapp.interfaces import IOpenLaunchBag
 from lp.services.webapp.servers import (
-    LaunchpadAccessLogger,
     register_launchpad_request_publication_factories,
     )
 import lp.services.webapp.session
@@ -1566,42 +1558,6 @@ class LaunchpadZopelessLayer(LaunchpadScriptLayer):
         transaction.abort()
 
 
-class MockHTTPTask:
-
-    class MockHTTPRequestParser:
-        headers = None
-        first_line = None
-
-    class MockHTTPServerChannel:
-        # This is not important to us, so we can hardcode it here.
-        addr = ['127.0.0.88', 80]
-
-    request_data = MockHTTPRequestParser()
-    channel = MockHTTPServerChannel()
-
-    def __init__(self, first_line, request, response_status, response_headers):
-        self.request = request
-        # We have no way of knowing when the task started, so we use
-        # the current time here. That shouldn't be a problem since we don't
-        # care about that for our tests anyway.
-        self.start_time = time.time()
-        self.status = response_status
-        # When streaming files (see lib/zope/publisher/httpresults.txt)
-        # the 'Content-Length' header is missing. When it happens we set
-        # 'bytes_written' to an obviously invalid value. This variable is
-        # used for logging purposes, see webapp/servers.py.
-        content_length = response_headers.get('Content-Length')
-        if content_length is not None:
-            self.bytes_written = int(content_length)
-        else:
-            self.bytes_written = -1
-        self.request_data.headers = self.request.headers
-        self.request_data.first_line = first_line
-
-    def getCGIEnvironment(self):
-        return self.request._orig_env
-
-
 class ProfilingMiddleware:
     """Middleware to profile WSGI responses."""
 
@@ -1615,54 +1571,10 @@ class ProfilingMiddleware:
         return self.app(environ, start_response)
 
 
-class AccessLoggingMiddleware:
-    """Middleware to log page hits."""
-
-    def __init__(self, app, access_logger):
-        self.app = app
-        self.access_logger = access_logger
-
-    def __call__(self, environ, start_response):
-        response_status_string = []
-        response_headers_list = []
-
-        def wrap_start_response(status, headers, exc_info=None):
-            response_status_string.append(status)
-            response_headers_list.extend(headers)
-            return start_response(status, headers, exc_info)
-
-        request = HTTPPublicationRequestFactory(None)(
-            environ['wsgi.input'], environ)
-        # Reconstruct the first line of the request.  This isn't completely
-        # accurate, but saving it in such a way that we can get at it from
-        # here is gratuitously annoying.  This is similar to parts of
-        # wsgiref.util.request_uri, but with slightly more lenient quoting.
-        url = quote(
-            six.ensure_str(
-                environ.get('SCRIPT_NAME', '') + environ.get('PATH_INFO', '')),
-            safe='/+')
-        if environ.get('QUERY_STRING'):
-            url += '?' + environ['QUERY_STRING']
-        first_line = '%s %s %s' % (
-            request.method, url, environ['SERVER_PROTOCOL'].rstrip('\n'))
-        entries = []
-        for entry in self.app(environ, wrap_start_response):
-            yield entry
-            entries.append(entry)
-        response_status = int(response_status_string[0].split(' ', 1)[0])
-        # Reversed so that the first of any given header wins.  This isn't
-        # very accurate, but is good enough for test middleware.
-        response_headers = dict(reversed(response_headers_list))
-        self.access_logger.log(MockHTTPTask(
-            first_line, request, response_status, response_headers))
-
-
 class PageTestLayer(LaunchpadFunctionalLayer, BingServiceLayer):
     """Environment for page tests.
     """
 
-    log_location = None
-
     @classmethod
     @profiled
     def setUp(cls):
@@ -1670,31 +1582,17 @@ class PageTestLayer(LaunchpadFunctionalLayer, BingServiceLayer):
             PageTestLayer.profiler = Profile()
         else:
             PageTestLayer.profiler = None
-        cls.log_location = tempfile.NamedTemporaryFile().name
-        file_handler = logging.FileHandler(cls.log_location, 'w')
-        file_handler.setFormatter(logging.Formatter())
-        logger = PythonLogger('pagetests-access')
-        logger.logger.addHandler(file_handler)
-        logger.logger.setLevel(logging.INFO)
-        access_logger = LaunchpadAccessLogger(logger)
 
         PageTestLayer._profiling_middleware = partial(
             ProfilingMiddleware, profiler=PageTestLayer.profiler)
-        PageTestLayer._access_logging_middleware = partial(
-            AccessLoggingMiddleware, access_logger=access_logger)
         FunctionalLayer.browser_layer.addMiddlewares(
-            PageTestLayer._profiling_middleware,
-            PageTestLayer._access_logging_middleware)
+            PageTestLayer._profiling_middleware)
 
     @classmethod
     @profiled
     def tearDown(cls):
         FunctionalLayer.browser_layer.removeMiddlewares(
-            PageTestLayer._access_logging_middleware,
             PageTestLayer._profiling_middleware)
-        logger = PythonLogger('pagetests-access')
-        for handler in list(logger.logger.handlers):
-            logger.logger.removeHandler(handler)
         if PageTestLayer.profiler:
             PageTestLayer.profiler.dump_stats(
                 os.environ.get('PROFILE_PAGETESTS_REQUESTS'))
diff --git a/requirements/launchpad.txt b/requirements/launchpad.txt
index 2904d84..7eee4bf 100644
--- a/requirements/launchpad.txt
+++ b/requirements/launchpad.txt
@@ -175,7 +175,6 @@ zope.app.http==4.0.1
 zope.app.publication==4.3.1
 zope.app.publisher==4.2.0
 zope.app.wsgi==4.3.0
-zope.server==4.0.2
 # lp:~launchpad-committers/zope.session:launchpad
 zope.session==4.3.0+lp1
 zope.testbrowser==5.5.1
diff --git a/setup.py b/setup.py
index 09fb9f4..874a893 100644
--- a/setup.py
+++ b/setup.py
@@ -284,7 +284,6 @@ setup(
         'zope.security',
         'zope.securitypolicy',
         'zope.sendmail',
-        'zope.server',
         'zope.session',
         'zope.tal',
         'zope.tales',
diff --git a/zcml/summarizerequests.zcml b/zcml/summarizerequests.zcml
index ccb0b33..39ed356 100644
--- a/zcml/summarizerequests.zcml
+++ b/zcml/summarizerequests.zcml
@@ -8,6 +8,6 @@
   <!-- output summary of requests for each hit -->
   <subscriber
      for="zope.publisher.interfaces.EndRequestEvent"
-        handler="lp.services.webapp.adapter.store_sql_statements_and_request_duration"
+        handler="lp.services.webapp.adapter.store_sql_statements"
         />
 </configure>