[Sync] Log age of auth tokens on authentication failure

sync/engine/net/server_connection_manager.cc

Index: sync/engine/net/server_connection_manager.cc
diff --git a/sync/engine/net/server_connection_manager.cc b/sync/engine/net/server_connection_manager.cc
index 75c5e5394ab05962ec56a7e047f9ad1ebbf475d7..9f3d0268467c66d2719a0931ebc2963e7095ba74 100644
--- a/sync/engine/net/server_connection_manager.cc
+++ b/sync/engine/net/server_connection_manager.cc
@@ -11,6 +11,7 @@
 #include <vector>
 
 #include "base/command_line.h"
+#include "base/metrics/histogram.h"
 #include "build/build_config.h"
 #include "googleurl/src/gurl.h"
 #include "net/base/net_errors.h"
@@ -213,6 +214,17 @@ void ServerConnectionManager::OnConnectionDestroyed(Connection* connection) {
 }
 
 void ServerConnectionManager::OnInvalidationCredentialsRejected() {
+  if (!auth_token_time_.is_null()) {
+    base::TimeDelta age = base::Time::Now() - auth_token_time_;
+    if (age < base::TimeDelta::FromHours(1)) {
+      UMA_HISTOGRAM_CUSTOM_TIMES("Sync.InvalidationRejectionAuthAgeShort",

[tim (not reviewing), 2013/05/03 00:46:43]

nit - might be nice to group auth related things in a Sync.Auth.* prefix.

[Nicolas Zea, 2013/05/03 01:31:41]

Done.

+                                 age,
+                                 base::TimeDelta::FromSeconds(1),
+                                 base::TimeDelta::FromHours(1),
+                                 50);
+    }
+    UMA_HISTOGRAM_COUNTS("Sync.InvalidationRejectionAuthAgeLong", age.InDays());
+  }
   InvalidateAndClearAuthToken();
   SetServerStatus(HttpResponse::SYNC_AUTH_ERROR);
 }
@@ -223,6 +235,7 @@ void ServerConnectionManager::InvalidateAndClearAuthToken() {
   if (!auth_token_.empty()) {
     previously_invalidated_token.assign(auth_token_);
     auth_token_ = std::string();
+    auth_token_time_ = base::Time();
   }
 }
 
@@ -273,8 +286,21 @@ bool ServerConnectionManager::PostBufferToPath(PostBufferParams* params,
   bool ok = post.get()->Init(
       path.c_str(), auth_token, params->buffer_in, &params->response);
 
-  if (params->response.server_status == HttpResponse::SYNC_AUTH_ERROR)
+  if (params->response.server_status == HttpResponse::SYNC_AUTH_ERROR) {
+    if (!auth_token_time_.is_null()) {
+      base::TimeDelta age = base::Time::Now() - auth_token_time_;
+      if (age < base::TimeDelta::FromHours(1)) {
+        UMA_HISTOGRAM_CUSTOM_TIMES("Sync.ServerRejectionAuthAgeShort",
+                                   age,
+                                   base::TimeDelta::FromSeconds(1),
+                                   base::TimeDelta::FromHours(1),
+                                   50);
+      }
+      UMA_HISTOGRAM_COUNTS("Sync.ServerRejectionAuthAgeLong",

[tim (not reviewing), 2013/05/03 00:46:43]

So no breakdown between 1 hour and 24 hours? I guess I was expecting an 'else'
and then a second histogram covering things > 1 hour.

[Nicolas Zea, 2013/05/03 01:31:41]

Well, this is going to cover those, they'll simply be in the first bucket. I
think it's useful to have a histogram that lets you see the total breakdown in
days.

+                           age.InDays());
+    }
     InvalidateAndClearAuthToken();
+  }
 
   if (!ok || net::HTTP_OK != params->response.response_code)
     return false;