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