chrome/browser/sync/startup_controller.cc

// Copyright 2014 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.

#include "chrome/browser/sync/startup_controller.h"

#include "base/command_line.h"
#include "base/message_loop/message_loop.h"
#include "base/metrics/histogram.h"
#include "base/strings/string_number_conversions.h"
#include "chrome/browser/sync/supervised_user_signin_manager_wrapper.h"
#include "chrome/common/chrome_switches.h"
#include "components/signin/core/browser/profile_oauth2_token_service.h"
#include "components/sync_driver/sync_prefs.h"

namespace browser_sync {

namespace {

// The amount of time we'll wait to initialize sync if no data type triggers
// initialization via a StartSyncFlare.
const int kDeferredInitFallbackSeconds = 10;

// Enum (for UMA, primarily) defining different events that cause us to
// exit the "deferred" state of initialization and invoke start_backend.
enum DeferredInitTrigger {
  // We have received a signal from a SyncableService requesting that sync
  // starts as soon as possible.
  TRIGGER_DATA_TYPE_REQUEST,
  // No data type requested sync to start and our fallback timer expired.
  TRIGGER_FALLBACK_TIMER,
  MAX_TRIGGER_VALUE
};

}  // namespace

StartupController::StartupController(
    ProfileSyncServiceStartBehavior start_behavior,
    const ProfileOAuth2TokenService* token_service,
    const sync_driver::SyncPrefs* sync_prefs,
    const SupervisedUserSigninManagerWrapper* signin,
    base::Closure start_backend)
    : received_start_request_(false),
      setup_in_progress_(false),
      auto_start_enabled_(start_behavior == AUTO_START),
      sync_prefs_(sync_prefs),
      token_service_(token_service),
      signin_(signin),
      start_backend_(start_backend),
      fallback_timeout_(
          base::TimeDelta::FromSeconds(kDeferredInitFallbackSeconds)),
      weak_factory_(this) {

  if (CommandLine::ForCurrentProcess()->HasSwitch(
          switches::kSyncDeferredStartupTimeoutSeconds)) {
    int timeout = kDeferredInitFallbackSeconds;
    if (base::StringToInt(CommandLine::ForCurrentProcess()->GetSwitchValueASCII(
            switches::kSyncDeferredStartupTimeoutSeconds), &timeout)) {
      DCHECK_GE(timeout, 0);
      DVLOG(2) << "Sync StartupController overriding startup timeout to "
               << timeout << " seconds.";
      fallback_timeout_ = base::TimeDelta::FromSeconds(timeout);
    }
  }
}

StartupController::~StartupController() {}

void StartupController::Reset(const syncer::ModelTypeSet registered_types) {
  received_start_request_ = false;
  start_up_time_ = base::Time();
  start_backend_time_ = base::Time();
  // Don't let previous timers affect us post-reset.
  weak_factory_.InvalidateWeakPtrs();
  registered_types_ = registered_types;
}

void StartupController::set_setup_in_progress(bool in_progress) {
  setup_in_progress_ = in_progress;
}

bool StartupController::StartUp(StartUpDeferredOption deferred_option) {
  const bool first_start = start_up_time_.is_null();
  if (first_start)
    start_up_time_ = base::Time::Now();

  if (deferred_option == STARTUP_BACKEND_DEFERRED &&
      !CommandLine::ForCurrentProcess()->HasSwitch(
          switches::kSyncDisableDeferredStartup) &&
      sync_prefs_->GetPreferredDataTypes(registered_types_)
          .Has(syncer::SESSIONS)) {
    if (first_start) {
      base::MessageLoop::current()->PostDelayedTask(
          FROM_HERE,
          base::Bind(&StartupController::OnFallbackStartupTimerExpired,
                     weak_factory_.GetWeakPtr()), fallback_timeout_);
    }
    return false;
  }

  if (start_backend_time_.is_null()) {
    start_backend_time_ = base::Time::Now();
    start_backend_.Run();
  }

  return true;
}

void StartupController::OverrideFallbackTimeoutForTest(
    const base::TimeDelta& timeout) {
  fallback_timeout_ = timeout;
}

bool StartupController::TryStart() {
  if (sync_prefs_->IsManaged())
    return false;

  if (sync_prefs_->IsStartSuppressed())
    return false;

  if (signin_->GetEffectiveUsername().empty())
    return false;

  if (!token_service_)
    return false;

  if (!token_service_->RefreshTokenIsAvailable(
          signin_->GetAccountIdToUse())) {
    return false;
  }

  // TODO(tim): Seems wrong to always record this histogram here...
  // If we got here then tokens are loaded and user logged in and sync is
  // enabled. If OAuth refresh token is not available then something is wrong.
  // When PSS requests access token, OAuth2TokenService will return error and
  // PSS will show error to user asking to reauthenticate.
  UMA_HISTOGRAM_BOOLEAN("Sync.RefreshTokenAvailable", true);

  // If sync setup has completed we always start the backend. If the user is in
  // the process of setting up now, we should start the backend to download
  // account control state / encryption information). If autostart is enabled,
  // but we haven't completed sync setup, we try to start sync anyway, since
  // it's possible we crashed/shutdown after logging in but before the backend
  // finished initializing the last time.
  //
  // However, the only time we actually need to start sync _immediately_ is if
  // we haven't completed sync setup and the user is in the process of setting
  // up - either they just signed in (for the first time) on an auto-start
  // platform or they explicitly kicked off sync setup, and e.g we need to
  // fetch account details like encryption state to populate UI. Otherwise,
  // for performance reasons and maximizing parallelism at chrome startup, we
  // defer the heavy lifting for sync init until things have calmed down.
  if (sync_prefs_->HasSyncSetupCompleted()) {
    if (!received_start_request_)
      return StartUp(STARTUP_BACKEND_DEFERRED);
    else
      return StartUp(STARTUP_IMMEDIATE);
  } else if (setup_in_progress_ || auto_start_enabled_) {
    // We haven't completed sync setup. Start immediately if the user explicitly
    // kicked this off or we're supposed to automatically start syncing.
    return StartUp(STARTUP_IMMEDIATE);
  }

  return false;
}

void StartupController::RecordTimeDeferred() {
  DCHECK(!start_up_time_.is_null());
  base::TimeDelta time_deferred = base::Time::Now() - start_up_time_;
  UMA_HISTOGRAM_CUSTOM_TIMES("Sync.Startup.TimeDeferred2",
      time_deferred,
      base::TimeDelta::FromSeconds(0),
      base::TimeDelta::FromMinutes(2),
      60);
}

void StartupController::OnFallbackStartupTimerExpired() {
  DCHECK(!CommandLine::ForCurrentProcess()->HasSwitch(
      switches::kSyncDisableDeferredStartup));

  if (!start_backend_time_.is_null())
    return;

  DVLOG(2) << "Sync deferred init fallback timer expired, starting backend.";
  RecordTimeDeferred();
  UMA_HISTOGRAM_ENUMERATION("Sync.Startup.DeferredInitTrigger",
                            TRIGGER_FALLBACK_TIMER,
                            MAX_TRIGGER_VALUE);
  received_start_request_ = true;
  TryStart();
}

std::string StartupController::GetBackendInitializationStateString() const {
  if (!start_backend_time_.is_null())
    return "Started";
  else if (!start_up_time_.is_null())
    return "Deferred";
  else
    return "Not started";
}

void StartupController::OnDataTypeRequestsSyncStartup(syncer::ModelType type) {
  if (CommandLine::ForCurrentProcess()->HasSwitch(
          switches::kSyncDisableDeferredStartup)) {
    DVLOG(2) << "Ignoring data type request for sync startup: "
             << syncer::ModelTypeToString(type);
    return;
  }

  if (!start_backend_time_.is_null())
    return;

  DVLOG(2) << "Data type requesting sync startup: "
           << syncer::ModelTypeToString(type);
  // Measure the time spent waiting for init and the type that triggered it.
  // We could measure the time spent deferred on a per-datatype basis, but
  // for now this is probably sufficient.
  if (!start_up_time_.is_null()) {
    RecordTimeDeferred();
    UMA_HISTOGRAM_ENUMERATION("Sync.Startup.TypeTriggeringInit",
                              ModelTypeToHistogramInt(type),
                              syncer::MODEL_TYPE_COUNT);
    UMA_HISTOGRAM_ENUMERATION("Sync.Startup.DeferredInitTrigger",
                              TRIGGER_DATA_TYPE_REQUEST,
                              MAX_TRIGGER_VALUE);
  }
  received_start_request_ = true;
  TryStart();
}

}  // namespace browser_sync