[Sync] Log age of auth tokens on authentication failure

[Sync] Log age of auth tokens on authentication failure

The fetch/refresh time of the sync credentials are plumbed through to the
server connection manager, which can then histogram their age in the event
that there is an auth failure.

BUG=none
R=tim@chromium.org

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=198531

[Nicolas Zea, 2013-05-03 00:22:01]

PTAL

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

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
File chrome/browser/signin/about_signin_internals.cc (right):

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:25: std::string
TimeToFriendlyStr(base::Time time) {
const& ?

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:27: return "";
prefer std::string()

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:38: TokenInfo("", "Not Loaded",
"", 0, kTokenPrefsArray[i])));
std::string() was a better choice than "".

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:78: base::Time now =
base::Time::NowFromSystemTime();
nit - there's a whole pile of base::Times in here. Perhaps 'using base::Time'
would let you inline all of these to the TimeToFriendlyStr call?

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:123: const std::string
time_internal = pref + ".time_internal";
What's with the local consts :P

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
File sync/engine/net/server_connection_manager.cc (right):

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
sync/engine/net/server_connection_manager.cc:220:
UMA_HISTOGRAM_CUSTOM_TIMES("Sync.InvalidationRejectionAuthAgeShort",
nit - might be nice to group auth related things in a Sync.Auth.* prefix.

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
sync/engine/net/server_connection_manager.cc:299:
UMA_HISTOGRAM_COUNTS("Sync.ServerRejectionAuthAgeLong",
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.

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
File sync/engine/net/server_connection_manager.h (right):

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
sync/engine/net/server_connection_manager.h:228: bool set_auth_token(const
std::string& auth_token,
This method should be renamed as per style guide (SetAuthTokenAndTime?), also
comment the new parameter and how it should relate to auth_token.

https://codereview.chromium.org/14888003/diff/1/sync/internal_api/public/sync...
File sync/internal_api/public/sync_manager.h (right):

https://codereview.chromium.org/14888003/diff/1/sync/internal_api/public/sync...
sync/internal_api/public/sync_manager.h:66: base::Time sync_token_time;
Comments, at least this new field as it's non-obvious what 'time' refers to.

[Nicolas Zea, 2013-05-03 01:31:40]

PTAL

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
File chrome/browser/signin/about_signin_internals.cc (right):

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:25: std::string
TimeToFriendlyStr(base::Time time) {
On 2013/05/03 00:46:43, timsteele wrote:
> const& ?

Done.

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:27: return "";
On 2013/05/03 00:46:43, timsteele wrote:
> prefer std::string()

Done.

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:38: TokenInfo("", "Not Loaded",
"", 0, kTokenPrefsArray[i])));
On 2013/05/03 00:46:43, timsteele wrote:
> std::string() was a better choice than "".

Done.

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:78: base::Time now =
base::Time::NowFromSystemTime();
On 2013/05/03 00:46:43, timsteele wrote:
> nit - there's a whole pile of base::Times in here. Perhaps 'using base::Time'
> would let you inline all of these to the TimeToFriendlyStr call?

Done.

https://codereview.chromium.org/14888003/diff/1/chrome/browser/signin/about_s...
chrome/browser/signin/about_signin_internals.cc:123: const std::string
time_internal = pref + ".time_internal";
On 2013/05/03 00:46:43, timsteele wrote:
> What's with the local consts :P

I was tempted to get rid of them!

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
File sync/engine/net/server_connection_manager.cc (right):

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
sync/engine/net/server_connection_manager.cc:220:
UMA_HISTOGRAM_CUSTOM_TIMES("Sync.InvalidationRejectionAuthAgeShort",
On 2013/05/03 00:46:43, timsteele wrote:
> nit - might be nice to group auth related things in a Sync.Auth.* prefix.

Done.

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
sync/engine/net/server_connection_manager.cc:299:
UMA_HISTOGRAM_COUNTS("Sync.ServerRejectionAuthAgeLong",
On 2013/05/03 00:46:43, timsteele wrote:
> 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.

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.

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
File sync/engine/net/server_connection_manager.h (right):

https://codereview.chromium.org/14888003/diff/1/sync/engine/net/server_connec...
sync/engine/net/server_connection_manager.h:228: bool set_auth_token(const
std::string& auth_token,
On 2013/05/03 00:46:43, timsteele wrote:
> This method should be renamed as per style guide (SetAuthTokenAndTime?), also
> comment the new parameter and how it should relate to auth_token.

Done.

https://codereview.chromium.org/14888003/diff/1/sync/internal_api/public/sync...
File sync/internal_api/public/sync_manager.h (right):

https://codereview.chromium.org/14888003/diff/1/sync/internal_api/public/sync...
sync/internal_api/public/sync_manager.h:66: base::Time sync_token_time;
On 2013/05/03 00:46:43, timsteele wrote:
> Comments, at least this new field as it's non-obvious what 'time' refers to.

Done.

[tim (not reviewing), 2013-05-03 03:16:24]

LGTM

[commit-bot: I haz the power, 2013-05-03 06:07:31]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/zea@chromium.org/14888003/12003

[commit-bot: I haz the power, 2013-05-03 06:23:37]

Sorry for I got bad news for ya.
Compile failed with a clobber build on ios_dbg_simulator.
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=ios_dbg_si...
Your code is likely broken or HEAD is junk. Please ensure your
code is not broken then alert the build sheriffs.
Look at the try server FAQ for more details.

[commit-bot: I haz the power, 2013-05-03 20:17:39]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/zea@chromium.org/14888003/33001

[commit-bot: I haz the power, 2013-05-03 21:18:34]

Step "update" is always a major failure.
Look at the try server FAQ for more details.
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=win_rel&nu...

[commit-bot: I haz the power, 2013-05-03 21:21:55]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/zea@chromium.org/14888003/33001

[commit-bot: I haz the power, 2013-05-04 00:08:14]

Sorry for I got bad news for ya.
Compile failed with a clobber build on win_rel.
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=win_rel&nu...
Your code is likely broken or HEAD is junk. Please ensure your
code is not broken then alert the build sheriffs.
Look at the try server FAQ for more details.

[commit-bot: I haz the power, 2013-05-04 00:13:07]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/zea@chromium.org/14888003/33001

[commit-bot: I haz the power, 2013-05-06 07:59:01]

Failed to apply patch for
chrome/browser/signin/about_signin_internals_factory.cc:
While running patch -p1 --forward --force --no-backup-if-mismatch;
  patching file chrome/browser/signin/about_signin_internals_factory.cc
  Hunk #1 FAILED at 62.
  1 out of 1 hunk FAILED -- saving rejects to file
chrome/browser/signin/about_signin_internals_factory.cc.rej

Patch:       chrome/browser/signin/about_signin_internals_factory.cc
Index: chrome/browser/signin/about_signin_internals_factory.cc
diff --git a/chrome/browser/signin/about_signin_internals_factory.cc
b/chrome/browser/signin/about_signin_internals_factory.cc
index
21a0922241253d8ea534f175816dd308c4126319..d3abc380872c9a8918768456445b5e64777aa5cf
100644
--- a/chrome/browser/signin/about_signin_internals_factory.cc
+++ b/chrome/browser/signin/about_signin_internals_factory.cc
@@ -62,12 +62,15 @@ void AboutSigninInternalsFactory::RegisterUserPrefs(
     const std::string value = pref + ".value";
     const std::string status = pref + ".status";
     const std::string time = pref + ".time";
+    const std::string time_internal = pref + ".time_internal";
     user_prefs->RegisterStringPref(
         value.c_str(), std::string(), PrefRegistrySyncable::UNSYNCABLE_PREF);
     user_prefs->RegisterStringPref(
         status.c_str(), std::string(), PrefRegistrySyncable::UNSYNCABLE_PREF);
     user_prefs->RegisterStringPref(
         time.c_str(), std::string(), PrefRegistrySyncable::UNSYNCABLE_PREF);
+    user_prefs->RegisterInt64Pref(
+        time_internal.c_str(), 0, PrefRegistrySyncable::UNSYNCABLE_PREF);
   }
 }

[commit-bot: I haz the power, 2013-05-06 17:29:36]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/zea@chromium.org/14888003/59001

[commit-bot: I haz the power, 2013-05-06 18:44:57]

Retried try job too often on win7_aura for step(s) interactive_ui_tests
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=win7_aura&...

[commit-bot: I haz the power, 2013-05-06 18:47:22]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/zea@chromium.org/14888003/59001

[Nicolas Zea, 2013-05-06 21:03:25]

Committed patchset #4 manually as r198531 (presubmit successful).