2013-02-11 23:33:47 +01:00
|
|
|
from django.conf import settings
|
2012-12-19 20:19:46 +01:00
|
|
|
from decorator import RequestVariableMissingError, RequestVariableConversionError
|
|
|
|
from zephyr.lib.response import json_error
|
2013-02-11 23:33:47 +01:00
|
|
|
from django.db import connection
|
2012-12-19 20:19:46 +01:00
|
|
|
|
2012-10-16 23:52:10 +02:00
|
|
|
import logging
|
2012-11-14 21:00:26 +01:00
|
|
|
import time
|
2012-10-16 23:52:10 +02:00
|
|
|
|
|
|
|
logger = logging.getLogger('humbug.requests')
|
|
|
|
|
|
|
|
class LogRequests(object):
|
2012-11-14 21:00:26 +01:00
|
|
|
def process_request(self, request):
|
|
|
|
request._time_started = time.time()
|
|
|
|
|
2012-10-16 23:52:10 +02:00
|
|
|
def process_response(self, request, response):
|
|
|
|
|
|
|
|
# The reverse proxy might have sent us the real external IP
|
|
|
|
remote_ip = request.META.get('HTTP_X_REAL_IP')
|
|
|
|
if remote_ip is None:
|
|
|
|
remote_ip = request.META['REMOTE_ADDR']
|
|
|
|
|
2012-11-14 21:00:26 +01:00
|
|
|
time_delta = -1
|
|
|
|
# A time duration of -1 means the StartLogRequests middleware
|
|
|
|
# didn't run for some reason
|
|
|
|
if hasattr(request, '_time_started'):
|
|
|
|
time_delta = time.time() - request._time_started
|
2013-02-11 23:15:34 +01:00
|
|
|
|
2013-02-11 23:33:47 +01:00
|
|
|
# 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.
|
2013-02-11 23:15:34 +01:00
|
|
|
try:
|
|
|
|
email = request._email
|
|
|
|
except Exception:
|
|
|
|
email = "unauth"
|
|
|
|
|
2013-02-11 23:33:47 +01:00
|
|
|
logger.info('%-15s %-7s %3d %.3fs %s%s (%s)'
|
2012-11-14 21:00:26 +01:00
|
|
|
% (remote_ip, request.method, response.status_code,
|
2013-02-11 23:33:47 +01:00
|
|
|
time_delta, db_stats, request.get_full_path(), email))
|
2013-02-01 20:17:15 +01:00
|
|
|
# Log some additional data whenever we return a 40x error
|
|
|
|
if 400 <= response.status_code < 500:
|
2013-02-05 20:34:16 +01:00
|
|
|
logger.info('status=%3d, data=%s, uid=%s' % (response.status_code, response.content, email))
|
2012-10-16 23:52:10 +02:00
|
|
|
return response
|
2012-12-19 20:19:46 +01:00
|
|
|
|
|
|
|
class JsonErrorHandler(object):
|
|
|
|
def process_exception(self, request, exception):
|
|
|
|
if hasattr(exception, 'to_json_error_msg') and callable(exception.to_json_error_msg):
|
|
|
|
return json_error(exception.to_json_error_msg())
|
|
|
|
return None
|