chrome/browser/sync/startup_controller.cc

   1 // Copyright 2014 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 "chrome/browser/sync/startup_controller.h"
   6
   7 #include "base/command_line.h"
   8 #include "base/location.h"
   9 #include "base/metrics/histogram.h"
  10 #include "base/single_thread_task_runner.h"
  11 #include "base/strings/string_number_conversions.h"
  12 #include "base/thread_task_runner_handle.h"
  13 #include "chrome/browser/sync/supervised_user_signin_manager_wrapper.h"
  14 #include "chrome/common/chrome_switches.h"
  15 #include "components/signin/core/browser/profile_oauth2_token_service.h"
  16 #include "components/sync_driver/sync_prefs.h"
  17
  18 namespace browser_sync {
  19
  20 namespace {
  21
  22 // The amount of time we'll wait to initialize sync if no data type triggers
  23 // initialization via a StartSyncFlare.
  24 const int kDeferredInitFallbackSeconds = 10;
  25
  26 // Enum (for UMA, primarily) defining different events that cause us to
  27 // exit the "deferred" state of initialization and invoke start_backend.
  28 enum DeferredInitTrigger {
  29   // We have received a signal from a SyncableService requesting that sync
  30   // starts as soon as possible.
  31   TRIGGER_DATA_TYPE_REQUEST,
  32   // No data type requested sync to start and our fallback timer expired.
  33   TRIGGER_FALLBACK_TIMER,
  34   MAX_TRIGGER_VALUE
  35 };
  36
  37 }  // namespace
  38
  39 StartupController::StartupController(
  40     ProfileSyncServiceStartBehavior start_behavior,
  41     const ProfileOAuth2TokenService* token_service,
  42     const sync_driver::SyncPrefs* sync_prefs,
  43     const SupervisedUserSigninManagerWrapper* signin,
  44     base::Closure start_backend)
  45     : received_start_request_(false),
  46       setup_in_progress_(false),
  47       auto_start_enabled_(start_behavior == AUTO_START),
  48       sync_prefs_(sync_prefs),
  49       token_service_(token_service),
  50       signin_(signin),
  51       start_backend_(start_backend),
  52       fallback_timeout_(
  53           base::TimeDelta::FromSeconds(kDeferredInitFallbackSeconds)),
  54       first_start_(true),
  55       weak_factory_(this) {
  56   if (base::CommandLine::ForCurrentProcess()->HasSwitch(
  57           switches::kSyncDeferredStartupTimeoutSeconds)) {
  58     int timeout = kDeferredInitFallbackSeconds;
  59     if (base::StringToInt(
  60             base::CommandLine::ForCurrentProcess()->GetSwitchValueASCII(
  61                 switches::kSyncDeferredStartupTimeoutSeconds),
  62             &timeout)) {
  63       DCHECK_GE(timeout, 0);
  64       DVLOG(2) << "Sync StartupController overriding startup timeout to "
  65                << timeout << " seconds.";
  66       fallback_timeout_ = base::TimeDelta::FromSeconds(timeout);
  67     }
  68   }
  69 }
  70
  71 StartupController::~StartupController() {}
  72
  73 void StartupController::Reset(const syncer::ModelTypeSet registered_types) {
  74   received_start_request_ = false;
  75   start_up_time_ = base::Time();
  76   start_backend_time_ = base::Time();
  77   // Don't let previous timers affect us post-reset.
  78   weak_factory_.InvalidateWeakPtrs();
  79   registered_types_ = registered_types;
  80 }
  81
  82 void StartupController::set_setup_in_progress(bool in_progress) {
  83   setup_in_progress_ = in_progress;
  84 }
  85
  86 bool StartupController::StartUp(StartUpDeferredOption deferred_option) {
  87   const bool first_start = start_up_time_.is_null();
  88   if (first_start)
  89     start_up_time_ = base::Time::Now();
  90
  91   if (deferred_option == STARTUP_BACKEND_DEFERRED &&
  92       !base::CommandLine::ForCurrentProcess()->HasSwitch(
  93           switches::kSyncDisableDeferredStartup) &&
  94       sync_prefs_->GetPreferredDataTypes(registered_types_)
  95           .Has(syncer::SESSIONS)) {
  96     if (first_start) {
  97       base::ThreadTaskRunnerHandle::Get()->PostDelayedTask(
  98           FROM_HERE,
  99           base::Bind(&StartupController::OnFallbackStartupTimerExpired,
 100                      weak_factory_.GetWeakPtr()),
 101           fallback_timeout_);
 102     }
 103     return false;
 104   }
 105
 106   if (start_backend_time_.is_null()) {
 107     start_backend_time_ = base::Time::Now();
 108     start_backend_.Run();
 109     first_start_ = false;
 110   }
 111
 112   return true;
 113 }
 114
 115 void StartupController::OverrideFallbackTimeoutForTest(
 116     const base::TimeDelta& timeout) {
 117   fallback_timeout_ = timeout;
 118 }
 119
 120 bool StartupController::TryStart() {
 121   if (sync_prefs_->IsManaged())
 122     return false;
 123
 124   if (!sync_prefs_->IsSyncRequested())
 125     return false;
 126
 127   if (signin_->GetEffectiveUsername().empty())
 128     return false;
 129
 130   if (!token_service_)
 131     return false;
 132
 133   if (!token_service_->RefreshTokenIsAvailable(
 134           signin_->GetAccountIdToUse())) {
 135     return false;
 136   }
 137
 138   // TODO(tim): Seems wrong to always record this histogram here...
 139   // If we got here then tokens are loaded and user logged in and sync is
 140   // enabled. If OAuth refresh token is not available then something is wrong.
 141   // When PSS requests access token, OAuth2TokenService will return error and
 142   // PSS will show error to user asking to reauthenticate.
 143   UMA_HISTOGRAM_BOOLEAN("Sync.RefreshTokenAvailable", true);
 144
 145   // If sync setup has completed we always start the backend. If the user is in
 146   // the process of setting up now, we should start the backend to download
 147   // account control state / encryption information). If autostart is enabled,
 148   // but we haven't completed sync setup, we try to start sync anyway, since
 149   // it's possible we crashed/shutdown after logging in but before the backend
 150   // finished initializing the last time.
 151   //
 152   // However, the only time we actually need to start sync _immediately_ is if
 153   // we haven't completed sync setup and the user is in the process of setting
 154   // up - either they just signed in (for the first time) on an auto-start
 155   // platform or they explicitly kicked off sync setup, and e.g we need to
 156   // fetch account details like encryption state to populate UI. Otherwise,
 157   // for performance reasons and maximizing parallelism at chrome startup, we
 158   // defer the heavy lifting for sync init until things have calmed down.
 159   if (sync_prefs_->HasSyncSetupCompleted()) {
 160     // For first time, defer start if data type hasn't requested sync to avoid
 161     // stressing browser start. If |first_start_| is false, most likely the
 162     // first attempt to start is intercepted by backup. When backup finishes,
 163     // TryStart() is called again and we should start immediately to avoid
 164     // unnecessary delay.
 165     if (!received_start_request_ && first_start_)
 166       return StartUp(STARTUP_BACKEND_DEFERRED);
 167     else
 168       return StartUp(STARTUP_IMMEDIATE);
 169   } else if (setup_in_progress_ || auto_start_enabled_) {
 170     // We haven't completed sync setup. Start immediately if the user explicitly
 171     // kicked this off or we're supposed to automatically start syncing.
 172     return StartUp(STARTUP_IMMEDIATE);
 173   }
 174
 175   return false;
 176 }
 177
 178 void StartupController::RecordTimeDeferred() {
 179   DCHECK(!start_up_time_.is_null());
 180   base::TimeDelta time_deferred = base::Time::Now() - start_up_time_;
 181   UMA_HISTOGRAM_CUSTOM_TIMES("Sync.Startup.TimeDeferred2",
 182       time_deferred,
 183       base::TimeDelta::FromSeconds(0),
 184       base::TimeDelta::FromMinutes(2),
 185       60);
 186 }
 187
 188 void StartupController::OnFallbackStartupTimerExpired() {
 189   DCHECK(!base::CommandLine::ForCurrentProcess()->HasSwitch(
 190       switches::kSyncDisableDeferredStartup));
 191
 192   if (!start_backend_time_.is_null())
 193     return;
 194
 195   DVLOG(2) << "Sync deferred init fallback timer expired, starting backend.";
 196   RecordTimeDeferred();
 197   UMA_HISTOGRAM_ENUMERATION("Sync.Startup.DeferredInitTrigger",
 198                             TRIGGER_FALLBACK_TIMER,
 199                             MAX_TRIGGER_VALUE);
 200   received_start_request_ = true;
 201   TryStart();
 202 }
 203
 204 std::string StartupController::GetBackendInitializationStateString() const {
 205   if (!start_backend_time_.is_null())
 206     return "Started";
 207   else if (!start_up_time_.is_null())
 208     return "Deferred";
 209   else
 210     return "Not started";
 211 }
 212
 213 void StartupController::OnDataTypeRequestsSyncStartup(syncer::ModelType type) {
 214   if (base::CommandLine::ForCurrentProcess()->HasSwitch(
 215           switches::kSyncDisableDeferredStartup)) {
 216     DVLOG(2) << "Ignoring data type request for sync startup: "
 217              << syncer::ModelTypeToString(type);
 218     return;
 219   }
 220
 221   if (!start_backend_time_.is_null())
 222     return;
 223
 224   DVLOG(2) << "Data type requesting sync startup: "
 225            << syncer::ModelTypeToString(type);
 226   // Measure the time spent waiting for init and the type that triggered it.
 227   // We could measure the time spent deferred on a per-datatype basis, but
 228   // for now this is probably sufficient.
 229   if (!start_up_time_.is_null()) {
 230     RecordTimeDeferred();
 231     UMA_HISTOGRAM_ENUMERATION("Sync.Startup.TypeTriggeringInit",
 232                               ModelTypeToHistogramInt(type),
 233                               syncer::MODEL_TYPE_COUNT);
 234     UMA_HISTOGRAM_ENUMERATION("Sync.Startup.DeferredInitTrigger",
 235                               TRIGGER_DATA_TYPE_REQUEST,
 236                               MAX_TRIGGER_VALUE);
 237   }
 238   received_start_request_ = true;
 239   TryStart();
 240 }
 241
 242 }  // namespace browser_sync