Home | History | Annotate | Download | only in sync 
      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/managed_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 ManagedUserSigninManagerWrapper* 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       weak_factory_(this) {
     53 
     54   if (CommandLine::ForCurrentProcess()->HasSwitch(
     55           switches::kSyncDeferredStartupTimeoutSeconds)) {
     56     int timeout = kDeferredInitFallbackSeconds;
     57     if (base::StringToInt(CommandLine::ForCurrentProcess()->GetSwitchValueASCII(
     58             switches::kSyncDeferredStartupTimeoutSeconds), &timeout)) {
     59       DCHECK_GE(timeout, 0);
     60       DVLOG(2) << "Sync StartupController overriding startup timeout to "
     61                << timeout << " seconds.";
     62       fallback_timeout_ = base::TimeDelta::FromSeconds(timeout);
     63     }
     64   }
     65 }
     66 
     67 StartupController::~StartupController() {}
     68 
     69 void StartupController::Reset(const syncer::ModelTypeSet registered_types) {
     70   received_start_request_ = false;
     71   start_up_time_ = base::Time();
     72   start_backend_time_ = base::Time();
     73   // Don't let previous timers affect us post-reset.
     74   weak_factory_.InvalidateWeakPtrs();
     75   registered_types_ = registered_types;
     76 }
     77 
     78 void StartupController::set_setup_in_progress(bool in_progress) {
     79   setup_in_progress_ = in_progress;
     80 }
     81 
     82 bool StartupController::StartUp(StartUpDeferredOption deferred_option) {
     83   const bool first_start = start_up_time_.is_null();
     84   if (first_start)
     85     start_up_time_ = base::Time::Now();
     86 
     87   if (deferred_option == STARTUP_BACKEND_DEFERRED &&
     88       !CommandLine::ForCurrentProcess()->HasSwitch(
     89           switches::kSyncDisableDeferredStartup) &&
     90       sync_prefs_->GetPreferredDataTypes(registered_types_)
     91           .Has(syncer::SESSIONS)) {
     92     if (first_start) {
     93       base::MessageLoop::current()->PostDelayedTask(
     94           FROM_HERE,
     95           base::Bind(&StartupController::OnFallbackStartupTimerExpired,
     96                      weak_factory_.GetWeakPtr()), fallback_timeout_);
     97     }
     98     return false;
     99   }
    100 
    101   if (start_backend_time_.is_null()) {
    102     start_backend_time_ = base::Time::Now();
    103     start_backend_.Run();
    104   }
    105 
    106   return true;
    107 }
    108 
    109 void StartupController::OverrideFallbackTimeoutForTest(
    110     const base::TimeDelta& timeout) {
    111   fallback_timeout_ = timeout;
    112 }
    113 
    114 bool StartupController::TryStart() {
    115   if (sync_prefs_->IsManaged())
    116     return false;
    117 
    118   if (sync_prefs_->IsStartSuppressed())
    119     return false;
    120 
    121   if (signin_->GetEffectiveUsername().empty())
    122     return false;
    123 
    124   if (!token_service_)
    125     return false;
    126 
    127   if (!token_service_->RefreshTokenIsAvailable(
    128           signin_->GetAccountIdToUse())) {
    129     return false;
    130   }
    131 
    132   // TODO(tim): Seems wrong to always record this histogram here...
    133   // If we got here then tokens are loaded and user logged in and sync is
    134   // enabled. If OAuth refresh token is not available then something is wrong.
    135   // When PSS requests access token, OAuth2TokenService will return error and
    136   // PSS will show error to user asking to reauthenticate.
    137   UMA_HISTOGRAM_BOOLEAN("Sync.RefreshTokenAvailable", true);
    138 
    139   // If sync setup has completed we always start the backend. If the user is in
    140   // the process of setting up now, we should start the backend to download
    141   // account control state / encryption information). If autostart is enabled,
    142   // but we haven't completed sync setup, we try to start sync anyway, since
    143   // it's possible we crashed/shutdown after logging in but before the backend
    144   // finished initializing the last time.
    145   //
    146   // However, the only time we actually need to start sync _immediately_ is if
    147   // we haven't completed sync setup and the user is in the process of setting
    148   // up - either they just signed in (for the first time) on an auto-start
    149   // platform or they explicitly kicked off sync setup, and e.g we need to
    150   // fetch account details like encryption state to populate UI. Otherwise,
    151   // for performance reasons and maximizing parallelism at chrome startup, we
    152   // defer the heavy lifting for sync init until things have calmed down.
    153   if (sync_prefs_->HasSyncSetupCompleted()) {
    154     if (!received_start_request_)
    155       return StartUp(STARTUP_BACKEND_DEFERRED);
    156     else
    157       return StartUp(STARTUP_IMMEDIATE);
    158   } else if (setup_in_progress_ || auto_start_enabled_) {
    159     // We haven't completed sync setup. Start immediately if the user explicitly
    160     // kicked this off or we're supposed to automatically start syncing.
    161     return StartUp(STARTUP_IMMEDIATE);
    162   }
    163 
    164   return false;
    165 }
    166 
    167 void StartupController::RecordTimeDeferred() {
    168   DCHECK(!start_up_time_.is_null());
    169   base::TimeDelta time_deferred = base::Time::Now() - start_up_time_;
    170   UMA_HISTOGRAM_CUSTOM_TIMES("Sync.Startup.TimeDeferred2",
    171       time_deferred,
    172       base::TimeDelta::FromSeconds(0),
    173       base::TimeDelta::FromMinutes(2),
    174       60);
    175 }
    176 
    177 void StartupController::OnFallbackStartupTimerExpired() {
    178   DCHECK(!CommandLine::ForCurrentProcess()->HasSwitch(
    179       switches::kSyncDisableDeferredStartup));
    180 
    181   if (!start_backend_time_.is_null())
    182     return;
    183 
    184   DVLOG(2) << "Sync deferred init fallback timer expired, starting backend.";
    185   RecordTimeDeferred();
    186   UMA_HISTOGRAM_ENUMERATION("Sync.Startup.DeferredInitTrigger",
    187                             TRIGGER_FALLBACK_TIMER,
    188                             MAX_TRIGGER_VALUE);
    189   received_start_request_ = true;
    190   TryStart();
    191 }
    192 
    193 std::string StartupController::GetBackendInitializationStateString() const {
    194   if (!start_backend_time_.is_null())
    195     return "Started";
    196   else if (!start_up_time_.is_null())
    197     return "Deferred";
    198   else
    199     return "Not started";
    200 }
    201 
    202 void StartupController::OnDataTypeRequestsSyncStartup(syncer::ModelType type) {
    203   if (CommandLine::ForCurrentProcess()->HasSwitch(
    204           switches::kSyncDisableDeferredStartup)) {
    205     DVLOG(2) << "Ignoring data type request for sync startup: "
    206              << syncer::ModelTypeToString(type);
    207     return;
    208   }
    209 
    210   if (!start_backend_time_.is_null())
    211     return;
    212 
    213   DVLOG(2) << "Data type requesting sync startup: "
    214            << syncer::ModelTypeToString(type);
    215   // Measure the time spent waiting for init and the type that triggered it.
    216   // We could measure the time spent deferred on a per-datatype basis, but
    217   // for now this is probably sufficient.
    218   if (!start_up_time_.is_null()) {
    219     RecordTimeDeferred();
    220     UMA_HISTOGRAM_ENUMERATION("Sync.Startup.TypeTriggeringInit",
    221                               ModelTypeToHistogramInt(type),
    222                               syncer::MODEL_TYPE_COUNT);
    223     UMA_HISTOGRAM_ENUMERATION("Sync.Startup.DeferredInitTrigger",
    224                               TRIGGER_DATA_TYPE_REQUEST,
    225                               MAX_TRIGGER_VALUE);
    226   }
    227   received_start_request_ = true;
    228   TryStart();
    229 }
    230 
    231 }  // namespace browser_sync
    232