1 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4
5 #include "components/sync/engine_impl/sync_scheduler_impl.h"
6
7 #include <cstring>
8 #include <utility>
9
10 #include "base/bind.h"
11 #include "base/location.h"
12 #include "base/logging.h"
13 #include "base/metrics/histogram_macros.h"
14 #include "base/rand_util.h"
15 #include "base/sequenced_task_runner.h"
16 #include "base/threading/platform_thread.h"
17 #include "base/threading/sequenced_task_runner_handle.h"
18 #include "components/sync/base/logging.h"
19 #include "components/sync/base/model_type.h"
20 #include "components/sync/engine/sync_engine_switches.h"
21 #include "components/sync/engine_impl/backoff_delay_provider.h"
22 #include "components/sync/protocol/sync.pb.h"
23
24 using base::TimeDelta;
25 using base::TimeTicks;
26
27 namespace syncer {
28
29 namespace {
30
IsConfigRelatedUpdateOriginValue(sync_pb::SyncEnums::GetUpdatesOrigin origin)31 bool IsConfigRelatedUpdateOriginValue(
32 sync_pb::SyncEnums::GetUpdatesOrigin origin) {
33 switch (origin) {
34 case sync_pb::SyncEnums::RECONFIGURATION:
35 case sync_pb::SyncEnums::MIGRATION:
36 case sync_pb::SyncEnums::NEW_CLIENT:
37 case sync_pb::SyncEnums::NEWLY_SUPPORTED_DATATYPE:
38 case sync_pb::SyncEnums::PROGRAMMATIC:
39 return true;
40 case sync_pb::SyncEnums::UNKNOWN_ORIGIN:
41 case sync_pb::SyncEnums::PERIODIC:
42 case sync_pb::SyncEnums::GU_TRIGGER:
43 case sync_pb::SyncEnums::RETRY:
44 return false;
45 }
46 NOTREACHED();
47 return false;
48 }
49
ShouldRequestEarlyExit(const SyncProtocolError & error)50 bool ShouldRequestEarlyExit(const SyncProtocolError& error) {
51 switch (error.error_type) {
52 case SYNC_SUCCESS:
53 case MIGRATION_DONE:
54 case THROTTLED:
55 case TRANSIENT_ERROR:
56 case PARTIAL_FAILURE:
57 return false;
58 case NOT_MY_BIRTHDAY:
59 case CLIENT_DATA_OBSOLETE:
60 case CLEAR_PENDING:
61 case DISABLED_BY_ADMIN:
62 case ENCRYPTION_OBSOLETE:
63 // If we send terminate sync early then |sync_cycle_ended| notification
64 // would not be sent. If there were no actions then |ACTIONABLE_ERROR|
65 // notification wouldnt be sent either. Then the UI layer would be left
66 // waiting forever. So assert we would send something.
67 DCHECK_NE(error.action, UNKNOWN_ACTION);
68 return true;
69 // Make UNKNOWN_ERROR a NOTREACHED. All the other error should be explicitly
70 // handled.
71 case UNKNOWN_ERROR:
72 // TODO(crbug.com/1081266): This NOTREACHED is questionable because the
73 // sync server can cause it.
74 NOTREACHED();
75 return false;
76 }
77 return false;
78 }
79
IsActionableError(const SyncProtocolError & error)80 bool IsActionableError(const SyncProtocolError& error) {
81 return (error.action != UNKNOWN_ACTION);
82 }
83
84 #define ENUM_CASE(x) \
85 case x: \
86 return #x; \
87 break;
88
89 } // namespace
90
ConfigurationParams()91 ConfigurationParams::ConfigurationParams()
92 : origin(sync_pb::SyncEnums::UNKNOWN_ORIGIN) {}
93
ConfigurationParams(sync_pb::SyncEnums::GetUpdatesOrigin origin,ModelTypeSet types_to_download,base::OnceClosure ready)94 ConfigurationParams::ConfigurationParams(
95 sync_pb::SyncEnums::GetUpdatesOrigin origin,
96 ModelTypeSet types_to_download,
97 base::OnceClosure ready)
98 : origin(origin),
99 types_to_download(types_to_download),
100 ready_task(std::move(ready)) {
101 DCHECK(!ready_task.is_null());
102 }
103
104 ConfigurationParams::ConfigurationParams(ConfigurationParams&&) = default;
105
106 ConfigurationParams& ConfigurationParams::operator=(ConfigurationParams&&) =
107 default;
108
109 ConfigurationParams::~ConfigurationParams() = default;
110
111 // Helper macros to log with the syncer thread name; useful when there
112 // are multiple syncer threads involved.
113
114 #define SDVLOG(verbose_level) DVLOG(verbose_level) << name_ << ": "
115
116 #define SDVLOG_LOC(from_here, verbose_level) \
117 DVLOG_LOC(from_here, verbose_level) << name_ << ": "
118
SyncSchedulerImpl(const std::string & name,BackoffDelayProvider * delay_provider,SyncCycleContext * context,Syncer * syncer,bool ignore_auth_credentials)119 SyncSchedulerImpl::SyncSchedulerImpl(const std::string& name,
120 BackoffDelayProvider* delay_provider,
121 SyncCycleContext* context,
122 Syncer* syncer,
123 bool ignore_auth_credentials)
124 : name_(name),
125 started_(false),
126 syncer_poll_interval_seconds_(context->poll_interval()),
127 mode_(CONFIGURATION_MODE),
128 delay_provider_(delay_provider),
129 syncer_(syncer),
130 cycle_context_(context),
131 next_sync_cycle_job_priority_(NORMAL_PRIORITY),
132 ignore_auth_credentials_(ignore_auth_credentials) {}
133
~SyncSchedulerImpl()134 SyncSchedulerImpl::~SyncSchedulerImpl() {
135 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
136
137 Stop();
138 }
139
OnCredentialsUpdated()140 void SyncSchedulerImpl::OnCredentialsUpdated() {
141 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
142
143 // If this is the first time we got credentials, or we were previously in an
144 // auth error state, then try connecting to the server now.
145 HttpResponse::ServerConnectionCode server_status =
146 cycle_context_->connection_manager()->server_status();
147 if (server_status == HttpResponse::NONE ||
148 server_status == HttpResponse::SYNC_AUTH_ERROR) {
149 OnServerConnectionErrorFixed();
150 }
151 }
152
OnConnectionStatusChange(network::mojom::ConnectionType type)153 void SyncSchedulerImpl::OnConnectionStatusChange(
154 network::mojom::ConnectionType type) {
155 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
156
157 if (type != network::mojom::ConnectionType::CONNECTION_NONE &&
158 HttpResponse::CONNECTION_UNAVAILABLE ==
159 cycle_context_->connection_manager()->server_status()) {
160 // Optimistically assume that the connection is fixed and try
161 // connecting.
162 OnServerConnectionErrorFixed();
163 }
164 }
165
OnServerConnectionErrorFixed()166 void SyncSchedulerImpl::OnServerConnectionErrorFixed() {
167 // There could be a pending nudge or configuration job in several cases:
168 //
169 // 1. We're in exponential backoff.
170 // 2. We're silenced / throttled.
171 // 3. A nudge was saved previously due to not having a valid access token.
172 // 4. A nudge was scheduled + saved while in configuration mode.
173 //
174 // In all cases except (2), we want to retry contacting the server. We
175 // call TryCanaryJob to achieve this, and note that nothing -- not even a
176 // canary job -- can bypass a THROTTLED WaitInterval. The only thing that
177 // has the authority to do that is the Unthrottle timer.
178 TryCanaryJob();
179 }
180
Start(Mode mode,base::Time last_poll_time)181 void SyncSchedulerImpl::Start(Mode mode, base::Time last_poll_time) {
182 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
183
184 std::string thread_name = base::PlatformThread::GetName();
185 if (thread_name.empty())
186 thread_name = "<Main thread>";
187 SDVLOG(2) << "Start called from thread " << thread_name << " with mode "
188 << GetModeString(mode);
189 if (!started_) {
190 started_ = true;
191 SendInitialSnapshot();
192 }
193
194 DCHECK(syncer_);
195
196 Mode old_mode = mode_;
197 mode_ = mode;
198 base::Time now = base::Time::Now();
199
200 // Only adjust the poll reset time if it was valid and in the past.
201 if (!last_poll_time.is_null() && last_poll_time <= now) {
202 // Convert from base::Time to base::TimeTicks. The reason we use Time
203 // for persisting is that TimeTicks can stop making forward progress when
204 // the machine is suspended. This implies that on resume the client might
205 // actually have miss the real poll, unless the client is restarted.
206 // Fixing that would require using an AlarmTimer though, which is only
207 // supported on certain platforms.
208 last_poll_reset_ =
209 TimeTicks::Now() -
210 (now - ComputeLastPollOnStart(last_poll_time, GetPollInterval(), now));
211 }
212
213 if (old_mode != mode_ && mode_ == NORMAL_MODE) {
214 // We just got back to normal mode. Let's try to run the work that was
215 // queued up while we were configuring.
216
217 AdjustPolling(UPDATE_INTERVAL); // Will kick start poll timer if needed.
218
219 // Update our current time before checking IsRetryRequired().
220 nudge_tracker_.SetSyncCycleStartTime(TimeTicks::Now());
221 if (nudge_tracker_.IsSyncRequired(GetEnabledAndUnblockedTypes()) &&
222 CanRunNudgeJobNow(NORMAL_PRIORITY)) {
223 TrySyncCycleJob();
224 }
225 }
226 }
227
228 // static
ComputeLastPollOnStart(base::Time last_poll,base::TimeDelta poll_interval,base::Time now)229 base::Time SyncSchedulerImpl::ComputeLastPollOnStart(
230 base::Time last_poll,
231 base::TimeDelta poll_interval,
232 base::Time now) {
233 if (base::FeatureList::IsEnabled(switches::kSyncResetPollIntervalOnStart)) {
234 return now;
235 }
236 // Handle immediate polls on start-up separately.
237 if (last_poll + poll_interval <= now) {
238 // Doing polls on start-up is generally a risk as other bugs in Chrome
239 // might cause start-ups -- potentially synchronized to a specific time.
240 // (think about a system timer waking up Chrome).
241 // To minimize that risk, we randomly delay polls on start-up to a max
242 // of 1% of the poll interval. Assuming a poll rate of 4h, that's at
243 // most 2.4 mins.
244 base::TimeDelta random_delay = base::RandDouble() * 0.01 * poll_interval;
245 return now - (poll_interval - random_delay);
246 }
247 return last_poll;
248 }
249
GetEnabledAndUnblockedTypes()250 ModelTypeSet SyncSchedulerImpl::GetEnabledAndUnblockedTypes() {
251 ModelTypeSet enabled_types = cycle_context_->GetEnabledTypes();
252 ModelTypeSet enabled_protocol_types =
253 Intersection(ProtocolTypes(), enabled_types);
254 ModelTypeSet blocked_types = nudge_tracker_.GetBlockedTypes();
255 return Difference(enabled_protocol_types, blocked_types);
256 }
257
SendInitialSnapshot()258 void SyncSchedulerImpl::SendInitialSnapshot() {
259 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
260
261 SyncCycleEvent event(SyncCycleEvent::STATUS_CHANGED);
262 event.snapshot = SyncCycle(cycle_context_, this).TakeSnapshot();
263 for (auto& observer : *cycle_context_->listeners())
264 observer.OnSyncCycleEvent(event);
265 }
266
ScheduleConfiguration(ConfigurationParams params)267 void SyncSchedulerImpl::ScheduleConfiguration(ConfigurationParams params) {
268 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
269 DCHECK(IsConfigRelatedUpdateOriginValue(params.origin));
270 DCHECK_EQ(CONFIGURATION_MODE, mode_);
271 DCHECK(!params.ready_task.is_null());
272 DCHECK(started_) << "Scheduler must be running to configure.";
273 SDVLOG(2) << "Reconfiguring syncer.";
274
275 // Only one configuration is allowed at a time. Verify we're not waiting
276 // for a pending configure job.
277 DCHECK(!pending_configure_params_);
278
279 // Only reconfigure if we have types to download.
280 if (!params.types_to_download.Empty()) {
281 pending_configure_params_ =
282 std::make_unique<ConfigurationParams>(std::move(params));
283 TrySyncCycleJob();
284 } else {
285 SDVLOG(2) << "No change in routing info, calling ready task directly.";
286 std::move(params.ready_task).Run();
287 }
288 }
289
CanRunJobNow(JobPriority priority)290 bool SyncSchedulerImpl::CanRunJobNow(JobPriority priority) {
291 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
292
293 if (IsGlobalThrottle()) {
294 SDVLOG(1) << "Unable to run a job because we're throttled.";
295 return false;
296 }
297
298 if (IsGlobalBackoff() && priority != CANARY_PRIORITY) {
299 SDVLOG(1) << "Unable to run a job because we're backing off.";
300 return false;
301 }
302
303 if (!ignore_auth_credentials_ &&
304 cycle_context_->connection_manager()->HasInvalidAccessToken()) {
305 SDVLOG(1) << "Unable to run a job because we have no valid access token.";
306 return false;
307 }
308
309 return true;
310 }
311
CanRunNudgeJobNow(JobPriority priority)312 bool SyncSchedulerImpl::CanRunNudgeJobNow(JobPriority priority) {
313 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
314
315 if (!CanRunJobNow(priority)) {
316 SDVLOG(1) << "Unable to run a nudge job right now";
317 return false;
318 }
319
320 const ModelTypeSet enabled_types = cycle_context_->GetEnabledTypes();
321 if (nudge_tracker_.GetBlockedTypes().HasAll(enabled_types)) {
322 SDVLOG(1) << "Not running a nudge because we're fully type throttled or "
323 "backed off.";
324 return false;
325 }
326
327 if (mode_ != NORMAL_MODE) {
328 SDVLOG(1) << "Not running nudge because we're not in normal mode.";
329 return false;
330 }
331
332 return true;
333 }
334
ScheduleLocalNudge(ModelTypeSet types,const base::Location & nudge_location)335 void SyncSchedulerImpl::ScheduleLocalNudge(
336 ModelTypeSet types,
337 const base::Location& nudge_location) {
338 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
339 DCHECK(!types.Empty());
340
341 SDVLOG_LOC(nudge_location, 2) << "Scheduling sync because of local change to "
342 << ModelTypeSetToString(types);
343 TimeDelta nudge_delay = nudge_tracker_.RecordLocalChange(types);
344 ScheduleNudgeImpl(nudge_delay, nudge_location);
345 }
346
ScheduleLocalRefreshRequest(ModelTypeSet types,const base::Location & nudge_location)347 void SyncSchedulerImpl::ScheduleLocalRefreshRequest(
348 ModelTypeSet types,
349 const base::Location& nudge_location) {
350 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
351 DCHECK(!types.Empty());
352
353 SDVLOG_LOC(nudge_location, 2)
354 << "Scheduling sync because of local refresh request for "
355 << ModelTypeSetToString(types);
356 TimeDelta nudge_delay = nudge_tracker_.RecordLocalRefreshRequest(types);
357 ScheduleNudgeImpl(nudge_delay, nudge_location);
358 }
359
ScheduleInvalidationNudge(ModelType model_type,std::unique_ptr<InvalidationInterface> invalidation,const base::Location & nudge_location)360 void SyncSchedulerImpl::ScheduleInvalidationNudge(
361 ModelType model_type,
362 std::unique_ptr<InvalidationInterface> invalidation,
363 const base::Location& nudge_location) {
364 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
365 DCHECK(!syncer_->IsSyncing());
366
367 SDVLOG_LOC(nudge_location, 2)
368 << "Scheduling sync because we received invalidation for "
369 << ModelTypeToString(model_type);
370 TimeDelta nudge_delay = nudge_tracker_.RecordRemoteInvalidation(
371 model_type, std::move(invalidation));
372 ScheduleNudgeImpl(nudge_delay, nudge_location);
373 }
374
ScheduleInitialSyncNudge(ModelType model_type)375 void SyncSchedulerImpl::ScheduleInitialSyncNudge(ModelType model_type) {
376 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
377 DCHECK(!syncer_->IsSyncing());
378
379 SDVLOG(2) << "Scheduling non-blocking initial sync for "
380 << ModelTypeToString(model_type);
381 nudge_tracker_.RecordInitialSyncRequired(model_type);
382 ScheduleNudgeImpl(TimeDelta::FromSeconds(0), FROM_HERE);
383 }
384
385 // TODO(zea): Consider adding separate throttling/backoff for datatype
386 // refresh requests.
ScheduleNudgeImpl(const TimeDelta & delay,const base::Location & nudge_location)387 void SyncSchedulerImpl::ScheduleNudgeImpl(
388 const TimeDelta& delay,
389 const base::Location& nudge_location) {
390 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
391
392 if (!started_) {
393 SDVLOG_LOC(nudge_location, 2)
394 << "Dropping nudge, scheduler is not running.";
395 return;
396 }
397
398 SDVLOG_LOC(nudge_location, 2) << "In ScheduleNudgeImpl with delay "
399 << delay.InMilliseconds() << " ms";
400
401 if (!CanRunNudgeJobNow(NORMAL_PRIORITY))
402 return;
403
404 if (!IsEarlierThanCurrentPendingJob(delay)) {
405 // Old job arrives sooner than this one. Don't reschedule it.
406 return;
407 }
408
409 // Either there is no existing nudge in flight or the incoming nudge should be
410 // made to arrive first (preempt) the existing nudge. We reschedule in either
411 // case.
412 SDVLOG_LOC(nudge_location, 2) << "Scheduling a nudge with "
413 << delay.InMilliseconds() << " ms delay";
414 pending_wakeup_timer_.Start(
415 nudge_location, delay,
416 base::BindOnce(&SyncSchedulerImpl::PerformDelayedNudge,
417 weak_ptr_factory_.GetWeakPtr()));
418 }
419
GetModeString(SyncScheduler::Mode mode)420 const char* SyncSchedulerImpl::GetModeString(SyncScheduler::Mode mode) {
421 switch (mode) {
422 ENUM_CASE(CONFIGURATION_MODE);
423 ENUM_CASE(NORMAL_MODE);
424 }
425 return "";
426 }
427
ForceShortNudgeDelayForTest()428 void SyncSchedulerImpl::ForceShortNudgeDelayForTest() {
429 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
430 // Set the default nudge delay to 0 because the default is used as a floor
431 // for override values, and we don't want the below override to be ignored.
432 nudge_tracker_.SetDefaultNudgeDelay(TimeDelta::FromMilliseconds(0));
433 // Only protocol types can have their delay customized.
434 const ModelTypeSet protocol_types = syncer::ProtocolTypes();
435 const base::TimeDelta short_nudge_delay = TimeDelta::FromMilliseconds(1);
436 std::map<ModelType, base::TimeDelta> nudge_delays;
437 for (ModelType type : protocol_types) {
438 nudge_delays[type] = short_nudge_delay;
439 }
440 nudge_tracker_.OnReceivedCustomNudgeDelays(nudge_delays);
441 // We should prevent further changing of nudge delays so if we use real server
442 // for integration test then server is not able to increase delays.
443 force_short_nudge_delay_for_test_ = true;
444 }
445
DoNudgeSyncCycleJob(JobPriority priority)446 void SyncSchedulerImpl::DoNudgeSyncCycleJob(JobPriority priority) {
447 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
448 DCHECK(CanRunNudgeJobNow(priority));
449
450 ModelTypeSet types = GetEnabledAndUnblockedTypes();
451 DVLOG(2) << "Will run normal mode sync cycle with types "
452 << ModelTypeSetToString(types);
453 SyncCycle cycle(cycle_context_, this);
454 bool success = syncer_->NormalSyncShare(types, &nudge_tracker_, &cycle);
455
456 if (success) {
457 // That cycle took care of any outstanding work we had.
458 SDVLOG(2) << "Nudge succeeded.";
459 // Note that some types might have become blocked (throttled) during the
460 // cycle. NudgeTracker knows of that, and won't clear any "outstanding work"
461 // flags for these types.
462 // TODO(crbug.com/930074): Consider renaming this method to
463 // RecordSuccessfulSyncCycleIfNotBlocked.
464 nudge_tracker_.RecordSuccessfulSyncCycle(types);
465 HandleSuccess();
466
467 // If this was a canary, we may need to restart the poll timer (the poll
468 // timer may have fired while the scheduler was in an error state, ignoring
469 // the poll).
470 if (!poll_timer_.IsRunning()) {
471 SDVLOG(1) << "Canary succeeded, restarting polling.";
472 AdjustPolling(UPDATE_INTERVAL);
473 }
474 } else {
475 HandleFailure(cycle.status_controller().model_neutral_state());
476 }
477 }
478
DoConfigurationSyncCycleJob(JobPriority priority)479 void SyncSchedulerImpl::DoConfigurationSyncCycleJob(JobPriority priority) {
480 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
481 DCHECK_EQ(mode_, CONFIGURATION_MODE);
482 DCHECK(pending_configure_params_ != nullptr);
483
484 if (!CanRunJobNow(priority)) {
485 SDVLOG(2) << "Unable to run configure job right now.";
486 return;
487 }
488
489 SDVLOG(2) << "Will run configure SyncShare with types "
490 << ModelTypeSetToString(
491 pending_configure_params_->types_to_download);
492 SyncCycle cycle(cycle_context_, this);
493 bool success =
494 syncer_->ConfigureSyncShare(pending_configure_params_->types_to_download,
495 pending_configure_params_->origin, &cycle);
496
497 if (success) {
498 SDVLOG(2) << "Configure succeeded.";
499 // At this point, the initial sync for the affected types has been
500 // completed. Let the nudge tracker know to avoid any spurious extra
501 // requests; see also crbug.com/926184.
502 nudge_tracker_.RecordInitialSyncDone(
503 pending_configure_params_->types_to_download);
504 std::move(pending_configure_params_->ready_task).Run();
505 pending_configure_params_.reset();
506 HandleSuccess();
507 } else {
508 HandleFailure(cycle.status_controller().model_neutral_state());
509 // Sync cycle might receive response from server that causes scheduler to
510 // stop and draws pending_configure_params_ invalid.
511 }
512 }
513
HandleSuccess()514 void SyncSchedulerImpl::HandleSuccess() {
515 // If we're here, then we successfully reached the server. End all global
516 // throttle or backoff.
517 wait_interval_.reset();
518 }
519
HandleFailure(const ModelNeutralState & model_neutral_state)520 void SyncSchedulerImpl::HandleFailure(
521 const ModelNeutralState& model_neutral_state) {
522 if (IsGlobalThrottle()) {
523 SDVLOG(2) << "Was throttled during previous sync cycle.";
524 } else {
525 // TODO(skym): Slightly bizarre, the initial SYNC_AUTH_ERROR seems to
526 // trigger exponential backoff here, although it's immediately retried with
527 // correct credentials, it'd be nice if things were a bit more clean.
528 base::TimeDelta previous_delay =
529 IsGlobalBackoff()
530 ? wait_interval_->length
531 : delay_provider_->GetInitialDelay(model_neutral_state);
532 TimeDelta next_delay = delay_provider_->GetDelay(previous_delay);
533 wait_interval_ = std::make_unique<WaitInterval>(
534 WaitInterval::EXPONENTIAL_BACKOFF, next_delay);
535 SDVLOG(2) << "Sync cycle failed. Will back off for "
536 << wait_interval_->length.InMilliseconds() << "ms.";
537 }
538 }
539
DoPollSyncCycleJob()540 void SyncSchedulerImpl::DoPollSyncCycleJob() {
541 SDVLOG(2) << "Polling with types "
542 << ModelTypeSetToString(GetEnabledAndUnblockedTypes());
543 SyncCycle cycle(cycle_context_, this);
544 bool success = syncer_->PollSyncShare(GetEnabledAndUnblockedTypes(), &cycle);
545
546 // Only restart the timer if the poll succeeded. Otherwise rely on normal
547 // failure handling to retry with backoff.
548 if (success) {
549 AdjustPolling(FORCE_RESET);
550 HandleSuccess();
551 } else {
552 HandleFailure(cycle.status_controller().model_neutral_state());
553 }
554 }
555
GetPollInterval()556 TimeDelta SyncSchedulerImpl::GetPollInterval() {
557 return syncer_poll_interval_seconds_;
558 }
559
AdjustPolling(PollAdjustType type)560 void SyncSchedulerImpl::AdjustPolling(PollAdjustType type) {
561 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
562
563 if (!started_)
564 return;
565
566 TimeDelta poll_interval = GetPollInterval();
567 TimeDelta poll_delay = poll_interval;
568 const TimeTicks now = TimeTicks::Now();
569
570 if (type == UPDATE_INTERVAL) {
571 if (!last_poll_reset_.is_null()) {
572 // Override the delay based on the last successful poll time (if it was
573 // set).
574 TimeTicks new_poll_time = poll_interval + last_poll_reset_;
575 poll_delay = new_poll_time - TimeTicks::Now();
576
577 if (poll_delay < TimeDelta()) {
578 // The desired poll time was in the past, so trigger a poll now (the
579 // timer will post the task asynchronously, so re-entrancy isn't an
580 // issue).
581 poll_delay = TimeDelta();
582 }
583 } else {
584 // There was no previous poll. Keep the delay set to the normal interval,
585 // as if we had just completed a poll.
586 DCHECK_EQ(GetPollInterval(), poll_delay);
587 last_poll_reset_ = now;
588 }
589 } else {
590 // Otherwise just restart the timer.
591 DCHECK_EQ(FORCE_RESET, type);
592 DCHECK_EQ(GetPollInterval(), poll_delay);
593 last_poll_reset_ = now;
594 }
595
596 SDVLOG(1) << "Updating polling delay to " << poll_delay.InMinutes()
597 << " minutes.";
598
599 // Adjust poll rate. Start will reset the timer if it was already running.
600 poll_timer_.Start(FROM_HERE, poll_delay, this,
601 &SyncSchedulerImpl::PollTimerCallback);
602 }
603
RestartWaiting()604 void SyncSchedulerImpl::RestartWaiting() {
605 NotifyBlockedTypesChanged();
606 if (wait_interval_) {
607 // Global throttling or backoff.
608 if (!IsEarlierThanCurrentPendingJob(wait_interval_->length)) {
609 // We check here because if we do not check here, and we already scheduled
610 // a global unblock job, we will schedule another unblock job which has
611 // same waiting time, then the job will be run later than expected. Even
612 // we did not schedule an unblock job when code reach here, it is ok since
613 // |TrySyncCycleJobImpl| will call this function after the scheduled job
614 // got run.
615 return;
616 }
617 NotifyRetryTime(base::Time::Now() + wait_interval_->length);
618 SDVLOG(2) << "Starting WaitInterval timer of length "
619 << wait_interval_->length.InMilliseconds() << "ms.";
620 if (wait_interval_->mode == WaitInterval::THROTTLED) {
621 pending_wakeup_timer_.Start(
622 FROM_HERE, wait_interval_->length,
623 base::BindOnce(&SyncSchedulerImpl::Unthrottle,
624 weak_ptr_factory_.GetWeakPtr()));
625 } else {
626 pending_wakeup_timer_.Start(
627 FROM_HERE, wait_interval_->length,
628 base::BindOnce(&SyncSchedulerImpl::ExponentialBackoffRetry,
629 weak_ptr_factory_.GetWeakPtr()));
630 }
631 } else if (nudge_tracker_.IsAnyTypeBlocked()) {
632 // Per-datatype throttled or backed off.
633 TimeDelta time_until_next_unblock =
634 nudge_tracker_.GetTimeUntilNextUnblock();
635 if (!IsEarlierThanCurrentPendingJob(time_until_next_unblock)) {
636 return;
637 }
638 NotifyRetryTime(base::Time::Now() + time_until_next_unblock);
639 pending_wakeup_timer_.Start(
640 FROM_HERE, time_until_next_unblock,
641 base::BindOnce(&SyncSchedulerImpl::OnTypesUnblocked,
642 weak_ptr_factory_.GetWeakPtr()));
643 } else {
644 NotifyRetryTime(base::Time());
645 }
646 }
647
Stop()648 void SyncSchedulerImpl::Stop() {
649 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
650 SDVLOG(2) << "Stop called";
651
652 // Kill any in-flight method calls.
653 weak_ptr_factory_.InvalidateWeakPtrs();
654 wait_interval_.reset();
655 NotifyRetryTime(base::Time());
656 poll_timer_.Stop();
657 pending_wakeup_timer_.Stop();
658 pending_configure_params_.reset();
659 if (started_)
660 started_ = false;
661 }
662
663 // This is the only place where we invoke DoSyncCycleJob with canary
664 // privileges. Everyone else should use NORMAL_PRIORITY.
TryCanaryJob()665 void SyncSchedulerImpl::TryCanaryJob() {
666 next_sync_cycle_job_priority_ = CANARY_PRIORITY;
667 SDVLOG(2) << "Attempting canary job";
668 TrySyncCycleJob();
669 }
670
TrySyncCycleJob()671 void SyncSchedulerImpl::TrySyncCycleJob() {
672 // Post call to TrySyncCycleJobImpl on current sequence. Later request for
673 // access token will be here.
674 base::SequencedTaskRunnerHandle::Get()->PostTask(
675 FROM_HERE, base::BindOnce(&SyncSchedulerImpl::TrySyncCycleJobImpl,
676 weak_ptr_factory_.GetWeakPtr()));
677 }
678
TrySyncCycleJobImpl()679 void SyncSchedulerImpl::TrySyncCycleJobImpl() {
680 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
681
682 // TODO(treib): Pass this as a parameter instead.
683 JobPriority priority = next_sync_cycle_job_priority_;
684 next_sync_cycle_job_priority_ = NORMAL_PRIORITY;
685
686 nudge_tracker_.SetSyncCycleStartTime(TimeTicks::Now());
687
688 if (mode_ == CONFIGURATION_MODE) {
689 if (pending_configure_params_) {
690 SDVLOG(2) << "Found pending configure job";
691 DoConfigurationSyncCycleJob(priority);
692 }
693 } else if (CanRunNudgeJobNow(priority)) {
694 if (nudge_tracker_.IsSyncRequired(GetEnabledAndUnblockedTypes())) {
695 SDVLOG(2) << "Found pending nudge job";
696 DoNudgeSyncCycleJob(priority);
697 } else if (((TimeTicks::Now() - last_poll_reset_) >= GetPollInterval())) {
698 SDVLOG(2) << "Found pending poll";
699 DoPollSyncCycleJob();
700 }
701 } else {
702 // We must be in an error state. Transitioning out of each of these
703 // error states should trigger a canary job.
704 DCHECK(IsGlobalThrottle() || IsGlobalBackoff() ||
705 cycle_context_->connection_manager()->HasInvalidAccessToken());
706 }
707
708 RestartWaiting();
709 }
710
PollTimerCallback()711 void SyncSchedulerImpl::PollTimerCallback() {
712 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
713 DCHECK(!syncer_->IsSyncing());
714
715 TrySyncCycleJob();
716 }
717
RetryTimerCallback()718 void SyncSchedulerImpl::RetryTimerCallback() {
719 TrySyncCycleJob();
720 }
721
Unthrottle()722 void SyncSchedulerImpl::Unthrottle() {
723 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
724 DCHECK_EQ(WaitInterval::THROTTLED, wait_interval_->mode);
725
726 // We're no longer throttled, so clear the wait interval.
727 wait_interval_.reset();
728
729 // We treat this as a 'canary' in the sense that it was originally scheduled
730 // to run some time ago, failed, and we now want to retry, versus a job that
731 // was just created (e.g via ScheduleNudgeImpl). The main implication is
732 // that we're careful to update routing info (etc) with such potentially
733 // stale canary jobs.
734 TryCanaryJob();
735 }
736
OnTypesUnblocked()737 void SyncSchedulerImpl::OnTypesUnblocked() {
738 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
739
740 nudge_tracker_.UpdateTypeThrottlingAndBackoffState();
741
742 // Maybe this is a good time to run a nudge job. Let's try it.
743 // If not a good time, reschedule a new run.
744 if (nudge_tracker_.IsSyncRequired(GetEnabledAndUnblockedTypes()) &&
745 CanRunNudgeJobNow(NORMAL_PRIORITY)) {
746 TrySyncCycleJob();
747 } else {
748 RestartWaiting();
749 }
750 }
751
PerformDelayedNudge()752 void SyncSchedulerImpl::PerformDelayedNudge() {
753 // Circumstances may have changed since we scheduled this delayed nudge.
754 // We must check to see if it's OK to run the job before we do so.
755 if (CanRunNudgeJobNow(NORMAL_PRIORITY)) {
756 TrySyncCycleJob();
757 } else {
758 // If we set |wait_interval_| while this PerformDelayedNudge was pending
759 // callback scheduled to |retry_timer_|, it's possible we didn't re-schedule
760 // because this PerformDelayedNudge was going to execute sooner. If that's
761 // the case, we need to make sure we setup to waiting callback now.
762 RestartWaiting();
763 }
764 }
765
ExponentialBackoffRetry()766 void SyncSchedulerImpl::ExponentialBackoffRetry() {
767 TryCanaryJob();
768 }
769
NotifyRetryTime(base::Time retry_time)770 void SyncSchedulerImpl::NotifyRetryTime(base::Time retry_time) {
771 for (auto& observer : *cycle_context_->listeners())
772 observer.OnRetryTimeChanged(retry_time);
773 }
774
NotifyBlockedTypesChanged()775 void SyncSchedulerImpl::NotifyBlockedTypesChanged() {
776 ModelTypeSet types = nudge_tracker_.GetBlockedTypes();
777 ModelTypeSet throttled_types;
778 ModelTypeSet backed_off_types;
779 for (ModelType type : types) {
780 WaitInterval::BlockingMode mode = nudge_tracker_.GetTypeBlockingMode(type);
781 if (mode == WaitInterval::THROTTLED) {
782 throttled_types.Put(type);
783 } else if (mode == WaitInterval::EXPONENTIAL_BACKOFF ||
784 mode == WaitInterval::EXPONENTIAL_BACKOFF_RETRYING) {
785 backed_off_types.Put(type);
786 }
787 }
788
789 for (auto& observer : *cycle_context_->listeners()) {
790 observer.OnThrottledTypesChanged(IsGlobalThrottle() ? ModelTypeSet::All()
791 : throttled_types);
792 observer.OnBackedOffTypesChanged(IsGlobalBackoff() ? ModelTypeSet::All()
793 : backed_off_types);
794 }
795 }
796
IsGlobalThrottle() const797 bool SyncSchedulerImpl::IsGlobalThrottle() const {
798 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
799 return wait_interval_ && wait_interval_->mode == WaitInterval::THROTTLED;
800 }
801
IsGlobalBackoff() const802 bool SyncSchedulerImpl::IsGlobalBackoff() const {
803 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
804 return wait_interval_ &&
805 wait_interval_->mode == WaitInterval::EXPONENTIAL_BACKOFF;
806 }
807
OnThrottled(const TimeDelta & throttle_duration)808 void SyncSchedulerImpl::OnThrottled(const TimeDelta& throttle_duration) {
809 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
810 wait_interval_ = std::make_unique<WaitInterval>(WaitInterval::THROTTLED,
811 throttle_duration);
812 for (auto& observer : *cycle_context_->listeners()) {
813 observer.OnThrottledTypesChanged(ModelTypeSet::All());
814 }
815 RestartWaiting();
816 }
817
OnTypesThrottled(ModelTypeSet types,const TimeDelta & throttle_duration)818 void SyncSchedulerImpl::OnTypesThrottled(ModelTypeSet types,
819 const TimeDelta& throttle_duration) {
820 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
821 SDVLOG(1) << "Throttling " << ModelTypeSetToString(types) << " for "
822 << throttle_duration.InMinutes() << " minutes.";
823 nudge_tracker_.SetTypesThrottledUntil(types, throttle_duration,
824 TimeTicks::Now());
825 RestartWaiting();
826 }
827
OnTypesBackedOff(ModelTypeSet types)828 void SyncSchedulerImpl::OnTypesBackedOff(ModelTypeSet types) {
829 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
830 for (ModelType type : types) {
831 TimeDelta last_backoff_time =
832 TimeDelta::FromSeconds(kInitialBackoffRetrySeconds);
833 if (nudge_tracker_.GetTypeBlockingMode(type) ==
834 WaitInterval::EXPONENTIAL_BACKOFF_RETRYING) {
835 last_backoff_time = nudge_tracker_.GetTypeLastBackoffInterval(type);
836 }
837
838 TimeDelta length = delay_provider_->GetDelay(last_backoff_time);
839 nudge_tracker_.SetTypeBackedOff(type, length, TimeTicks::Now());
840 SDVLOG(1) << "Backing off " << ModelTypeToString(type) << " for "
841 << length.InSeconds() << " second.";
842 }
843 RestartWaiting();
844 }
845
IsAnyThrottleOrBackoff()846 bool SyncSchedulerImpl::IsAnyThrottleOrBackoff() {
847 return wait_interval_ || nudge_tracker_.IsAnyTypeBlocked();
848 }
849
OnReceivedPollIntervalUpdate(const TimeDelta & new_interval)850 void SyncSchedulerImpl::OnReceivedPollIntervalUpdate(
851 const TimeDelta& new_interval) {
852 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
853
854 if (new_interval == syncer_poll_interval_seconds_)
855 return;
856 SDVLOG(1) << "Updating poll interval to " << new_interval.InMinutes()
857 << " minutes.";
858 syncer_poll_interval_seconds_ = new_interval;
859 AdjustPolling(UPDATE_INTERVAL);
860 }
861
OnReceivedCustomNudgeDelays(const std::map<ModelType,TimeDelta> & nudge_delays)862 void SyncSchedulerImpl::OnReceivedCustomNudgeDelays(
863 const std::map<ModelType, TimeDelta>& nudge_delays) {
864 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
865
866 if (force_short_nudge_delay_for_test_)
867 return;
868
869 nudge_tracker_.OnReceivedCustomNudgeDelays(nudge_delays);
870 }
871
OnReceivedClientInvalidationHintBufferSize(int size)872 void SyncSchedulerImpl::OnReceivedClientInvalidationHintBufferSize(int size) {
873 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
874
875 if (size > 0)
876 nudge_tracker_.SetHintBufferSize(size);
877 else
878 NOTREACHED() << "Hint buffer size should be > 0.";
879 }
880
OnSyncProtocolError(const SyncProtocolError & sync_protocol_error)881 void SyncSchedulerImpl::OnSyncProtocolError(
882 const SyncProtocolError& sync_protocol_error) {
883 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
884
885 if (ShouldRequestEarlyExit(sync_protocol_error)) {
886 SDVLOG(2) << "Sync Scheduler requesting early exit.";
887 Stop();
888 }
889 if (IsActionableError(sync_protocol_error)) {
890 SDVLOG(2) << "OnActionableError";
891 for (auto& observer : *cycle_context_->listeners())
892 observer.OnActionableError(sync_protocol_error);
893 }
894 }
895
OnReceivedGuRetryDelay(const TimeDelta & delay)896 void SyncSchedulerImpl::OnReceivedGuRetryDelay(const TimeDelta& delay) {
897 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
898
899 nudge_tracker_.SetNextRetryTime(TimeTicks::Now() + delay);
900 retry_timer_.Start(FROM_HERE, delay, this,
901 &SyncSchedulerImpl::RetryTimerCallback);
902 }
903
OnReceivedMigrationRequest(ModelTypeSet types)904 void SyncSchedulerImpl::OnReceivedMigrationRequest(ModelTypeSet types) {
905 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
906
907 for (auto& observer : *cycle_context_->listeners())
908 observer.OnMigrationRequested(types);
909 }
910
SetNotificationsEnabled(bool notifications_enabled)911 void SyncSchedulerImpl::SetNotificationsEnabled(bool notifications_enabled) {
912 DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
913
914 cycle_context_->set_notifications_enabled(notifications_enabled);
915 if (notifications_enabled)
916 nudge_tracker_.OnInvalidationsEnabled();
917 else
918 nudge_tracker_.OnInvalidationsDisabled();
919 }
920
IsEarlierThanCurrentPendingJob(const TimeDelta & delay)921 bool SyncSchedulerImpl::IsEarlierThanCurrentPendingJob(const TimeDelta& delay) {
922 TimeTicks incoming_run_time = TimeTicks::Now() + delay;
923 if (pending_wakeup_timer_.IsRunning() &&
924 (pending_wakeup_timer_.desired_run_time() < incoming_run_time)) {
925 // Old job arrives sooner than this one.
926 return false;
927 }
928 return true;
929 }
930
931 #undef SDVLOG_LOC
932 #undef SDVLOG
933 #undef ENUM_CASE
934
935 } // namespace syncer
936