launchpad-reviewers team mailing list archive
-
launchpad-reviewers team
-
Mailing list archive
-
Message #00097
[Merge] lp:~spiv/launchpad/loggerhead-logging into lp:launchpad
Andrew Bennetts has proposed merging lp:~spiv/launchpad/loggerhead-logging into lp:launchpad.
Requested reviews:
Launchpad code reviewers (launchpad-reviewers)
This is a small change to start-loggerhead.py to add explicit logging for the completion of a request (in addition to the logging of the start of processing a request). It logs the time taken between the request start and finish (even when requests trigger errors), and summarises the error if there is an error.
The main goal of this patch is to make it easier to gather stats about how long requests take.
--
https://code.launchpad.net/~spiv/launchpad/loggerhead-logging/+merge/29962
Your team Launchpad code reviewers is requested to review the proposed merge of lp:~spiv/launchpad/loggerhead-logging into lp:launchpad.
=== modified file 'scripts/start-loggerhead.py'
--- scripts/start-loggerhead.py 2010-06-08 15:43:13 +0000
+++ scripts/start-loggerhead.py 2010-07-15 09:31:00 +0000
@@ -8,12 +8,15 @@
import logging
import os
import sys
+import time
+import traceback
from paste import httpserver
from paste.deploy.config import PrefixMiddleware
from paste.httpexceptions import HTTPExceptionHandler
from paste.request import construct_url
from paste.translogger import TransLogger
+from paste.wsgilib import catch_errors
from canonical.config import config
import lp.codehosting
@@ -129,13 +132,22 @@
app = RootApp(SESSION_VAR)
app = HTTPExceptionHandler(app)
app = SessionHandler(app, SESSION_VAR, secret)
-def log_on_request_start(app):
+def log_request_start_and_stop(app):
def wrapped(environ, start_response):
log = logging.getLogger('loggerhead')
- log.info("Starting to process %s", construct_url(environ))
- return app(environ, start_response)
+ url = construct_url(environ)
+ log.info("Starting to process %s", url)
+ start_time = time.time()
+ def request_done_ok():
+ log.info("Processed ok %s [%0.3f seconds]", url, time.time() -
+ start_time)
+ def request_done_err(exc_info):
+ log.info("Processed err %s [%0.3f seconds]: %s", url, time.time() -
+ start_time, traceback.format_exception_only(*exc_info[:2]))
+ return catch_errors(app, environ, start_response, request_done_err,
+ request_done_ok)
return wrapped
-app = log_on_request_start(app)
+app = log_request_start_and_stop(app)
app = PrefixMiddleware(app)
app = TransLogger(app)
app = threadpool_debug(app)