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