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
StartupController(ProfileSyncServiceStartBehavior start_behavior,const ProfileOAuth2TokenService * token_service,const sync_driver::SyncPrefs * sync_prefs,const SupervisedUserSigninManagerWrapper * signin,base::Closure start_backend)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
~StartupController()68 StartupController::~StartupController() {}
69
Reset(const syncer::ModelTypeSet registered_types)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
set_setup_in_progress(bool in_progress)79 void StartupController::set_setup_in_progress(bool in_progress) {
80 setup_in_progress_ = in_progress;
81 }
82
StartUp(StartUpDeferredOption deferred_option)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
OverrideFallbackTimeoutForTest(const base::TimeDelta & timeout)111 void StartupController::OverrideFallbackTimeoutForTest(
112 const base::TimeDelta& timeout) {
113 fallback_timeout_ = timeout;
114 }
115
TryStart()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
RecordTimeDeferred()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
OnFallbackStartupTimerExpired()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
GetBackendInitializationStateString() const200 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
OnDataTypeRequestsSyncStartup(syncer::ModelType type)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
239