diff --git a/apps/profile/middleware.py b/apps/profile/middleware.py index 7381757fc..4e1df2bc3 100644 --- a/apps/profile/middleware.py +++ b/apps/profile/middleware.py @@ -1,6 +1,7 @@ import datetime import re import random +import time from utils import log as logging from django.conf import settings from django.db import connection @@ -29,7 +30,7 @@ class LastSeenMiddleware(object): class SQLLogToConsoleMiddleware: def process_response(self, request, response): if settings.DEBUG and connection.queries: - time = sum([float(q['time']) for q in connection.queries]) + time_elapsed = sum([float(q['time']) for q in connection.queries]) queries = connection.queries for query in queries: if query.get('mongo'): @@ -41,7 +42,7 @@ class SQLLogToConsoleMiddleware: query['sql'] = re.sub(r'UPDATE', '~FY~SBUPDATE', query['sql']) query['sql'] = re.sub(r'DELETE', '~FR~SBDELETE', query['sql']) t = Template("{% for sql in sqllog %}{% if not forloop.first %} {% endif %}[{{forloop.counter}}] ~FC{{sql.time}}s~FW: {{sql.sql|safe}}{% if not forloop.last %}\n{% endif %}{% endfor %}") - logging.debug(t.render(Context({'sqllog':queries,'count':len(queries),'time':time}))) + logging.debug(t.render(Context({'sqllog':queries,'count':len(queries),'time':time_elapsed}))) return response SIMPSONS_QUOTES = [ @@ -155,4 +156,7 @@ class SimpsonsMiddleware: response["X-%s" % source] = quote[1] return response - \ No newline at end of file + +class TimingMiddleware: + def process_request(self, request): + setattr(request, 'start_time', time.time()) diff --git a/apps/social/views.py b/apps/social/views.py index 3e4f04075..edf6f9c79 100644 --- a/apps/social/views.py +++ b/apps/social/views.py @@ -519,6 +519,7 @@ def shared_stories_public(request, username): @json.json_view def profile(request): + time.sleep(1) user = get_user(request.user) user_id = request.GET.get('user_id', user.pk) include_activities_html = request.REQUEST.get('include_activities_html', None) diff --git a/settings.py b/settings.py index 2a7eff93f..1e240a63f 100644 --- a/settings.py +++ b/settings.py @@ -92,6 +92,7 @@ MIDDLEWARE_CLASSES = ( 'django.middleware.common.CommonMiddleware', 'django.contrib.sessions.middleware.SessionMiddleware', 'django.contrib.auth.middleware.AuthenticationMiddleware', + 'apps.profile.middleware.TimingMiddleware', 'apps.profile.middleware.LastSeenMiddleware', 'apps.profile.middleware.SQLLogToConsoleMiddleware', 'subdomains.middleware.SubdomainMiddleware', diff --git a/utils/log.py b/utils/log.py index 1ddc5b683..1bd199499 100644 --- a/utils/log.py +++ b/utils/log.py @@ -1,6 +1,7 @@ import logging import re import string +import time from django.core.handlers.wsgi import WSGIRequest from django.conf import settings @@ -14,6 +15,7 @@ def getlogger(): def user(u, msg): platform = '------' + time_elapsed = "" if isinstance(u, WSGIRequest): request = u u = request.user @@ -46,9 +48,13 @@ def user(u, msg): platform = 'Opera' elif 'WP7' in user_agent: platform = 'WP7' + + if hasattr(request, 'start_time'): + now = time.time() + time_elapsed = "[%.4ss] " % (now - request.start_time) premium = '*' if u.is_authenticated() and u.profile.is_premium else '' username = cipher(unicode(u)) if settings.CIPHER_USERNAMES else u - info(' ---> [~FB~SN%-6s~SB] [%s%s] %s' % (platform, username, premium, msg)) + info(' ---> [~FB~SN%-6s~SB] [%s%s] %s%s' % (platform, time_elapsed, username, premium, msg)) def cipher(msg): shift = len(msg)