sync: Report GetUpdate triggers to the server

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 209 matching lines @@
     started_ = true;
     SendInitialSnapshot();
   }
 
   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_.IsEmpty()) {
+  if (old_mode != mode_ && mode_ == NORMAL_MODE &&
+      nudge_tracker_.SyncRequired()) {
     // We just got back to normal mode.  Let's try to run the work that was
     // queued up while we were configuring.
     DoNudgeSyncSessionJob(NORMAL_PRIORITY);
   }
 }
 
 void SyncSchedulerImpl::SendInitialSnapshot() {
   DCHECK(CalledOnValidThread());
   scoped_ptr<SyncSession> dummy(new SyncSession(
           session_context_, this, SyncSourceInfo()));
@@ skipping 106 matching lines @@
   }
 
   if (mode_ == CONFIGURATION_MODE) {
     SDVLOG(1) << "Not running nudge because we're in configuration mode.";
     return false;
   }
 
   return true;
 }
 
-void SyncSchedulerImpl::ScheduleNudgeAsync(
+void SyncSchedulerImpl::ScheduleLocalNudge(
     const TimeDelta& desired_delay,
-    NudgeSource source, ModelTypeSet types,
+    ModelTypeSet types,
     const tracked_objects::Location& nudge_location) {
   DCHECK(CalledOnValidThread());
+  DCHECK(!types.Empty());
+
   SDVLOG_LOC(nudge_location, 2)
-      << "Nudge scheduled with delay "
-      << desired_delay.InMilliseconds() << " ms, "
-      << "source " << GetNudgeSourceString(source) << ", "
-      << "types " << ModelTypeSetToString(types);
-
-  ModelTypeInvalidationMap invalidation_map =
-      ModelTypeSetToInvalidationMap(types, std::string());
-  SyncSchedulerImpl::ScheduleNudgeImpl(desired_delay,
-                                       GetUpdatesFromNudgeSource(source),
-                                       invalidation_map,
-                                       nudge_location);
+      << "Scheduling sync because of local change to "
+      << ModelTypeSetToString(types);
+  UpdateNudgeTimeRecords(types);
+  nudge_tracker_.RecordLocalChange(types);
+  ScheduleNudgeImpl(desired_delay, nudge_location);
 }
 
-void SyncSchedulerImpl::ScheduleNudgeWithStatesAsync(
+void SyncSchedulerImpl::ScheduleLocalRefreshRequest(
     const TimeDelta& desired_delay,
-    NudgeSource source, const ModelTypeInvalidationMap& invalidation_map,
+    ModelTypeSet types,
     const tracked_objects::Location& nudge_location) {
   DCHECK(CalledOnValidThread());
+  DCHECK(!types.Empty());
+
   SDVLOG_LOC(nudge_location, 2)
-      << "Nudge scheduled with delay "
-      << desired_delay.InMilliseconds() << " ms, "
-      << "source " << GetNudgeSourceString(source) << ", "
-      << "payloads "
-      << ModelTypeInvalidationMapToString(invalidation_map);
-
-  SyncSchedulerImpl::ScheduleNudgeImpl(desired_delay,
-                                       GetUpdatesFromNudgeSource(source),
-                                       invalidation_map,
-                                       nudge_location);
+      << "Scheduling sync because of local refresch request for "
+      << ModelTypeSetToString(types);
+  nudge_tracker_.RecordLocalRefreshRequest(types);
+  ScheduleNudgeImpl(desired_delay, nudge_location);
 }
 
+void SyncSchedulerImpl::ScheduleInvalidation(

[tim (not reviewing), 2013/05/06 21:29:04]

ScheduleInvalidationNudge seems better, to distinguish it from something that
sounds like it might call directly into ticl.

[rlarocque, 2013/05/07 18:45:39]

Done.

+    const TimeDelta& desired_delay,
+    const ModelTypeInvalidationMap& invalidation_map,
+    const tracked_objects::Location& nudge_location) {
+  DCHECK(CalledOnValidThread());
+  DCHECK(!invalidation_map.empty());
+
+  SDVLOG_LOC(nudge_location, 2)
+      << "Scheduling sync because we received invalidation for "
+      << ModelTypeInvalidationMapToString(invalidation_map);
+  nudge_tracker_.RecordRemoteInvalidation(invalidation_map);
+  ScheduleNudgeImpl(desired_delay, nudge_location);
+}
 
 // TODO(zea): Consider adding separate throttling/backoff for datatype
 // refresh requests.
 void SyncSchedulerImpl::ScheduleNudgeImpl(
     const TimeDelta& delay,
-    GetUpdatesCallerInfo::GetUpdatesSource source,
-    const ModelTypeInvalidationMap& invalidation_map,
     const tracked_objects::Location& nudge_location) {
   DCHECK(CalledOnValidThread());
-  DCHECK(!invalidation_map.empty()) << "Nudge scheduled for no types!";
 
   if (no_scheduling_allowed_) {
     NOTREACHED() << "Illegal to schedule job while session in progress.";
     return;
   }
 
   if (!started_) {
     SDVLOG_LOC(nudge_location, 2)
         << "Dropping nudge, scheduler is not running.";
     return;
   }
 
   SDVLOG_LOC(nudge_location, 2)
       << "In ScheduleNudgeImpl with delay "
-      << delay.InMilliseconds() << " ms, "
-      << "source " << GetUpdatesSourceString(source) << ", "
-      << "payloads "
-      << ModelTypeInvalidationMapToString(invalidation_map);
-
-  SyncSourceInfo info(source, invalidation_map);
-  UpdateNudgeTimeRecords(info);
-
-  // Coalesce the new nudge information with any existing information.
-  nudge_tracker_.CoalesceSources(info);
+      << delay.InMilliseconds() << " ms";
 
   if (!CanRunNudgeJobNow(NORMAL_PRIORITY))
     return;
 
   if (!started_) {
     SDVLOG_LOC(nudge_location, 2)
         << "Schedule not started; not running a nudge.";
     return;
   }
 
@@ skipping 28 matching lines @@
 }
 
 void SyncSchedulerImpl::DoNudgeSyncSessionJob(JobPriority priority) {
   DCHECK(CalledOnValidThread());
 
   if (!CanRunNudgeJobNow(priority))
     return;
 
   DVLOG(2) << "Will run normal mode sync cycle with routing info "
            << ModelSafeRoutingInfoToString(session_context_->routing_info());
-  SyncSession session(session_context_, this, nudge_tracker_.source_info());
+  SyncSession session(session_context_,
+                      this,
+                      nudge_tracker_.source_info(),
+                      &nudge_tracker_);
   bool premature_exit = !syncer_->SyncShare(&session, SYNCER_BEGIN, SYNCER_END);
   AdjustPolling(FORCE_RESET);
 
   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_.Reset();
+    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());
   }
 }
@@ skipping 76 matching lines @@
   AdjustPolling(UPDATE_INTERVAL);
 
   if (IsSyncingCurrentlySilenced()) {
     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();
   }
 }
 
-void SyncSchedulerImpl::UpdateNudgeTimeRecords(const SyncSourceInfo& info) {
+void SyncSchedulerImpl::UpdateNudgeTimeRecords(ModelTypeSet types) {
   DCHECK(CalledOnValidThread());
-
-  // We are interested in recording time between local nudges for datatypes.
-  // TODO(tim): Consider tracking LOCAL_NOTIFICATION as well.
-  if (info.updates_source != GetUpdatesCallerInfo::LOCAL)
-    return;
-
   base::TimeTicks now = TimeTicks::Now();
   // Update timing information for how often datatypes are triggering nudges.
-  for (ModelTypeInvalidationMap::const_iterator iter = info.types.begin();
-       iter != info.types.end();
-       ++iter) {
-    base::TimeTicks previous = last_local_nudges_by_model_type_[iter->first];
-    last_local_nudges_by_model_type_[iter->first] = now;
+  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())
       continue;
 
 #define PER_DATA_TYPE_MACRO(type_str) \
     SYNC_FREQ_HISTOGRAM("Sync.Freq" type_str, now - previous);
-    SYNC_DATA_TYPE_HISTOGRAM(iter->first);
+    SYNC_DATA_TYPE_HISTOGRAM(iter.Get());
 #undef PER_DATA_TYPE_MACRO
   }
 }
 
 void SyncSchedulerImpl::AdjustPolling(PollAdjustType type) {
   DCHECK(CalledOnValidThread());
 
   TimeDelta poll  = (!session_context_->notifications_enabled()) ?
       syncer_short_poll_interval_seconds_ :
       syncer_long_poll_interval_seconds_;
@@ skipping 71 matching lines @@
 }
 
 // This is the only place where we invoke DoSyncSessionJob with canary
 // privileges.  Everyone else should use NORMAL_PRIORITY.
 void SyncSchedulerImpl::TryCanaryJob() {
   DCHECK(CalledOnValidThread());
 
   if (mode_ == CONFIGURATION_MODE && pending_configure_params_) {
     SDVLOG(2) << "Found pending configure job; will run as canary";
     DoConfigurationSyncSessionJob(CANARY_PRIORITY);
-  } else if (mode_ == NORMAL_MODE && !nudge_tracker_.IsEmpty()) {
+  } else if (mode_ == NORMAL_MODE && nudge_tracker_.SyncRequired()) {

[tim (not reviewing), 2013/05/06 21:29:04]

Tangential question, would NORMAL_MODE be better renamed to NUDGE_MODE?

[rlarocque, 2013/05/07 18:45:39]

I actually like the name NORMAL_MODE.  I think it does a good job of
communicating the most important property of that mode (that it's the "normal"
state of the scheduler), even if it doesn't explain what the mode does.  

NUDGE_MODE doesn't make a lot of sense unless you already understand what a
"nudge" is.  

[tim (not reviewing), 2013/05/07 20:34:13]

Fair, I like NORMAL_MODE as well.

     SDVLOG(2) << "Found pending nudge job; will run as canary";
     DoNudgeSyncSessionJob(CANARY_PRIORITY);
   } else {
     SDVLOG(2) << "Found no work to do; will not run a canary";
   }
 }
 
 void SyncSchedulerImpl::PollTimerCallback() {
   DCHECK(CalledOnValidThread());
   if (no_scheduling_allowed_) {
@@ skipping 99 matching lines @@
     SDVLOG(2) << "Sync Scheduler requesting early exit.";
     syncer_->RequestEarlyExit();  // Thread-safe.
   }
   if (IsActionableError(snapshot.model_neutral_state().sync_protocol_error))
     OnActionableError(snapshot);
 }
 
 void SyncSchedulerImpl::SetNotificationsEnabled(bool notifications_enabled) {
   DCHECK(CalledOnValidThread());
   session_context_->set_notifications_enabled(notifications_enabled);
+  if (notifications_enabled) {
+    nudge_tracker_.InvalidationsEnabled();
+  } else {
+    nudge_tracker_.InvalidationsDisabled();
+  }
 }
 
 base::TimeDelta SyncSchedulerImpl::GetSessionsCommitDelay() const {
   DCHECK(CalledOnValidThread());
   return sessions_commit_delay_;
 }
 
 #undef SDVLOG_LOC
 
 #undef SDVLOG
 
 #undef SLOG
 
 #undef ENUM_CASE
 
 }  // namespace syncer