sync_session_durations_metrics_recorder.cc 12 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328
  1. // Copyright 2018 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. #include "components/sync/driver/sync_session_durations_metrics_recorder.h"
  5. #include <string>
  6. #include "base/metrics/histogram_functions.h"
  7. #include "base/time/time.h"
  8. #include "components/signin/public/identity_manager/accounts_in_cookie_jar_info.h"
  9. #include "components/sync/engine/cycle/sync_cycle_snapshot.h"
  10. namespace syncer {
  11. namespace {
  12. base::TimeDelta SubtractInactiveTime(base::TimeDelta total_length,
  13. base::TimeDelta inactive_time) {
  14. // Substract any time the user was inactive from our session length. If this
  15. // ends up giving the session negative length, which can happen if the feature
  16. // state changed after the user became inactive, log the length as 0.
  17. base::TimeDelta session_length = total_length - inactive_time;
  18. if (session_length.is_negative()) {
  19. session_length = base::TimeDelta();
  20. }
  21. return session_length;
  22. }
  23. void LogDuration(const std::string& histogram, base::TimeDelta session_length) {
  24. DVLOG(1) << "Logging " << histogram << " of " << session_length;
  25. base::UmaHistogramLongTimes(histogram, session_length);
  26. }
  27. } // namespace
  28. SyncSessionDurationsMetricsRecorder::SyncSessionDurationsMetricsRecorder(
  29. SyncService* sync_service,
  30. signin::IdentityManager* identity_manager)
  31. : sync_service_(sync_service), identity_manager_(identity_manager) {
  32. // |sync_service| can be null if sync is disabled by a command line flag.
  33. if (sync_service_) {
  34. sync_observation_.Observe(sync_service_.get());
  35. }
  36. identity_manager_observation_.Observe(identity_manager_.get());
  37. // Since this is created after the profile itself is created, we need to
  38. // handle the initial state.
  39. HandleSyncAndAccountChange();
  40. DCHECK_NE(account_status_, FeatureState::UNKNOWN);
  41. // Check if we already know the signed in cookies. This will trigger a fetch
  42. // if we don't have them yet.
  43. signin::AccountsInCookieJarInfo accounts_in_cookie_jar_info =
  44. identity_manager_->GetAccountsInCookieJar();
  45. if (accounts_in_cookie_jar_info.accounts_are_fresh) {
  46. OnAccountsInCookieUpdated(accounts_in_cookie_jar_info,
  47. GoogleServiceAuthError::AuthErrorNone());
  48. }
  49. DVLOG(1) << "Ready to track Session.TotalDuration metrics";
  50. }
  51. SyncSessionDurationsMetricsRecorder::~SyncSessionDurationsMetricsRecorder() {
  52. DCHECK(!total_session_timer_) << "Missing a call to OnSessionEnded().";
  53. sync_observation_.Reset();
  54. DCHECK(identity_manager_observation_.IsObserving());
  55. identity_manager_observation_.Reset();
  56. }
  57. bool SyncSessionDurationsMetricsRecorder::IsSignedIn() const {
  58. return identity_manager_->HasPrimaryAccount(signin::ConsentLevel::kSignin);
  59. }
  60. bool SyncSessionDurationsMetricsRecorder::IsSyncing() const {
  61. return account_status_ == FeatureState::ON &&
  62. sync_status_ == FeatureState::ON;
  63. }
  64. void SyncSessionDurationsMetricsRecorder::OnSessionStarted(
  65. base::TimeTicks session_start) {
  66. DVLOG(1) << "Session start";
  67. total_session_timer_ = std::make_unique<base::ElapsedTimer>();
  68. signin_session_timer_ = std::make_unique<base::ElapsedTimer>();
  69. sync_account_session_timer_ = std::make_unique<base::ElapsedTimer>();
  70. }
  71. void SyncSessionDurationsMetricsRecorder::OnSessionEnded(
  72. base::TimeDelta session_length) {
  73. DVLOG(1) << "Session end";
  74. if (!total_session_timer_) {
  75. // If there was no active session, just ignore this call.
  76. return;
  77. }
  78. if (session_length.is_zero()) {
  79. // During Profile teardown, this method is called with a |session_length|
  80. // of zero.
  81. session_length = total_session_timer_->Elapsed();
  82. }
  83. base::TimeDelta total_session_time = total_session_timer_->Elapsed();
  84. base::TimeDelta signin_session_time = signin_session_timer_->Elapsed();
  85. base::TimeDelta sync_account_session_time_ =
  86. sync_account_session_timer_->Elapsed();
  87. total_session_timer_.reset();
  88. signin_session_timer_.reset();
  89. sync_account_session_timer_.reset();
  90. base::TimeDelta total_inactivity_time = total_session_time - session_length;
  91. LogSigninDuration(
  92. SubtractInactiveTime(signin_session_time, total_inactivity_time));
  93. LogSyncAndAccountDuration(
  94. SubtractInactiveTime(sync_account_session_time_, total_inactivity_time));
  95. }
  96. void SyncSessionDurationsMetricsRecorder::OnAccountsInCookieUpdated(
  97. const signin::AccountsInCookieJarInfo& accounts_in_cookie_jar_info,
  98. const GoogleServiceAuthError& error) {
  99. DVLOG(1) << "Cookie state change. accounts: "
  100. << accounts_in_cookie_jar_info.signed_in_accounts.size()
  101. << " fresh: " << accounts_in_cookie_jar_info.accounts_are_fresh
  102. << " err: " << error.ToString();
  103. if (error.state() != GoogleServiceAuthError::NONE) {
  104. // Return early if there's an error. This should only happen if there's an
  105. // actual error getting the account list. If there are any auth errors with
  106. // the tokens, those accounts will be moved to signed_out_accounts instead.
  107. return;
  108. }
  109. DCHECK(accounts_in_cookie_jar_info.accounts_are_fresh);
  110. if (accounts_in_cookie_jar_info.signed_in_accounts.empty()) {
  111. // No signed in account.
  112. if (signin_status_ == FeatureState::ON && signin_session_timer_) {
  113. LogSigninDuration(signin_session_timer_->Elapsed());
  114. signin_session_timer_ = std::make_unique<base::ElapsedTimer>();
  115. }
  116. signin_status_ = FeatureState::OFF;
  117. } else {
  118. // There is a signed in account.
  119. if (signin_status_ == FeatureState::OFF && signin_session_timer_) {
  120. LogSigninDuration(signin_session_timer_->Elapsed());
  121. signin_session_timer_ = std::make_unique<base::ElapsedTimer>();
  122. }
  123. signin_status_ = FeatureState::ON;
  124. }
  125. }
  126. void SyncSessionDurationsMetricsRecorder::OnStateChanged(SyncService* sync) {
  127. DVLOG(1) << "Sync state change";
  128. HandleSyncAndAccountChange();
  129. }
  130. void SyncSessionDurationsMetricsRecorder::OnPrimaryAccountChanged(
  131. const signin::PrimaryAccountChangeEvent& event) {
  132. DVLOG(1) << __func__;
  133. HandleSyncAndAccountChange();
  134. }
  135. void SyncSessionDurationsMetricsRecorder::OnRefreshTokenUpdatedForAccount(
  136. const CoreAccountInfo& account_info) {
  137. DVLOG(1) << __func__;
  138. HandleSyncAndAccountChange();
  139. }
  140. void SyncSessionDurationsMetricsRecorder::OnRefreshTokenRemovedForAccount(
  141. const CoreAccountId& account_id) {
  142. DVLOG(1) << __func__;
  143. HandleSyncAndAccountChange();
  144. }
  145. void SyncSessionDurationsMetricsRecorder::OnRefreshTokensLoaded() {
  146. DVLOG(1) << __func__;
  147. HandleSyncAndAccountChange();
  148. }
  149. void SyncSessionDurationsMetricsRecorder::
  150. OnErrorStateOfRefreshTokenUpdatedForAccount(
  151. const CoreAccountInfo& account_info,
  152. const GoogleServiceAuthError& error) {
  153. DVLOG(1) << __func__;
  154. HandleSyncAndAccountChange();
  155. }
  156. bool SyncSessionDurationsMetricsRecorder::ShouldLogUpdate(
  157. FeatureState new_sync_status,
  158. FeatureState new_account_status) {
  159. bool status_change = (new_sync_status != sync_status_ ||
  160. new_account_status != account_status_);
  161. bool was_unknown = sync_status_ == FeatureState::UNKNOWN ||
  162. account_status_ == FeatureState::UNKNOWN;
  163. return sync_account_session_timer_ && status_change && !was_unknown;
  164. }
  165. void SyncSessionDurationsMetricsRecorder::UpdateSyncAndAccountStatus(
  166. FeatureState new_sync_status,
  167. FeatureState new_account_status) {
  168. DVLOG(1) << "UpdateSyncAndAccountStatus:"
  169. << " new_sync_status: " << static_cast<int>(new_sync_status)
  170. << " new_account_status: " << static_cast<int>(new_account_status);
  171. // |new_sync_status| may be unknown when there is a primary account, but
  172. // the sync engine has not yet started.
  173. DCHECK_NE(FeatureState::UNKNOWN, new_account_status);
  174. if (ShouldLogUpdate(new_sync_status, new_account_status)) {
  175. LogSyncAndAccountDuration(sync_account_session_timer_->Elapsed());
  176. sync_account_session_timer_ = std::make_unique<base::ElapsedTimer>();
  177. }
  178. sync_status_ = new_sync_status;
  179. account_status_ = new_account_status;
  180. }
  181. void SyncSessionDurationsMetricsRecorder::HandleSyncAndAccountChange() {
  182. UpdateSyncAndAccountStatus(DetermineSyncStatus(),
  183. DeterminePrimaryAccountStatus());
  184. }
  185. // static
  186. constexpr int SyncSessionDurationsMetricsRecorder::GetFeatureStates(
  187. FeatureState feature1,
  188. FeatureState feature2) {
  189. return 100 * static_cast<int>(feature1) + static_cast<int>(feature2);
  190. }
  191. void SyncSessionDurationsMetricsRecorder::LogSigninDuration(
  192. base::TimeDelta session_length) {
  193. switch (signin_status_) {
  194. case FeatureState::ON:
  195. LogDuration("Session.TotalDuration.WithAccount", session_length);
  196. break;
  197. case FeatureState::UNKNOWN:
  198. // Since the feature wasn't working for the user if we didn't know its
  199. // state, log the status as off.
  200. [[fallthrough]];
  201. case FeatureState::OFF:
  202. LogDuration("Session.TotalDuration.WithoutAccount", session_length);
  203. break;
  204. }
  205. }
  206. void SyncSessionDurationsMetricsRecorder::LogSyncAndAccountDuration(
  207. base::TimeDelta session_length) {
  208. switch (GetFeatureStates(account_status_, sync_status_)) {
  209. case GetFeatureStates(FeatureState::UNKNOWN, FeatureState::ON):
  210. case GetFeatureStates(FeatureState::UNKNOWN, FeatureState::UNKNOWN):
  211. case GetFeatureStates(FeatureState::UNKNOWN, FeatureState::OFF):
  212. NOTREACHED() << "Account status is determined in the constructor so it is"
  213. " known when LogSyncAndAccountDuration() is called";
  214. break;
  215. case GetFeatureStates(FeatureState::ON, FeatureState::ON):
  216. LogDuration("Session.TotalDuration.OptedInToSyncWithAccount",
  217. session_length);
  218. break;
  219. case GetFeatureStates(FeatureState::ON, FeatureState::UNKNOWN):
  220. // Sync engine not initialized yet, default to it being off.
  221. [[fallthrough]];
  222. case GetFeatureStates(FeatureState::ON, FeatureState::OFF):
  223. LogDuration("Session.TotalDuration.NotOptedInToSyncWithAccount",
  224. session_length);
  225. break;
  226. case GetFeatureStates(FeatureState::OFF, FeatureState::ON):
  227. LogDuration("Session.TotalDuration.OptedInToSyncWithoutAccount",
  228. session_length);
  229. break;
  230. case GetFeatureStates(FeatureState::OFF, FeatureState::UNKNOWN):
  231. // Sync engine not initialized yet, default to it being off.
  232. [[fallthrough]];
  233. case GetFeatureStates(FeatureState::OFF, FeatureState::OFF):
  234. LogDuration("Session.TotalDuration.NotOptedInToSyncWithoutAccount",
  235. session_length);
  236. break;
  237. default:
  238. NOTREACHED() << "Unexpected feature states: "
  239. << GetFeatureStates(account_status_, sync_status_);
  240. break;
  241. }
  242. }
  243. SyncSessionDurationsMetricsRecorder::FeatureState
  244. SyncSessionDurationsMetricsRecorder::DeterminePrimaryAccountStatus() const {
  245. if (!identity_manager_->HasPrimaryAccount(signin::ConsentLevel::kSignin)) {
  246. return SyncSessionDurationsMetricsRecorder::FeatureState::OFF;
  247. }
  248. CoreAccountId primary_account_id =
  249. identity_manager_->GetPrimaryAccountId(signin::ConsentLevel::kSignin);
  250. return (identity_manager_->HasAccountWithRefreshToken(primary_account_id) &&
  251. !identity_manager_->HasAccountWithRefreshTokenInPersistentErrorState(
  252. primary_account_id))
  253. ? SyncSessionDurationsMetricsRecorder::FeatureState::ON
  254. : SyncSessionDurationsMetricsRecorder::FeatureState::OFF;
  255. }
  256. SyncSessionDurationsMetricsRecorder::FeatureState
  257. SyncSessionDurationsMetricsRecorder::DetermineSyncStatus() const {
  258. if (!sync_service_ || !sync_service_->CanSyncFeatureStart()) {
  259. return FeatureState::OFF;
  260. }
  261. if (sync_service_->GetTransportState() ==
  262. SyncService::TransportState::PAUSED) {
  263. // Sync is considered to be ON even when paused.
  264. return FeatureState::ON;
  265. }
  266. if (sync_service_->IsSyncFeatureActive() &&
  267. sync_service_->HasCompletedSyncCycle()) {
  268. return FeatureState::ON;
  269. }
  270. // This branch corresponds to the case when the sync engine is initializing.
  271. //
  272. // The sync state may already be set to ON/OFF if updated previously. Return
  273. // the current sync status.
  274. //
  275. // Note: It is possible for |sync_status_| to be ON/OFF at this point. This
  276. // corresponds to sync state transitions that can happen if a turns sync on
  277. // or off. For example if during browser startup there is no signed-in user,
  278. /// then |sync_state_| is OFF. When the user turns on Sync, the sync state
  279. // is essentially unknown for a while - the current implementation keeps
  280. // previous |sync_state_|.
  281. return sync_status_;
  282. }
  283. } // namespace syncer