SyncAuthManager: make sure next_token_request_time gets cleared

This fixes one (small) issue where the next_token_request_time didn't
get cleared if the retry timer called us while there was already a
request ongoing. It also adds a bunch of DCHECKs to hopefully catch
any other cases I might have missed.
Inspired by some recent bug reports that showed a "Next Token Request"
time in the past on about:sync-internals.

Bug: 889859
Change-Id: I8cd189c0e4acccc4af0d38a3ce9da6ccbd3cac7a
Reviewed-on: https://chromium-review.googlesource.com/1249067Reviewed-by: Mikel Astiz <mastiz@chromium.org>
Commit-Queue: Marc Treib <treib@chromium.org>
Cr-Commit-Position: refs/heads/master@{#594714}

components/browser_sync/sync_auth_manager.cc

@@ -160,11 +160,14 @@ void SyncAuthManager::ConnectionStatusChanged(syncer::ConnectionStatus status) {
         // this point.
         DCHECK(access_token_.empty());
         DCHECK(!request_access_token_retry_timer_.IsRunning());
+        DCHECK(token_status_.next_token_request_time.is_null());
       } else if (request_access_token_retry_timer_.IsRunning()) {
         // The timer to perform a request later is already running; nothing
         // further needs to be done at this point.
         DCHECK(access_token_.empty());
+        DCHECK(!token_status_.next_token_request_time.is_null());
       } else if (request_access_token_backoff_.failure_count() == 0) {
+        DCHECK(token_status_.next_token_request_time.is_null());
         // First time request without delay. Currently invalid token is used
         // to initialize sync engine and we'll always end up here. We don't
         // want to delay initialization.
@@ -179,13 +182,7 @@ void SyncAuthManager::ConnectionStatusChanged(syncer::ConnectionStatus status) {
           credentials_changed_callback_.Run();
         }
         request_access_token_backoff_.InformOfRequest(false);
-        base::TimeDelta delay =
-            request_access_token_backoff_.GetTimeUntilRelease();
-        token_status_.next_token_request_time = base::Time::Now() + delay;
-        request_access_token_retry_timer_.Start(
-            FROM_HERE, delay,
-            base::BindRepeating(&SyncAuthManager::RequestAccessToken,
-                                weak_ptr_factory_.GetWeakPtr()));
+        ScheduleAccessTokenRequest();
       }
       break;
     case syncer::CONNECTION_OK:
@@ -195,6 +192,7 @@ void SyncAuthManager::ConnectionStatusChanged(syncer::ConnectionStatus status) {
       // thus hammers token server. To be safe, only reset backoff delay when
       // no scheduled request.
       if (!request_access_token_retry_timer_.IsRunning()) {
+        DCHECK(token_status_.next_token_request_time.is_null());
         request_access_token_backoff_.Reset();
       }
       last_auth_error_ = GoogleServiceAuthError::AuthErrorNone();
@@ -220,6 +218,20 @@ void SyncAuthManager::ClearAccessTokenAndRequest() {
   weak_ptr_factory_.InvalidateWeakPtrs();
 }
 
+void SyncAuthManager::ScheduleAccessTokenRequest() {
+  DCHECK(access_token_.empty());
+  DCHECK(!ongoing_access_token_fetch_);
+  DCHECK(!request_access_token_retry_timer_.IsRunning());
+  DCHECK(token_status_.next_token_request_time.is_null());
+
+  base::TimeDelta delay = request_access_token_backoff_.GetTimeUntilRelease();
+  token_status_.next_token_request_time = base::Time::Now() + delay;
+  request_access_token_retry_timer_.Start(
+      FROM_HERE, delay,
+      base::BindRepeating(&SyncAuthManager::RequestAccessToken,
+                          weak_ptr_factory_.GetWeakPtr()));
+}
+
 void SyncAuthManager::Clear() {
   // TODO(crbug.com/839834): Clearing the auth error here isn't quite right.
   // It makes sense to clear any auth error we got from the Sync server, but we
@@ -389,6 +401,12 @@ bool SyncAuthManager::UpdateSyncAccountIfNecessary() {
 }
 
 void SyncAuthManager::RequestAccessToken() {
+  // First reset the next request time: Either we were called back by the retry
+  // timer, in which case this is now obsolete, or we'll cancel the timer below.
+  // Note that if we were called back by the retry timer, then it's already
+  // considered not running, so we reset this time unconditionally.
+  token_status_.next_token_request_time = base::Time();
+
   // Only one active request at a time.
   if (ongoing_access_token_fetch_) {
     DCHECK(access_token_.empty());
@@ -401,10 +419,6 @@ void SyncAuthManager::RequestAccessToken() {
   if (request_access_token_retry_timer_.IsRunning()) {
     request_access_token_retry_timer_.Stop();
   }
-  // Also reset the next request time. Note that if we were called back by the
-  // timer, then it's already considered not running, so we reset this time
-  // unconditionally.
-  token_status_.next_token_request_time = base::Time();
 
   const OAuth2TokenService::ScopeSet kOAuth2ScopeSet{
       GaiaConstants::kChromeSyncOAuth2Scope};
@@ -436,6 +450,7 @@ void SyncAuthManager::AccessTokenFetched(
     identity::AccessTokenInfo access_token_info) {
   DCHECK(ongoing_access_token_fetch_);
   ongoing_access_token_fetch_.reset();
+  DCHECK(!request_access_token_retry_timer_.IsRunning());
 
   access_token_ = access_token_info.token;
   token_status_.last_get_token_error = error;
@@ -458,13 +473,7 @@ void SyncAuthManager::AccessTokenFetched(
       // persistent error. Should we use .IsTransientError() instead of manually
       // listing cases here?
       request_access_token_backoff_.InformOfRequest(false);
-      token_status_.next_token_request_time =
-          base::Time::Now() +
-          request_access_token_backoff_.GetTimeUntilRelease();
-      request_access_token_retry_timer_.Start(
-          FROM_HERE, request_access_token_backoff_.GetTimeUntilRelease(),
-          base::BindRepeating(&SyncAuthManager::RequestAccessToken,
-                              weak_ptr_factory_.GetWeakPtr()));
+      ScheduleAccessTokenRequest();
       break;
     case GoogleServiceAuthError::INVALID_GAIA_CREDENTIALS:
       sync_prefs_->SetSyncAuthError(true);

components/browser_sync/sync_auth_manager.h

@@ -120,8 +120,17 @@ class SyncAuthManager : public identity::IdentityManager::Observer {
   // account to another is exposed to observers as a sign-out + sign-in.
   bool UpdateSyncAccountIfNecessary();
 
+  // Clears any access token we have, and cancels any pending or scheduled
+  // request for one.
   void ClearAccessTokenAndRequest();
 
+  // Schedules a request for an access token according to the current
+  // |request_access_token_backoff_|. Usually called after some transient error.
+  void ScheduleAccessTokenRequest();
+
+  // Immediately starts an access token request, unless one is already ongoing.
+  // If another request is scheduled for later, it is canceled. Any access token
+  // we currently have is dropped and removed from IdentityManager's cache.
   void RequestAccessToken();
 
   void AccessTokenFetched(GoogleServiceAuthError error,