From 8085ff81a81315a8cba5ace318a64771d2e7aa13 Mon Sep 17 00:00:00 2001
From: Joseph Schorr <joseph.schorr@coreos.com>
Date: Sun, 4 Jan 2015 14:50:08 -0500
Subject: [PATCH] Only call get_authenticated_* once in the track_and_log, and
 add better logging to it

---
 endpoints/trackhelper.py | 41 ++++++++++++++++++++++++----------------
 1 file changed, 25 insertions(+), 16 deletions(-)

diff --git a/endpoints/trackhelper.py b/endpoints/trackhelper.py
index d26db7e7e..83b9d4270 100644
--- a/endpoints/trackhelper.py
+++ b/endpoints/trackhelper.py
@@ -19,20 +19,23 @@ def track_and_log(event_name, repo, **kwargs):
 
   analytics_id = 'anonymous'
 
+  authenticated_oauth_token = get_validated_oauth_token()
+  authenticated_user = get_authenticated_user()
+  authenticated_token = get_validated_token() if not authenticated_user else None
+
   profile.debug('Logging the %s to Mixpanel and the log system', event_name)
-  if get_validated_oauth_token():
-    oauth_token = get_validated_oauth_token()
-    metadata['oauth_token_id'] = oauth_token.id
-    metadata['oauth_token_application_id'] = oauth_token.application.client_id
-    metadata['oauth_token_application'] = oauth_token.application.name
-    analytics_id = 'oauth:' + oauth_token.id
-  elif get_authenticated_user():
-    metadata['username'] = get_authenticated_user().username
-    analytics_id = get_authenticated_user().username
-  elif get_validated_token():
-    metadata['token'] = get_validated_token().friendly_name
-    metadata['token_code'] = get_validated_token().code
-    analytics_id = 'token:' + get_validated_token().code
+  if authenticated_oauth_token:
+    metadata['oauth_token_id'] = authenticated_oauth_token.id
+    metadata['oauth_token_application_id'] = authenticated_oauth_token.application.client_id
+    metadata['oauth_token_application'] = authenticated_oauth_token.application.name
+    analytics_id = 'oauth:' + authenticated_oauth_token.id
+  elif authenticated_user:
+    metadata['username'] = authenticated_user.username
+    analytics_id = authenticated_user.username
+  elif authenticated_token:
+    metadata['token'] = authenticated_token.friendly_name
+    metadata['token_code'] = authenticated_token.code
+    analytics_id = 'token:' + authenticated_token.code
   else:
     metadata['public'] = True
     analytics_id = 'anonymous'
@@ -42,21 +45,27 @@ def track_and_log(event_name, repo, **kwargs):
   }
 
   # Publish the user event (if applicable)
-  if get_authenticated_user():
+  profile.debug('Checking publishing %s to the user events system', event_name)
+  if authenticated_user:
+    profile.debug('Publishing %s to the user events system', event_name)
     user_event_data = {
       'action': event_name,
       'repository': repository,
       'namespace': namespace
     }
 
-    event = userevents.get_event(get_authenticated_user().username)
+    event = userevents.get_event(authenticated_user.username)
     event.publish_event_data('docker-cli', user_event_data)
 
   # Save the action to mixpanel.
+  profile.debug('Logging the %s to Mixpanel', event_name)
   analytics.track(analytics_id, event_name, extra_params)
 
   # Log the action to the database.
+  profile.debug('Logging the %s to logs system', event_name)
   model.log_action(event_name, namespace,
-                   performer=get_authenticated_user(),
+                   performer=authenticated_user,
                    ip=request.remote_addr, metadata=metadata,
                    repository=repo)
+
+  profile.debug('Track and log of %s complete', event_name)