diff --git a/zephyr/middleware.py b/zephyr/middleware.py index 319aa1fd2e..92dbb4beb6 100644 --- a/zephyr/middleware.py +++ b/zephyr/middleware.py @@ -1,5 +1,7 @@ +from django.conf import settings from decorator import RequestVariableMissingError, RequestVariableConversionError from zephyr.lib.response import json_error +from django.db import connection import logging import time @@ -23,14 +25,22 @@ class LogRequests(object): if hasattr(request, '_time_started'): time_delta = time.time() - request._time_started + # Get the amount of time spent doing database queries + query_time = sum(float(query.get('time', 0)) for query in connection.queries) + if settings.DEBUG: + db_stats = "(db: %.3fs/%sq) " % (query_time, len(connection.queries),) + else: + db_stats = "" + + # Get the requestor's email address, if available. try: email = request._email except Exception: email = "unauth" - logger.info('%-15s %-7s %3d %.3fs %s (%s)' + logger.info('%-15s %-7s %3d %.3fs %s%s (%s)' % (remote_ip, request.method, response.status_code, - time_delta, request.get_full_path(), email)) + time_delta, db_stats, request.get_full_path(), email)) # Log some additional data whenever we return a 40x error if 400 <= response.status_code < 500: logger.info('status=%3d, data=%s, uid=%s' % (response.status_code, response.content, email))