Client-side changes to support retry GU.

sync/engine/sync_scheduler_impl.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "sync/engine/sync_scheduler_impl.h"
 
 #include <algorithm>
 #include <cstring>
 
 #include "base/auto_reset.h"
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/compiler_specific.h"
 #include "base/location.h"
 #include "base/logging.h"
 #include "base/message_loop/message_loop.h"
+#include "base/time/default_clock.h"
 #include "sync/engine/backoff_delay_provider.h"
 #include "sync/engine/syncer.h"
 #include "sync/notifier/object_id_invalidation_map.h"
 #include "sync/protocol/proto_enum_conversions.h"
 #include "sync/protocol/sync.pb.h"
 #include "sync/util/data_type_histogram.h"
 #include "sync/util/logging.h"
 
 using base::TimeDelta;
 using base::TimeTicks;
@@ skipping 131 matching lines @@
     : name_(name),
       started_(false),
       syncer_short_poll_interval_seconds_(
           TimeDelta::FromSeconds(kDefaultShortPollIntervalSeconds)),
       syncer_long_poll_interval_seconds_(
           TimeDelta::FromSeconds(kDefaultLongPollIntervalSeconds)),
       sessions_commit_delay_(
           TimeDelta::FromSeconds(kDefaultSessionsCommitDelaySeconds)),
       mode_(NORMAL_MODE),
       delay_provider_(delay_provider),
+      nudge_tracker_(new base::DefaultClock),
       syncer_(syncer),
       session_context_(context),
       no_scheduling_allowed_(false),
       do_poll_after_credentials_updated_(false),
       next_sync_session_job_priority_(NORMAL_PRIORITY),
       weak_ptr_factory_(this),
       weak_ptr_factory_for_weak_handle_(this) {
   weak_handle_this_ = MakeWeakHandle(
       weak_ptr_factory_for_weak_handle_.GetWeakPtr());
 }
@@ skipping 49 matching lines @@
   }
 
   DCHECK(!session_context_->account_name().empty());
   DCHECK(syncer_.get());
   Mode old_mode = mode_;
   mode_ = mode;
   AdjustPolling(UPDATE_INTERVAL);  // Will kick start poll timer if needed.
 
   if (old_mode != mode_ &&
       mode_ == NORMAL_MODE &&
-      nudge_tracker_.IsSyncRequired() &&
+      (nudge_tracker_.IsSyncRequired() || nudge_tracker_.IsRetryRequired()) &&
       CanRunNudgeJobNow(NORMAL_PRIORITY)) {
     // We just got back to normal mode.  Let's try to run the work that was
     // queued up while we were configuring.
     TrySyncSessionJob();
   }
 }
 
 ModelTypeSet SyncSchedulerImpl::GetEnabledAndUnthrottledTypes() {
   ModelTypeSet enabled_types = session_context_->enabled_types();
   ModelTypeSet throttled_types = nudge_tracker_.GetThrottledTypes();
@@ skipping 192 matching lines @@
 }
 
 const char* SyncSchedulerImpl::GetModeString(SyncScheduler::Mode mode) {
   switch (mode) {
     ENUM_CASE(CONFIGURATION_MODE);
     ENUM_CASE(NORMAL_MODE);
   }
   return "";
 }
 
-void SyncSchedulerImpl::DoNudgeSyncSessionJob(JobPriority priority) {
-  DCHECK(CalledOnValidThread());
-  DCHECK(CanRunNudgeJobNow(priority));
-
-  DVLOG(2) << "Will run normal mode sync cycle with types "
-           << ModelTypeSetToString(session_context_->enabled_types());
-  scoped_ptr<SyncSession> session(SyncSession::Build(session_context_, this));
-  bool premature_exit = !syncer_->NormalSyncShare(
-      GetEnabledAndUnthrottledTypes(),
-      nudge_tracker_,
-      session.get());
-  AdjustPolling(FORCE_RESET);
-  // Don't run poll job till the next time poll timer fires.
-  do_poll_after_credentials_updated_ = false;
-
-  bool success = !premature_exit
-      && !sessions::HasSyncerError(
-          session->status_controller().model_neutral_state());
-
-  if (success) {
-    // That cycle took care of any outstanding work we had.
-    SDVLOG(2) << "Nudge succeeded.";
-    nudge_tracker_.RecordSuccessfulSyncCycle();
-    scheduled_nudge_time_ = base::TimeTicks();
-
-    // If we're here, then we successfully reached the server.  End all backoff.
-    wait_interval_.reset();
-    NotifyRetryTime(base::Time());
-    return;
-  } else {
-    HandleFailure(session->status_controller().model_neutral_state());
-  }
-}
-
 void SyncSchedulerImpl::DoConfigurationSyncSessionJob(JobPriority priority) {
   DCHECK(CalledOnValidThread());
   DCHECK_EQ(mode_, CONFIGURATION_MODE);
   DCHECK(pending_configure_params_ != NULL);
 
   if (!CanRunJobNow(priority)) {
     SDVLOG(2) << "Unable to run configure job right now.";
     if (!pending_configure_params_->retry_task.is_null()) {
       pending_configure_params_->retry_task.Run();
       pending_configure_params_->retry_task.Reset();
@@ skipping 45 matching lines @@
     TimeDelta length = delay_provider_->GetDelay(
         delay_provider_->GetInitialDelay(model_neutral_state));
     wait_interval_.reset(
         new WaitInterval(WaitInterval::EXPONENTIAL_BACKOFF, length));
     SDVLOG(2) << "Sync cycle failed.  Will back off for "
         << wait_interval_->length.InMilliseconds() << "ms.";
     RestartWaiting();
   }
 }
 
-void SyncSchedulerImpl::DoPollSyncSessionJob() {
+bool SyncSchedulerImpl::DoNudgeSyncSessionJob(SyncSession* session) {
+  DCHECK(CalledOnValidThread());
+
+  DVLOG(2) << "Will run normal mode sync cycle with types "
+           << ModelTypeSetToString(GetEnabledAndUnthrottledTypes());
+  return syncer_->NormalSyncShare(GetEnabledAndUnthrottledTypes(),
+                                  nudge_tracker_,
+                                  session);
+}
+
+bool SyncSchedulerImpl::DoPollSyncSessionJob(SyncSession* session) {
+  DCHECK(CalledOnValidThread());
+  DCHECK_EQ(mode_, NORMAL_MODE);
+
   base::AutoReset<bool> protector(&no_scheduling_allowed_, true);
 
-  if (!CanRunJobNow(NORMAL_PRIORITY)) {
-    SDVLOG(2) << "Unable to run a poll job right now.";
-    return;
-  }
+  SDVLOG(2) << "Polling with types "
+            << ModelTypeSetToString(GetEnabledAndUnthrottledTypes());
+  return syncer_->PollSyncShare(GetEnabledAndUnthrottledTypes(),
+                                session);
+}
 
-  if (mode_ != NORMAL_MODE) {
-    SDVLOG(2) << "Not running poll job in configure mode.";
-    return;
-  }
+bool SyncSchedulerImpl::DoRetrySyncSessionJob(SyncSession* session) {
+  DCHECK(CalledOnValidThread());
+  DCHECK_EQ(mode_, NORMAL_MODE);
 
-  SDVLOG(2) << "Polling with types "
-            << ModelTypeSetToString(session_context_->enabled_types());
-  scoped_ptr<SyncSession> session(SyncSession::Build(session_context_, this));
-  syncer_->PollSyncShare(
-      GetEnabledAndUnthrottledTypes(),
-      session.get());
+  base::AutoReset<bool> protector(&no_scheduling_allowed_, true);
 
-  AdjustPolling(FORCE_RESET);
-
-  if (IsCurrentlyThrottled()) {
-    SDVLOG(2) << "Poll request got us throttled.";
-    // The OnSilencedUntil() call set up the WaitInterval for us.  All we need
-    // to do is start the timer.
-    RestartWaiting();
-  }
+  SDVLOG(2) << "Retry with types "
+            << ModelTypeSetToString(GetEnabledAndUnthrottledTypes());
+  return syncer_->RetrySyncShare(GetEnabledAndUnthrottledTypes(),
+                                 session);
 }
 
 void SyncSchedulerImpl::UpdateNudgeTimeRecords(ModelTypeSet types) {
   DCHECK(CalledOnValidThread());
   base::TimeTicks now = TimeTicks::Now();
   // Update timing information for how often datatypes are triggering nudges.
   for (ModelTypeSet::Iterator iter = types.First(); iter.Good(); iter.Inc()) {
     base::TimeTicks previous = last_local_nudges_by_model_type_[iter.Get()];
     last_local_nudges_by_model_type_[iter.Get()] = now;
     if (previous.is_null())
@@ skipping 91 matching lines @@
   next_sync_session_job_priority_ = NORMAL_PRIORITY;
 
   DCHECK(CalledOnValidThread());
   if (mode_ == CONFIGURATION_MODE) {
     if (pending_configure_params_) {
       SDVLOG(2) << "Found pending configure job";
       DoConfigurationSyncSessionJob(priority);
     }
   } else {
     DCHECK(mode_ == NORMAL_MODE);
-    if (nudge_tracker_.IsSyncRequired() && CanRunNudgeJobNow(priority)) {
+    if (!CanRunNudgeJobNow(priority))
+      return;
+
+    scoped_ptr<SyncSession> session(SyncSession::Build(session_context_, this));

[rlarocque, 2014/01/06 23:00:33]

I'm strongly against this.  I spent a lot of time trying to eliminate the
SyncSession.  It's brittle and has caused lots of hard to detect crashes in the
past.

Looking to the future, I think an important goal will be to remove the concept
of the sync cycle.  Otherwise we'll never be able to properly handle
no-precommit-GU cycles.  The SyncSession is an obstacle that prevents this
change, and that's why I want to eliminate it.

This change would make it much harder to remove the SyncSession.  We should find
some other way to implement this.

[haitaol1, 2014/01/07 19:03:37]

Done.

+    bool tried_sync = false;
+
+    if (nudge_tracker_.IsSyncRequired()) {
       SDVLOG(2) << "Found pending nudge job";
-      DoNudgeSyncSessionJob(priority);
+      tried_sync = DoNudgeSyncSessionJob(session.get());
+    } else if (nudge_tracker_.IsRetryRequired()) {
+      tried_sync = DoRetrySyncSessionJob(session.get());
     } else if (do_poll_after_credentials_updated_ ||
-        ((base::TimeTicks::Now() - last_poll_reset_) >= GetPollInterval())) {
-      DoPollSyncSessionJob();
-      // Poll timer fires infrequently. Usually by this time access token is
-      // already expired and poll job will fail with auth error. Set flag to
-      // retry poll once ProfileSyncService gets new access token, TryCanaryJob
-      // will be called after access token is retrieved.
-      if (HttpResponse::SYNC_AUTH_ERROR ==
-          session_context_->connection_manager()->server_status()) {
-        do_poll_after_credentials_updated_ = true;
-      }
+        (base::TimeTicks::Now() - last_poll_reset_) >= GetPollInterval()) {
+      tried_sync = DoPollSyncSessionJob(session.get());
     }
+
+    if (tried_sync)
+      SyncSessionPostProcessing(session.get());
   }
 
   if (priority == CANARY_PRIORITY) {
     // If this is canary job then whatever result was don't run poll job till
     // the next time poll timer fires.
     do_poll_after_credentials_updated_ = false;
   }
 
   if (IsBackingOff() && !pending_wakeup_timer_.IsRunning()) {
     // If we succeeded, our wait interval would have been cleared.  If it hasn't
     // been cleared, then we should increase our backoff interval and schedule
     // another retry.
     TimeDelta length = delay_provider_->GetDelay(wait_interval_->length);
     wait_interval_.reset(
       new WaitInterval(WaitInterval::EXPONENTIAL_BACKOFF, length));
     SDVLOG(2) << "Sync cycle failed.  Will back off for "
         << wait_interval_->length.InMilliseconds() << "ms.";
     RestartWaiting();
   }
 }
 
+void SyncSchedulerImpl::SyncSessionPostProcessing(SyncSession* session) {
+  AdjustPolling(FORCE_RESET);
+  // Don't run poll job till the next time poll timer fires.
+  do_poll_after_credentials_updated_ = false;
+
+  bool success = !sessions::HasSyncerError(
+          session->status_controller().model_neutral_state());
+
+  if (success) {
+    // That cycle took care of any outstanding work we had.
+    SDVLOG(2) << "Sync session succeeded.";
+    nudge_tracker_.RecordSuccessfulSyncCycle();

[rlarocque, 2014/01/06 23:00:33]

The SyncScheduler used to have code that looks like this.  I've tried to move it
in a different direction, and this would be a step backward.

At some point, we're going to have to let the NudgeTracker know when the syncer
has completed a GU, Commit, or both.  It will have to update it's state
differently in each case.  Calling "RecordSuccessfulSyncCycle()" may update the
status wrongly if this was a commit-only sync cycle.  There are also some
strange edge cases, like when a GU succeeds but the commit fails with a
transient error.

The syncer, about:sync and a few other components are still not quite ready for
that change.  However, when that change does come, we'll need to have failure
handling logic that is unique to each kind of job in the SyncScheduler.  This is
why I moved the error handling logic into separate functions and why I want to
keep it there.

[haitaol1, 2014/01/07 19:03:37]

Done.

+    scheduled_nudge_time_ = base::TimeTicks();
+
+    // If we're here, then we successfully reached the server.  End all backoff.
+    wait_interval_.reset();
+    NotifyRetryTime(base::Time());
+
+    return;
+  } else {
+    HandleFailure(session->status_controller().model_neutral_state());
+  }
+}
+
 void SyncSchedulerImpl::PollTimerCallback() {
   DCHECK(CalledOnValidThread());
   if (no_scheduling_allowed_) {
     // The no_scheduling_allowed_ flag is set by a function-scoped AutoReset in
     // functions that are called only on the sync thread.  This function is also
     // called only on the sync thread, and only when it is posted by an expiring
     // timer.  If we find that no_scheduling_allowed_ is set here, then
     // something is very wrong.  Maybe someone mistakenly called us directly, or
     // mishandled the book-keeping for no_scheduling_allowed_.
     NOTREACHED() << "Illegal to schedule job while session in progress.";
     return;
   }
 
   TrySyncSessionJob();
 }
 
+void SyncSchedulerImpl::RetryTimerCallback() {
+  TrySyncSessionJob();
+}
+
 void SyncSchedulerImpl::Unthrottle() {
   DCHECK(CalledOnValidThread());
   DCHECK_EQ(WaitInterval::THROTTLED, wait_interval_->mode);
 
   // We're no longer throttled, so clear the wait interval.
   wait_interval_.reset();
   NotifyRetryTime(base::Time());
 
   // We treat this as a 'canary' in the sense that it was originally scheduled
   // to run some time ago, failed, and we now want to retry, versus a job that
@@ skipping 133 matching lines @@
   DCHECK(CalledOnValidThread());
   if (ShouldRequestEarlyExit(
           snapshot.model_neutral_state().sync_protocol_error)) {
     SDVLOG(2) << "Sync Scheduler requesting early exit.";
     Stop();
   }
   if (IsActionableError(snapshot.model_neutral_state().sync_protocol_error))
     OnActionableError(snapshot);
 }
 
+void SyncSchedulerImpl::OnReceivedGuRetryDelaySeconds(int delay_seconds) {
+  nudge_tracker_.set_next_retry_time(
+      base::Time::Now() + base::TimeDelta::FromSeconds(delay_seconds));
+  retry_timer_.Start(FROM_HERE, base::TimeDelta::FromSeconds(delay_seconds),
+                     this, &SyncSchedulerImpl::RetryTimerCallback);
+}
+
 void SyncSchedulerImpl::SetNotificationsEnabled(bool notifications_enabled) {
   DCHECK(CalledOnValidThread());
   session_context_->set_notifications_enabled(notifications_enabled);
   if (notifications_enabled)
     nudge_tracker_.OnInvalidationsEnabled();
   else
     nudge_tracker_.OnInvalidationsDisabled();
 }
 
 base::TimeDelta SyncSchedulerImpl::GetSessionsCommitDelay() const {
   DCHECK(CalledOnValidThread());
   return sessions_commit_delay_;
 }
 
 #undef SDVLOG_LOC
 
 #undef SDVLOG
 
 #undef SLOG
 
 #undef ENUM_CASE
 
 }  // namespace syncer