On chrome://sync-internals, also show the time when an auth error was set

In some past investigations, it might have been useful to know since
when an auth error state has existed.

Bug: 948074
Change-Id: I4220dbea552725cd0d75b35e563e292f7d5eea12
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1557027Reviewed-by: Mikel Astiz <mastiz@chromium.org>
Commit-Queue: Marc Treib <treib@chromium.org>
Cr-Commit-Position: refs/heads/master@{#649054}

components/sync/driver/about_sync_util.cc

@@ -331,7 +331,6 @@ std::unique_ptr<base::DictionaryValue> ConstructAboutInformation(
   Stat<std::string>* username = section_identity->AddStringStat("Username");
   Stat<bool>* user_is_primary = section_identity->AddBoolStat("Is Primary");
   Stat<std::string>* auth_error = section_identity->AddStringStat("Auth Error");
-  // TODO(crbug.com/948074): Add the time of the auth error.
 
   Section* section_credentials = section_list.AddSection("Credentials");
   Stat<std::string>* request_token_time =
@@ -471,7 +470,9 @@ std::unique_ptr<base::DictionaryValue> ConstructAboutInformation(
   username->Set(service->GetAuthenticatedAccountInfo().email);
   user_is_primary->Set(service->IsAuthenticatedAccountPrimary());
   std::string auth_error_str = service->GetAuthError().ToString();
-  auth_error->Set(auth_error_str.empty() ? "None" : auth_error_str);
+  auth_error->Set(base::StringPrintf(
+      "%s since %s", (auth_error_str.empty() ? "OK" : auth_error_str).c_str(),
+      GetTimeStr(service->GetAuthErrorTime(), "browser startup").c_str()));
 
   // Credentials.
   request_token_time->Set(GetTimeStr(token_status.token_request_time, "n/a"));

components/sync/driver/fake_sync_service.cc

@@ -90,6 +90,10 @@ GoogleServiceAuthError FakeSyncService::GetAuthError() const {
   return GoogleServiceAuthError();
 }
 
+base::Time FakeSyncService::GetAuthErrorTime() const {
+  return base::Time();
+}
+
 bool FakeSyncService::RequiresClientUpgrade() const {
   return false;
 }

components/sync/driver/fake_sync_service.h

@@ -45,6 +45,7 @@ class FakeSyncService : public SyncService {
       override;
   bool IsSetupInProgress() const override;
   GoogleServiceAuthError GetAuthError() const override;
+  base::Time GetAuthErrorTime() const override;
   bool RequiresClientUpgrade() const override;
   UserShare* GetUserShare() const override;
   void ReenableDatatype(ModelType type) override;

components/sync/driver/mock_sync_service.h

@@ -38,6 +38,7 @@ class MockSyncService : public SyncService {
   MOCK_CONST_METHOD0(GetAuthenticatedAccountInfo, CoreAccountInfo());
   MOCK_CONST_METHOD0(IsAuthenticatedAccountPrimary, bool());
   MOCK_CONST_METHOD0(GetAuthError, GoogleServiceAuthError());
+  MOCK_CONST_METHOD0(GetAuthErrorTime, base::Time());
   MOCK_CONST_METHOD0(RequiresClientUpgrade, bool());
 
   MOCK_METHOD0(GetSetupInProgressHandle,

components/sync/driver/profile_sync_service.cc

@@ -1165,6 +1165,11 @@ GoogleServiceAuthError ProfileSyncService::GetAuthError() const {
   return auth_manager_->GetLastAuthError();
 }
 
+base::Time ProfileSyncService::GetAuthErrorTime() const {
+  DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
+  return auth_manager_->GetLastAuthErrorTime();
+}
+
 bool ProfileSyncService::RequiresClientUpgrade() const {
   return last_actionable_error_.action == UPGRADE_CLIENT;
 }

components/sync/driver/profile_sync_service.h

@@ -120,6 +120,7 @@ class ProfileSyncService : public SyncService,
   CoreAccountInfo GetAuthenticatedAccountInfo() const override;
   bool IsAuthenticatedAccountPrimary() const override;
   GoogleServiceAuthError GetAuthError() const override;
+  base::Time GetAuthErrorTime() const override;
   bool RequiresClientUpgrade() const override;
   std::unique_ptr<SyncSetupInProgressHandle> GetSetupInProgressHandle()
       override;

components/sync/driver/sync_auth_manager.cc

@@ -104,6 +104,15 @@ GoogleServiceAuthError SyncAuthManager::GetLastAuthError() const {
   return last_auth_error_;
 }
 
+base::Time SyncAuthManager::GetLastAuthErrorTime() const {
+  // See GetLastAuthError().
+  if (partial_token_status_.connection_status ==
+      syncer::CONNECTION_SERVER_ERROR) {
+    return partial_token_status_.connection_status_update_time;
+  }
+  return last_auth_error_time_;
+}
+
 bool SyncAuthManager::IsSyncPaused() const {
   return IsWebSignout(GetLastAuthError());
 }
@@ -281,7 +290,7 @@ void SyncAuthManager::OnRefreshTokenUpdatedForAccount(
     // that's not going to happen in this case.
     // TODO(blundell): Long-term, it would be nicer if Sync didn't have to
     // cache signin-level authentication errors.
-    last_auth_error_ = token_error;
+    SetLastAuthError(token_error);
 
     credentials_changed_callback_.Run();
     return;
@@ -322,8 +331,8 @@ void SyncAuthManager::OnRefreshTokenRemovedForAccount(
 
   // TODO(crbug.com/839834): REQUEST_CANCELED doesn't seem like the right auth
   // error to use here. Maybe INVALID_GAIA_CREDENTIALS?
-  last_auth_error_ =
-      GoogleServiceAuthError(GoogleServiceAuthError::REQUEST_CANCELED);
+  SetLastAuthError(
+      GoogleServiceAuthError(GoogleServiceAuthError::REQUEST_CANCELED));
   ClearAccessTokenAndRequest();
 
   credentials_changed_callback_.Run();
@@ -369,7 +378,7 @@ bool SyncAuthManager::UpdateSyncAccountIfNecessary() {
     // Also clear any pending request or auth errors we might have, since they
     // aren't meaningful anymore.
     ConnectionClosed();
-    last_auth_error_ = GoogleServiceAuthError::AuthErrorNone();
+    SetLastAuthError(GoogleServiceAuthError::AuthErrorNone());
     account_state_changed_callback_.Run();
   }
 
@@ -429,7 +438,7 @@ void SyncAuthManager::AccessTokenFetched(
   switch (error.state()) {
     case GoogleServiceAuthError::NONE:
       partial_token_status_.token_receive_time = base::Time::Now();
-      last_auth_error_ = GoogleServiceAuthError::AuthErrorNone();
+      SetLastAuthError(GoogleServiceAuthError::AuthErrorNone());
       break;
     case GoogleServiceAuthError::CONNECTION_FAILED:
     case GoogleServiceAuthError::REQUEST_CANCELED:
@@ -443,14 +452,22 @@ void SyncAuthManager::AccessTokenFetched(
       ScheduleAccessTokenRequest();
       break;
     case GoogleServiceAuthError::INVALID_GAIA_CREDENTIALS:
-      last_auth_error_ = error;
+      SetLastAuthError(error);
       break;
     default:
-      LOG(ERROR) << "Unexpected persistent error: " << error.ToString();
-      last_auth_error_ = error;
+      DLOG(ERROR) << "Unexpected persistent error: " << error.ToString();
+      SetLastAuthError(error);
   }
 
   credentials_changed_callback_.Run();
 }
 
+void SyncAuthManager::SetLastAuthError(const GoogleServiceAuthError& error) {
+  if (last_auth_error_ == error) {
+    return;
+  }
+  last_auth_error_ = error;
+  last_auth_error_time_ = base::Time::Now();
+}
+
 }  // namespace syncer

components/sync/driver/sync_auth_manager.h

@@ -12,6 +12,7 @@
 #include "base/callback.h"
 #include "base/macros.h"
 #include "base/memory/weak_ptr.h"
+#include "base/time/time.h"
 #include "base/timer/timer.h"
 #include "components/signin/core/browser/account_info.h"
 #include "components/sync/driver/sync_auth_util.h"
@@ -66,6 +67,9 @@ class SyncAuthManager : public identity::IdentityManager::Observer {
   // from the Sync server or from the IdentityManager.
   GoogleServiceAuthError GetLastAuthError() const;
 
+  // Returns the time at which the last auth error was set.
+  base::Time GetLastAuthErrorTime() const;
+
   // Returns whether we are in the "Sync paused" state. That means there is a
   // primary account, but the user signed out in the content area, and so we
   // don't have credentials for it anymore.
@@ -134,9 +138,12 @@ class SyncAuthManager : public identity::IdentityManager::Observer {
   // we currently have is invalidated.
   void RequestAccessToken();
 
+  // Callback for |ongoing_access_token_fetch_|.
   void AccessTokenFetched(GoogleServiceAuthError error,
                           identity::AccessTokenInfo access_token_info);
 
+  void SetLastAuthError(const GoogleServiceAuthError& error);
+
   identity::IdentityManager* const identity_manager_;
 
   const AccountStateChangedCallback account_state_changed_callback_;
@@ -152,6 +159,7 @@ class SyncAuthManager : public identity::IdentityManager::Observer {
   // This is a cache of the last authentication response we received from
   // Chrome's identity/token management system.
   GoogleServiceAuthError last_auth_error_;
+  base::Time last_auth_error_time_;
 
   // The current access token. This is mutually exclusive with
   // |ongoing_access_token_fetch_| and |request_access_token_retry_timer_|:

components/sync/driver/sync_service.h

@@ -226,6 +226,7 @@ class SyncService : public KeyedService {
   // an access token), or from the Sync server. It gets cleared when the error
   // is resolved.
   virtual GoogleServiceAuthError GetAuthError() const = 0;
+  virtual base::Time GetAuthErrorTime() const = 0;
 
   // Returns true if the Chrome client is too old and needs to be updated for
   // Sync to work.

components/sync/driver/test_sync_service.cc

@@ -149,6 +149,10 @@ GoogleServiceAuthError TestSyncService::GetAuthError() const {
   return auth_error_;
 }
 
+base::Time TestSyncService::GetAuthErrorTime() const {
+  return base::Time();
+}
+
 bool TestSyncService::RequiresClientUpgrade() const {
   return detailed_sync_status_.sync_protocol_error.action ==
          syncer::UPGRADE_CLIENT;

components/sync/driver/test_sync_service.h

@@ -58,6 +58,7 @@ class TestSyncService : public SyncService {
   CoreAccountInfo GetAuthenticatedAccountInfo() const override;
   bool IsAuthenticatedAccountPrimary() const override;
   GoogleServiceAuthError GetAuthError() const override;
+  base::Time GetAuthErrorTime() const override;
   bool RequiresClientUpgrade() const override;
 
   std::unique_ptr<SyncSetupInProgressHandle> GetSetupInProgressHandle()