sync: GU retry with less explicit TimeTicks logic

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"
@@ skipping 152 matching lines @@
           TimeDelta::FromSeconds(kDefaultLongPollIntervalSeconds)),
       sessions_commit_delay_(
           TimeDelta::FromSeconds(kDefaultSessionsCommitDelaySeconds)),
       mode_(NORMAL_MODE),
       delay_provider_(delay_provider),
       syncer_(syncer),
       session_context_(context),
       no_scheduling_allowed_(false),
       do_poll_after_credentials_updated_(false),
       next_sync_session_job_priority_(NORMAL_PRIORITY),
+      received_pending_retry_(false),
       weak_ptr_factory_(this),
       weak_ptr_factory_for_weak_handle_(this) {
   weak_handle_this_ = MakeWeakHandle(
       weak_ptr_factory_for_weak_handle_.GetWeakPtr());
 }
 
 SyncSchedulerImpl::~SyncSchedulerImpl() {
   DCHECK(CalledOnValidThread());
   Stop();
 }
@@ skipping 44 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_.IsRetryRequired(base::TimeTicks::Now())) &&
+      (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 196 matching lines @@
     ENUM_CASE(CONFIGURATION_MODE);
     ENUM_CASE(NORMAL_MODE);
   }
   return "";
 }
 
 void SyncSchedulerImpl::DoNudgeSyncSessionJob(JobPriority priority) {
   DCHECK(CalledOnValidThread());
   DCHECK(CanRunNudgeJobNow(priority));
 
+  // Clear pending retry flag in case it was stale.
+  ClearReceivedGuRetryDelayFlag();
+
   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(base::TimeTicks::Now());
+    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;
+
+    // Set the next GU retry time, if the server requested it.
+    ProcessReceivedGuRetryDelay();

[haitaol1, 2014/01/27 23:17:07]

Previously retry may be scheduled even when sync failed (partially successful).
Retry should depend on server command only.

[rlarocque, 2014/01/28 01:06:34]

Interesting.  I think that makes a few corner cases a bit easier to handle.

   } 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);
 
@@ skipping 83 matching lines @@
 
   base::AutoReset<bool> protector(&no_scheduling_allowed_, true);
 
   SDVLOG(2) << "Retrying with types "
             << ModelTypeSetToString(GetEnabledAndUnthrottledTypes());
   scoped_ptr<SyncSession> session(SyncSession::Build(session_context_, this));
   if (syncer_->RetrySyncShare(GetEnabledAndUnthrottledTypes(),
                               session.get()) &&
       !sessions::HasSyncerError(
           session->status_controller().model_neutral_state())) {
-    nudge_tracker_.RecordSuccessfulSyncCycle(base::TimeTicks::Now());
+    nudge_tracker_.RecordSuccessfulSyncCycle();
   } else {
     HandleFailure(session->status_controller().model_neutral_state());
   }
 }
 
 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()) {
@@ skipping 86 matching lines @@
   // access token will be here.
   base::MessageLoop::current()->PostTask(FROM_HERE, base::Bind(
       &SyncSchedulerImpl::TrySyncSessionJobImpl,
       weak_ptr_factory_.GetWeakPtr()));
 }
 
 void SyncSchedulerImpl::TrySyncSessionJobImpl() {
   JobPriority priority = next_sync_session_job_priority_;
   next_sync_session_job_priority_ = NORMAL_PRIORITY;
 
+  nudge_tracker_.ToggleRetryFlagIfRequired(base::TimeTicks::Now());
+
   DCHECK(CalledOnValidThread());
   if (mode_ == CONFIGURATION_MODE) {
     if (pending_configure_params_) {
       SDVLOG(2) << "Found pending configure job";
       DoConfigurationSyncSessionJob(priority);
     }
   } else if (CanRunNudgeJobNow(priority)) {
     if (nudge_tracker_.IsSyncRequired()) {
       SDVLOG(2) << "Found pending nudge job";
       DoNudgeSyncSessionJob(priority);
-    } else if (nudge_tracker_.IsRetryRequired(base::TimeTicks::Now())) {
+    } else if (nudge_tracker_.IsRetryRequired()) {
       DoRetrySyncSessionJob();
     } 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()) {
@@ skipping 188 matching lines @@
   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::OnReceivedGuRetryDelay(const base::TimeDelta& delay) {
-  nudge_tracker_.set_next_retry_time(base::TimeTicks::Now() + delay);
-  retry_timer_.Start(FROM_HERE, delay, this,
-                     &SyncSchedulerImpl::RetryTimerCallback);
+  // We'll deal with this after the sync cycle is complete.
+  received_pending_retry_ = true;

[haitaol1, 2014/01/27 23:17:07]

Why change this? Previous implementation is simple and easy to understand. This
change is complicated and requires coordinating calls in several places. I don't
think there's a need for that.

I see your argument about NudgeTracker::IsRetryRequired() being consistent
before/after. I'm not sure that's true. E.g. if sync cycle starts before retry
timeout and finishes after, shouldn't IsRetryRequired() be false before and true
after.

[rlarocque, 2014/01/28 01:06:34]

Agreed, it is complicated.  Pavel made similar comments.  I'll have to change
this.
I was trying to prevent a scenario where the NudgeTracker was modified while the
sync cycle is in progress.  The NudgeTracker is always referenced as a 'const
NudgeTracker&' while the sync cycle is in progress.  To use the
SyncSessionDelegate to escape the sync cycle, return to this context, and modify
it anyway seems like cheating.  

Depending on some details of how the NudgeTracker keeps track of the retry state
and what the semantics of GU retries should be, this could cause subtle bugs.  

For example, let's say the syncer is fetching updates because of a GU retry.  If
the server decides to return more than one batch of items and also sets a new
retry delay, should the second sync cycle (the one that fetches the next batch
of the items) also have the is_retry flag set?  I would think yes.  If this
callback can change the NudgeTracker's IsRetryRequired(), we'd need to be very
careful about how we handle this scenario.

+  pending_retry_delay_ = delay;
+}
+
+void SyncSchedulerImpl::ProcessReceivedGuRetryDelay() {
+  if (received_pending_retry_) {
+    nudge_tracker_.SetNextRetryTime(TimeTicks::Now() + pending_retry_delay_);
+    retry_timer_.Start(FROM_HERE, pending_retry_delay_, this,
+                       &SyncSchedulerImpl::RetryTimerCallback);
+  }

[pavely, 2014/01/27 11:54:05]

Not required for this change but I would put "received_pending_retry_ = false;"
here to show that all actions were performed and next call to
ProcessReceivedGURetryDelay will be no-op.

+}
+
+void SyncSchedulerImpl::ClearReceivedGuRetryDelayFlag() {
+  received_pending_retry_ = false;
 }
 
 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