[Sync] Sync client should to exponential backoff when receive partial failure

components/sync/engine_impl/sync_scheduler_impl.cc

Index: components/sync/engine_impl/sync_scheduler_impl.cc
diff --git a/components/sync/engine_impl/sync_scheduler_impl.cc b/components/sync/engine_impl/sync_scheduler_impl.cc
index 9f8f3fd7f53e8fb2556bf4f664f720089e098db8..46fd0f0028d2aec271cf9a04e742f1dcbbf15169 100644
--- a/components/sync/engine_impl/sync_scheduler_impl.cc
+++ b/components/sync/engine_impl/sync_scheduler_impl.cc
@@ -88,6 +88,11 @@ void RunAndReset(base::Closure* task) {
   task->Reset();
 }
 
+#define ENUM_CASE(x) \
+  case x:            \
+    return #x;       \
+    break;
+
 }  // namespace
 
 ConfigurationParams::ConfigurationParams()
@@ -116,28 +121,6 @@ ClearParams::ClearParams(const base::Closure& report_success_task)
 ClearParams::ClearParams(const ClearParams& other) = default;
 ClearParams::~ClearParams() {}
 
-SyncSchedulerImpl::WaitInterval::WaitInterval() : mode(UNKNOWN) {}
-
-SyncSchedulerImpl::WaitInterval::WaitInterval(Mode mode, TimeDelta length)
-    : mode(mode), length(length) {}
-
-SyncSchedulerImpl::WaitInterval::~WaitInterval() {}
-
-#define ENUM_CASE(x) \
-  case x:            \
-    return #x;       \
-    break;
-
-const char* SyncSchedulerImpl::WaitInterval::GetModeString(Mode mode) {
-  switch (mode) {
-    ENUM_CASE(UNKNOWN);
-    ENUM_CASE(EXPONENTIAL_BACKOFF);
-    ENUM_CASE(THROTTLED);
-  }
-  NOTREACHED();
-  return "";
-}
-
 GetUpdatesCallerInfo::GetUpdatesSource GetUpdatesFromNudgeSource(
     NudgeSource source) {
   switch (source) {
@@ -251,8 +234,7 @@ void SyncSchedulerImpl::Start(Mode mode, base::Time last_poll_time) {
     // actually have miss the real poll, unless the client is restarted. Fixing
     // that would require using an AlarmTimer though, which is only supported
     // on certain platforms.
-    last_poll_reset_ =
-        base::TimeTicks::Now() - (base::Time::Now() - last_poll_time);
+    last_poll_reset_ = TimeTicks::Now() - (base::Time::Now() - last_poll_time);
   }
 
   if (old_mode != mode_ && mode_ == NORMAL_MODE) {
@@ -262,19 +244,21 @@ void SyncSchedulerImpl::Start(Mode mode, base::Time last_poll_time) {
     AdjustPolling(UPDATE_INTERVAL);  // Will kick start poll timer if needed.
 
     // Update our current time before checking IsRetryRequired().
-    nudge_tracker_.SetSyncCycleStartTime(base::TimeTicks::Now());
+    nudge_tracker_.SetSyncCycleStartTime(TimeTicks::Now());
     if (nudge_tracker_.IsSyncRequired() && CanRunNudgeJobNow(NORMAL_PRIORITY)) {
       TrySyncCycleJob();
     }
   }
 }
 
-ModelTypeSet SyncSchedulerImpl::GetEnabledAndUnthrottledTypes() {
+ModelTypeSet SyncSchedulerImpl::GetEnabledAndUnblockedTypes() {
   ModelTypeSet enabled_types = cycle_context_->GetEnabledTypes();
   ModelTypeSet enabled_protocol_types =
       Intersection(ProtocolTypes(), enabled_types);
   ModelTypeSet throttled_types = nudge_tracker_.GetThrottledTypes();
-  return Difference(enabled_protocol_types, throttled_types);
+  ModelTypeSet backed_off_types = nudge_tracker_.GetBackedOffTypes();
+  return Difference(enabled_protocol_types,
+                    Union(throttled_types, backed_off_types));
 }
 
 void SyncSchedulerImpl::SendInitialSnapshot() {
@@ -394,7 +378,7 @@ void SyncSchedulerImpl::ScheduleLocalNudge(
   SDVLOG_LOC(nudge_location, 2) << "Scheduling sync because of local change to "
                                 << ModelTypeSetToString(types);
   UpdateNudgeTimeRecords(types);
-  base::TimeDelta nudge_delay = nudge_tracker_.RecordLocalChange(types);
+  TimeDelta nudge_delay = nudge_tracker_.RecordLocalChange(types);
   ScheduleNudgeImpl(nudge_delay, nudge_location);
 }
 
@@ -407,7 +391,7 @@ void SyncSchedulerImpl::ScheduleLocalRefreshRequest(
   SDVLOG_LOC(nudge_location, 2)
       << "Scheduling sync because of local refresh request for "
       << ModelTypeSetToString(types);
-  base::TimeDelta nudge_delay = nudge_tracker_.RecordLocalRefreshRequest(types);
+  TimeDelta nudge_delay = nudge_tracker_.RecordLocalRefreshRequest(types);
   ScheduleNudgeImpl(nudge_delay, nudge_location);
 }
 
@@ -420,7 +404,7 @@ void SyncSchedulerImpl::ScheduleInvalidationNudge(
   SDVLOG_LOC(nudge_location, 2)
       << "Scheduling sync because we received invalidation for "
       << ModelTypeToString(model_type);
-  base::TimeDelta nudge_delay = nudge_tracker_.RecordRemoteInvalidation(
+  TimeDelta nudge_delay = nudge_tracker_.RecordRemoteInvalidation(
       model_type, std::move(invalidation));
   ScheduleNudgeImpl(nudge_delay, nudge_location);
 }
@@ -455,8 +439,8 @@ void SyncSchedulerImpl::ScheduleNudgeImpl(
     return;
 
   TimeTicks incoming_run_time = TimeTicks::Now() + delay;
-  if (!scheduled_nudge_time_.is_null() &&
-      (scheduled_nudge_time_ < incoming_run_time)) {
+  if (global_wakeup_timer_.IsRunning() &&
+      (global_wakeup_timer_.desired_run_time() < incoming_run_time)) {
     // Old job arrives sooner than this one.  Don't reschedule it.
     return;
   }
@@ -466,9 +450,8 @@ void SyncSchedulerImpl::ScheduleNudgeImpl(
   // case.
   SDVLOG_LOC(nudge_location, 2) << "Scheduling a nudge with "
                                 << delay.InMilliseconds() << " ms delay";
-  scheduled_nudge_time_ = incoming_run_time;
-  pending_wakeup_timer_.Start(
-      nudge_location, delay, base::Bind(&SyncSchedulerImpl::PerformDelayedNudge,
+  global_wakeup_timer_.Start(nudge_location, delay,
+                             base::Bind(&SyncSchedulerImpl::PerformDelayedNudge,
                                         weak_ptr_factory_.GetWeakPtr()));
 }
 
@@ -481,7 +464,7 @@ const char* SyncSchedulerImpl::GetModeString(SyncScheduler::Mode mode) {
   return "";
 }
 
-void SyncSchedulerImpl::SetDefaultNudgeDelay(base::TimeDelta delay_ms) {
+void SyncSchedulerImpl::SetDefaultNudgeDelay(TimeDelta delay_ms) {
   DCHECK(CalledOnValidThread());
   nudge_tracker_.SetDefaultNudgeDelay(delay_ms);
 }
@@ -493,14 +476,13 @@ void SyncSchedulerImpl::DoNudgeSyncCycleJob(JobPriority priority) {
   DVLOG(2) << "Will run normal mode sync cycle with types "
            << ModelTypeSetToString(cycle_context_->GetEnabledTypes());
   std::unique_ptr<SyncCycle> cycle(SyncCycle::Build(cycle_context_, this));
-  bool success = syncer_->NormalSyncShare(GetEnabledAndUnthrottledTypes(),
+  bool success = syncer_->NormalSyncShare(GetEnabledAndUnblockedTypes(),
                                           &nudge_tracker_, cycle.get());
 
   if (success) {
     // That cycle took care of any outstanding work we had.
     SDVLOG(2) << "Nudge succeeded.";
     nudge_tracker_.RecordSuccessfulSyncCycle();
-    scheduled_nudge_time_ = base::TimeTicks();
     HandleSuccess();
 
     // If this was a canary, we may need to restart the poll timer (the poll
@@ -578,6 +560,11 @@ void SyncSchedulerImpl::HandleSuccess() {
 
 void SyncSchedulerImpl::HandleFailure(
     const ModelNeutralState& model_neutral_state) {
+  if (model_neutral_state.commit_result == SERVER_RETURN_PARTIAL_FAILURE) {

[Nicolas Zea, 2016/11/09 00:21:25]

Should partial failure just count as success?

[Gang Wu, 2016/11/10 21:56:51]

Done.

+    // Since it is partial failure, we have handled in OnTypesThrottled or
+    // OnTypesBackedOff already.
+    return;
+  }
   if (IsCurrentlyThrottled()) {
     SDVLOG(2) << "Was throttled during previous sync cycle.";
   } else if (!IsBackingOff()) {
@@ -601,10 +588,10 @@ void SyncSchedulerImpl::HandleFailure(
 
 void SyncSchedulerImpl::DoPollSyncCycleJob() {
   SDVLOG(2) << "Polling with types "
-            << ModelTypeSetToString(GetEnabledAndUnthrottledTypes());
+            << ModelTypeSetToString(GetEnabledAndUnblockedTypes());
   std::unique_ptr<SyncCycle> cycle(SyncCycle::Build(cycle_context_, this));
   bool success =
-      syncer_->PollSyncShare(GetEnabledAndUnthrottledTypes(), cycle.get());
+      syncer_->PollSyncShare(GetEnabledAndUnblockedTypes(), cycle.get());
 
   // Only restart the timer if the poll succeeded. Otherwise rely on normal
   // failure handling to retry with backoff.
@@ -618,10 +605,10 @@ void SyncSchedulerImpl::DoPollSyncCycleJob() {
 
 void SyncSchedulerImpl::UpdateNudgeTimeRecords(ModelTypeSet types) {
   DCHECK(CalledOnValidThread());
-  base::TimeTicks now = TimeTicks::Now();
+  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()];
+    TimeTicks previous = last_local_nudges_by_model_type_[iter.Get()];
     last_local_nudges_by_model_type_[iter.Get()] = now;
     if (previous.is_null())
       continue;
@@ -690,11 +677,11 @@ void SyncSchedulerImpl::RestartWaiting() {
   SDVLOG(2) << "Starting WaitInterval timer of length "
             << wait_interval_->length.InMilliseconds() << "ms.";
   if (wait_interval_->mode == WaitInterval::THROTTLED) {
-    pending_wakeup_timer_.Start(FROM_HERE, wait_interval_->length,
-                                base::Bind(&SyncSchedulerImpl::Unthrottle,
-                                           weak_ptr_factory_.GetWeakPtr()));
+    global_wakeup_timer_.Start(FROM_HERE, wait_interval_->length,
+                               base::Bind(&SyncSchedulerImpl::Unthrottle,
+                                          weak_ptr_factory_.GetWeakPtr()));
   } else {
-    pending_wakeup_timer_.Start(
+    global_wakeup_timer_.Start(
         FROM_HERE, wait_interval_->length,
         base::Bind(&SyncSchedulerImpl::ExponentialBackoffRetry,
                    weak_ptr_factory_.GetWeakPtr()));
@@ -710,7 +697,8 @@ void SyncSchedulerImpl::Stop() {
   wait_interval_.reset();
   NotifyRetryTime(base::Time());
   poll_timer_.Stop();
-  pending_wakeup_timer_.Stop();
+  global_wakeup_timer_.Stop();
+  type_wakeup_timer_.Stop();
   pending_configure_params_.reset();
   pending_clear_params_.reset();
   if (started_)
@@ -737,7 +725,7 @@ void SyncSchedulerImpl::TrySyncCycleJobImpl() {
   JobPriority priority = next_sync_cycle_job_priority_;
   next_sync_cycle_job_priority_ = NORMAL_PRIORITY;
 
-  nudge_tracker_.SetSyncCycleStartTime(base::TimeTicks::Now());
+  nudge_tracker_.SetSyncCycleStartTime(TimeTicks::Now());
 
   DCHECK(CalledOnValidThread());
   if (mode_ == CONFIGURATION_MODE) {
@@ -753,8 +741,7 @@ void SyncSchedulerImpl::TrySyncCycleJobImpl() {
     if (nudge_tracker_.IsSyncRequired()) {
       SDVLOG(2) << "Found pending nudge job";
       DoNudgeSyncCycleJob(priority);
-    } else if (((base::TimeTicks::Now() - last_poll_reset_) >=
-                GetPollInterval())) {
+    } else if (((TimeTicks::Now() - last_poll_reset_) >= GetPollInterval())) {
       SDVLOG(2) << "Found pending poll";
       DoPollSyncCycleJob();
     }
@@ -765,7 +752,7 @@ void SyncSchedulerImpl::TrySyncCycleJobImpl() {
            cycle_context_->connection_manager()->HasInvalidAuthToken());
   }
 
-  if (IsBackingOff() && !pending_wakeup_timer_.IsRunning()) {
+  if (IsBackingOff() && !global_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.
@@ -806,19 +793,28 @@ void SyncSchedulerImpl::Unthrottle() {
   TryCanaryJob();
 }
 
-void SyncSchedulerImpl::TypeUnthrottle(base::TimeTicks unthrottle_time) {
+void SyncSchedulerImpl::TypesUnblock(TimeTicks unbackoff_time) {

[Nicolas Zea, 2016/11/09 00:21:25]

I think naming this method something like OnTypesUnblocked would be clearer.

[Gang Wu, 2016/11/10 21:56:51]

Done.

   DCHECK(CalledOnValidThread());
-  nudge_tracker_.UpdateTypeThrottlingState(unthrottle_time);
+  nudge_tracker_.UpdateTypeThrottlingAndBackoffState(unbackoff_time);
   NotifyThrottledTypesChanged(nudge_tracker_.GetThrottledTypes());
+  NotifyBackedOffTypesChanged(nudge_tracker_.GetBackedOffTypes());
 
+  // If there are some datatype still throttling or backoff, find the closest

[Nicolas Zea, 2016/11/09 00:21:25]

"still throttling or backoff" -> "still throttled or backed off"

[Gang Wu, 2016/11/10 21:56:51]

Done.

+  // time and schedule SyncSchedulerImpl::TypesUnblock with the closest time.
+  const TimeTicks now = TimeTicks::Now();
+  TimeDelta time_until_next_unblock = TimeDelta::Max();
   if (nudge_tracker_.IsAnyTypeThrottled()) {
-    const base::TimeTicks now = base::TimeTicks::Now();
-    base::TimeDelta time_until_next_unthrottle =
-        nudge_tracker_.GetTimeUntilNextUnthrottle(now);
-    type_unthrottle_timer_.Start(FROM_HERE, time_until_next_unthrottle,
-                                 base::Bind(&SyncSchedulerImpl::TypeUnthrottle,
-                                            weak_ptr_factory_.GetWeakPtr(),
-                                            now + time_until_next_unthrottle));
+    time_until_next_unblock = nudge_tracker_.GetTimeUntilNextUnthrottle(now);
+  }
+  if (nudge_tracker_.IsAnyTypeBackedOff()) {
+    time_until_next_unblock = std::min(
+        time_until_next_unblock, nudge_tracker_.GetTimeUntilNextUnbackoff(now));
+  }
+  if (!time_until_next_unblock.is_max()) {
+    type_wakeup_timer_.Start(FROM_HERE, time_until_next_unblock,
+                             base::Bind(&SyncSchedulerImpl::TypesUnblock,
+                                        weak_ptr_factory_.GetWeakPtr(),
+                                        now + time_until_next_unblock));

[Nicolas Zea, 2016/11/09 00:21:25]

as mentioned earlier, it's not clear to me why we need to pass an argument to
TypesUnlock. Given the timer will call it at the right time, we should I think
be able to rely on base::TimeTicks::Now()

[Gang Wu, 2016/11/10 21:56:51]

Done.

   }
 
   // Maybe this is a good time to run a nudge job.  Let's try it.
@@ -853,13 +849,18 @@ void SyncSchedulerImpl::NotifyThrottledTypesChanged(ModelTypeSet types) {
     observer.OnThrottledTypesChanged(types);
 }
 
+void SyncSchedulerImpl::NotifyBackedOffTypesChanged(ModelTypeSet types) {
+  for (auto& observer : *cycle_context_->listeners())
+    observer.OnBackedOffTypesChanged(types);
+}
+
 bool SyncSchedulerImpl::IsBackingOff() const {
   DCHECK(CalledOnValidThread());
   return wait_interval_.get() &&
          wait_interval_->mode == WaitInterval::EXPONENTIAL_BACKOFF;
 }
 
-void SyncSchedulerImpl::OnThrottled(const base::TimeDelta& throttle_duration) {
+void SyncSchedulerImpl::OnThrottled(const TimeDelta& throttle_duration) {
   DCHECK(CalledOnValidThread());
   wait_interval_ = base::MakeUnique<WaitInterval>(WaitInterval::THROTTLED,
                                                   throttle_duration);
@@ -867,24 +868,47 @@ void SyncSchedulerImpl::OnThrottled(const base::TimeDelta& throttle_duration) {
   NotifyThrottledTypesChanged(ModelTypeSet::All());
 }
 
-void SyncSchedulerImpl::OnTypesThrottled(
-    ModelTypeSet types,
-    const base::TimeDelta& throttle_duration) {
-  base::TimeTicks now = base::TimeTicks::Now();
+void SyncSchedulerImpl::OnTypesThrottled(ModelTypeSet types,
+                                         const TimeDelta& throttle_duration) {
+  TimeTicks now = TimeTicks::Now();
 
   SDVLOG(1) << "Throttling " << ModelTypeSetToString(types) << " for "
             << throttle_duration.InMinutes() << " minutes.";
 
   nudge_tracker_.SetTypesThrottledUntil(types, throttle_duration, now);
-  base::TimeDelta time_until_next_unthrottle =
+  TimeDelta time_until_next_unthrottle =
       nudge_tracker_.GetTimeUntilNextUnthrottle(now);
-  type_unthrottle_timer_.Start(FROM_HERE, time_until_next_unthrottle,
-                               base::Bind(&SyncSchedulerImpl::TypeUnthrottle,
-                                          weak_ptr_factory_.GetWeakPtr(),
-                                          now + time_until_next_unthrottle));
+  type_wakeup_timer_.Start(FROM_HERE, time_until_next_unthrottle,

[Nicolas Zea, 2016/11/09 00:21:25]

Why do we need a separate timer? Can't we reuse the global timer?

[Gang Wu, 2016/11/10 21:56:51]

Done.

+                           base::Bind(&SyncSchedulerImpl::TypesUnblock,
+                                      weak_ptr_factory_.GetWeakPtr(),
+                                      now + time_until_next_unthrottle));
   NotifyThrottledTypesChanged(nudge_tracker_.GetThrottledTypes());
 }
 
+void SyncSchedulerImpl::OnTypesBackedOff(ModelTypeSet types) {
+  TimeTicks now = TimeTicks::Now();
+
+  for (ModelTypeSet::Iterator type = types.First(); type.Good(); type.Inc()) {
+    TimeDelta last_backoff_time =
+        TimeDelta::FromSeconds(kInitialBackoffRetrySeconds);
+    if (nudge_tracker_.IsTypeBackedOff(type.Get())) {
+      last_backoff_time = nudge_tracker_.GetTypeLastBackoffInterval(type.Get());
+    }
+
+    TimeDelta length = delay_provider_->GetDelay(last_backoff_time);
+    nudge_tracker_.SetTypeBackedOff(type.Get(), length, now);
+    SDVLOG(1) << "Backing off " << ModelTypeToString(type.Get()) << " for "
+              << length.InSeconds() << " second.";
+  }
+  TimeDelta time_until_next_unbackoff =
+      nudge_tracker_.GetTimeUntilNextUnbackoff(now);
+  type_wakeup_timer_.Start(FROM_HERE, time_until_next_unbackoff,
+                           base::Bind(&SyncSchedulerImpl::TypesUnblock,
+                                      weak_ptr_factory_.GetWeakPtr(),
+                                      now + time_until_next_unbackoff));
+  NotifyBackedOffTypesChanged(nudge_tracker_.GetBackedOffTypes());
+}
+
 bool SyncSchedulerImpl::IsCurrentlyThrottled() {
   DCHECK(CalledOnValidThread());
   return wait_interval_.get() &&
@@ -892,7 +916,7 @@ bool SyncSchedulerImpl::IsCurrentlyThrottled() {
 }
 
 void SyncSchedulerImpl::OnReceivedShortPollIntervalUpdate(
-    const base::TimeDelta& new_interval) {
+    const TimeDelta& new_interval) {
   DCHECK(CalledOnValidThread());
   if (new_interval == syncer_short_poll_interval_seconds_)
     return;
@@ -903,7 +927,7 @@ void SyncSchedulerImpl::OnReceivedShortPollIntervalUpdate(
 }
 
 void SyncSchedulerImpl::OnReceivedLongPollIntervalUpdate(
-    const base::TimeDelta& new_interval) {
+    const TimeDelta& new_interval) {
   DCHECK(CalledOnValidThread());
   if (new_interval == syncer_long_poll_interval_seconds_)
     return;
@@ -914,7 +938,7 @@ void SyncSchedulerImpl::OnReceivedLongPollIntervalUpdate(
 }
 
 void SyncSchedulerImpl::OnReceivedCustomNudgeDelays(
-    const std::map<ModelType, base::TimeDelta>& nudge_delays) {
+    const std::map<ModelType, TimeDelta>& nudge_delays) {
   DCHECK(CalledOnValidThread());
   nudge_tracker_.OnReceivedCustomNudgeDelays(nudge_delays);
 }
@@ -940,7 +964,7 @@ void SyncSchedulerImpl::OnSyncProtocolError(
   }
 }
 
-void SyncSchedulerImpl::OnReceivedGuRetryDelay(const base::TimeDelta& delay) {
+void SyncSchedulerImpl::OnReceivedGuRetryDelay(const TimeDelta& delay) {
   nudge_tracker_.SetNextRetryTime(TimeTicks::Now() + delay);
   retry_timer_.Start(FROM_HERE, delay, this,
                      &SyncSchedulerImpl::RetryTimerCallback);