Commit 207efe48 authored by Josh Nohle's avatar Josh Nohle Committed by Commit Bot

[Enrollment v2] Use TimeTicks for async execution time metrics

TimeTicks are better suited for measuring time durations, specifically
for tracking the amount of time a task runs. See comments at the top
of https://cs.chromium.org/chromium/src/base/time/time.h.

Bug: 899080, 933656
Change-Id: I9892e1690b194b9c91ea091a895555a88a45173a
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1775209
Commit-Queue: Josh Nohle <nohle@chromium.org>
Commit-Queue: Kyle Horimoto <khorimoto@chromium.org>
Auto-Submit: Josh Nohle <nohle@chromium.org>
Reviewed-by: default avatarKyle Horimoto <khorimoto@chromium.org>
Cr-Commit-Position: refs/heads/master@{#691749}
parent 2589455d
...@@ -9,7 +9,6 @@ ...@@ -9,7 +9,6 @@
#include "base/bind.h" #include "base/bind.h"
#include "base/memory/ptr_util.h" #include "base/memory/ptr_util.h"
#include "base/no_destructor.h" #include "base/no_destructor.h"
#include "base/time/default_clock.h"
#include "chromeos/components/multidevice/logging/logging.h" #include "chromeos/components/multidevice/logging/logging.h"
#include "chromeos/services/device_sync/async_execution_time_metrics_logger.h" #include "chromeos/services/device_sync/async_execution_time_metrics_logger.h"
#include "chromeos/services/device_sync/cryptauth_client.h" #include "chromeos/services/device_sync/cryptauth_client.h"
...@@ -442,7 +441,7 @@ void CryptAuthV2EnrollerImpl::SetState(State state) { ...@@ -442,7 +441,7 @@ void CryptAuthV2EnrollerImpl::SetState(State state) {
PA_LOG(INFO) << "Transitioning from " << state_ << " to " << state; PA_LOG(INFO) << "Transitioning from " << state_ << " to " << state;
state_ = state; state_ = state;
last_state_change_timestamp_ = base::DefaultClock::GetInstance()->Now(); last_state_change_timestamp_ = base::TimeTicks::Now();
base::Optional<base::TimeDelta> timeout_for_state = GetTimeoutForState(state); base::Optional<base::TimeDelta> timeout_for_state = GetTimeoutForState(state);
if (!timeout_for_state) if (!timeout_for_state)
...@@ -462,7 +461,7 @@ void CryptAuthV2EnrollerImpl::OnTimeout() { ...@@ -462,7 +461,7 @@ void CryptAuthV2EnrollerImpl::OnTimeout() {
DCHECK(error_code); DCHECK(error_code);
base::TimeDelta execution_time = base::TimeDelta execution_time =
base::DefaultClock::GetInstance()->Now() - last_state_change_timestamp_; base::TimeTicks::Now() - last_state_change_timestamp_;
switch (state_) { switch (state_) {
case State::kWaitingForSyncKeysResponse: case State::kWaitingForSyncKeysResponse:
RecordSyncKeysMetrics(execution_time, CryptAuthApiCallResult::kTimeout); RecordSyncKeysMetrics(execution_time, CryptAuthApiCallResult::kTimeout);
...@@ -552,9 +551,8 @@ void CryptAuthV2EnrollerImpl::OnSyncKeysSuccess( ...@@ -552,9 +551,8 @@ void CryptAuthV2EnrollerImpl::OnSyncKeysSuccess(
const SyncKeysResponse& response) { const SyncKeysResponse& response) {
DCHECK(state_ == State::kWaitingForSyncKeysResponse); DCHECK(state_ == State::kWaitingForSyncKeysResponse);
RecordSyncKeysMetrics( RecordSyncKeysMetrics(base::TimeTicks::Now() - last_state_change_timestamp_,
base::DefaultClock::GetInstance()->Now() - last_state_change_timestamp_, CryptAuthApiCallResult::kSuccess);
CryptAuthApiCallResult::kSuccess);
if (response.server_status() == SyncKeysResponse::SERVER_OVERLOADED) { if (response.server_status() == SyncKeysResponse::SERVER_OVERLOADED) {
FinishAttempt( FinishAttempt(
...@@ -731,9 +729,8 @@ CryptAuthV2EnrollerImpl::ProcessKeyCreationInstructions( ...@@ -731,9 +729,8 @@ CryptAuthV2EnrollerImpl::ProcessKeyCreationInstructions(
} }
void CryptAuthV2EnrollerImpl::OnSyncKeysFailure(NetworkRequestError error) { void CryptAuthV2EnrollerImpl::OnSyncKeysFailure(NetworkRequestError error) {
RecordSyncKeysMetrics( RecordSyncKeysMetrics(base::TimeTicks::Now() - last_state_change_timestamp_,
base::DefaultClock::GetInstance()->Now() - last_state_change_timestamp_, CryptAuthApiCallResultFromNetworkRequestError(error));
CryptAuthApiCallResultFromNetworkRequestError(error));
FinishAttempt(SyncKeysNetworkRequestErrorToResultCode(error)); FinishAttempt(SyncKeysNetworkRequestErrorToResultCode(error));
} }
...@@ -747,7 +744,7 @@ void CryptAuthV2EnrollerImpl::OnKeysCreated( ...@@ -747,7 +744,7 @@ void CryptAuthV2EnrollerImpl::OnKeysCreated(
DCHECK(state_ == State::kWaitingForKeyCreation); DCHECK(state_ == State::kWaitingForKeyCreation);
RecordKeyCreationMetrics( RecordKeyCreationMetrics(
base::DefaultClock::GetInstance()->Now() - last_state_change_timestamp_, base::TimeTicks::Now() - last_state_change_timestamp_,
CryptAuthAsyncTaskResult::kSuccess); CryptAuthAsyncTaskResult::kSuccess);
EnrollKeysRequest request; EnrollKeysRequest request;
...@@ -805,9 +802,8 @@ void CryptAuthV2EnrollerImpl::OnEnrollKeysSuccess( ...@@ -805,9 +802,8 @@ void CryptAuthV2EnrollerImpl::OnEnrollKeysSuccess(
const EnrollKeysResponse& response) { const EnrollKeysResponse& response) {
DCHECK(state_ == State::kWaitingForEnrollKeysResponse); DCHECK(state_ == State::kWaitingForEnrollKeysResponse);
RecordEnrollKeysMetrics( RecordEnrollKeysMetrics(base::TimeTicks::Now() - last_state_change_timestamp_,
base::DefaultClock::GetInstance()->Now() - last_state_change_timestamp_, CryptAuthApiCallResult::kSuccess);
CryptAuthApiCallResult::kSuccess);
for (const std::pair<CryptAuthKeyBundle::Name, CryptAuthKey>& new_key : for (const std::pair<CryptAuthKeyBundle::Name, CryptAuthKey>& new_key :
new_keys) { new_keys) {
...@@ -824,9 +820,8 @@ void CryptAuthV2EnrollerImpl::OnEnrollKeysSuccess( ...@@ -824,9 +820,8 @@ void CryptAuthV2EnrollerImpl::OnEnrollKeysSuccess(
} }
void CryptAuthV2EnrollerImpl::OnEnrollKeysFailure(NetworkRequestError error) { void CryptAuthV2EnrollerImpl::OnEnrollKeysFailure(NetworkRequestError error) {
RecordEnrollKeysMetrics( RecordEnrollKeysMetrics(base::TimeTicks::Now() - last_state_change_timestamp_,
base::DefaultClock::GetInstance()->Now() - last_state_change_timestamp_, CryptAuthApiCallResultFromNetworkRequestError(error));
CryptAuthApiCallResultFromNetworkRequestError(error));
FinishAttempt(EnrollKeysNetworkRequestErrorToResultCode(error)); FinishAttempt(EnrollKeysNetworkRequestErrorToResultCode(error));
} }
......
...@@ -160,7 +160,7 @@ class CryptAuthV2EnrollerImpl : public CryptAuthV2Enroller { ...@@ -160,7 +160,7 @@ class CryptAuthV2EnrollerImpl : public CryptAuthV2Enroller {
State state_ = State::kNotStarted; State state_ = State::kNotStarted;
// The time of the last state change. Used for execution time metrics. // The time of the last state change. Used for execution time metrics.
base::Time last_state_change_timestamp_; base::TimeTicks last_state_change_timestamp_;
// The new ClientDirective from SyncKeysResponse. This value is stored in the // The new ClientDirective from SyncKeysResponse. This value is stored in the
// CryptAuthEnrollmentResult which is passed to the // CryptAuthEnrollmentResult which is passed to the
......
...@@ -377,8 +377,8 @@ void CryptAuthV2EnrollmentManagerImpl::OnGCMRegistrationResult(bool success) { ...@@ -377,8 +377,8 @@ void CryptAuthV2EnrollmentManagerImpl::OnGCMRegistrationResult(bool success) {
CryptAuthAsyncTaskResult result = was_successful CryptAuthAsyncTaskResult result = was_successful
? CryptAuthAsyncTaskResult::kSuccess ? CryptAuthAsyncTaskResult::kSuccess
: CryptAuthAsyncTaskResult::kError; : CryptAuthAsyncTaskResult::kError;
RecordGcmRegistrationMetrics(clock_->Now() - last_state_change_timestamp_, RecordGcmRegistrationMetrics(
result); base::TimeTicks::Now() - last_state_change_timestamp_, result);
if (!was_successful) { if (!was_successful) {
OnEnrollmentFinished(CryptAuthEnrollmentResult( OnEnrollmentFinished(CryptAuthEnrollmentResult(
...@@ -405,7 +405,7 @@ void CryptAuthV2EnrollmentManagerImpl::OnClientAppMetadataFetched( ...@@ -405,7 +405,7 @@ void CryptAuthV2EnrollmentManagerImpl::OnClientAppMetadataFetched(
CryptAuthAsyncTaskResult result = success ? CryptAuthAsyncTaskResult::kSuccess CryptAuthAsyncTaskResult result = success ? CryptAuthAsyncTaskResult::kSuccess
: CryptAuthAsyncTaskResult::kError; : CryptAuthAsyncTaskResult::kError;
RecordClientAppMetadataFetchMetrics( RecordClientAppMetadataFetchMetrics(
clock_->Now() - last_state_change_timestamp_, result); base::TimeTicks::Now() - last_state_change_timestamp_, result);
if (!success) { if (!success) {
OnEnrollmentFinished( OnEnrollmentFinished(
...@@ -499,7 +499,7 @@ void CryptAuthV2EnrollmentManagerImpl::SetState(State state) { ...@@ -499,7 +499,7 @@ void CryptAuthV2EnrollmentManagerImpl::SetState(State state) {
PA_LOG(INFO) << "Transitioning from " << state_ << " to " << state; PA_LOG(INFO) << "Transitioning from " << state_ << " to " << state;
state_ = state; state_ = state;
last_state_change_timestamp_ = clock_->Now(); last_state_change_timestamp_ = base::TimeTicks::Now();
base::Optional<base::TimeDelta> timeout_for_state = GetTimeoutForState(state); base::Optional<base::TimeDelta> timeout_for_state = GetTimeoutForState(state);
if (!timeout_for_state) if (!timeout_for_state)
...@@ -518,7 +518,8 @@ void CryptAuthV2EnrollmentManagerImpl::OnTimeout() { ...@@ -518,7 +518,8 @@ void CryptAuthV2EnrollmentManagerImpl::OnTimeout() {
ResultCodeErrorFromTimeoutDuringState(state_); ResultCodeErrorFromTimeoutDuringState(state_);
DCHECK(error_code); DCHECK(error_code);
base::TimeDelta execution_time = clock_->Now() - last_state_change_timestamp_; base::TimeDelta execution_time =
base::TimeTicks::Now() - last_state_change_timestamp_;
switch (state_) { switch (state_) {
case State::kWaitingForGcmRegistration: case State::kWaitingForGcmRegistration:
RecordGcmRegistrationMetrics(execution_time, RecordGcmRegistrationMetrics(execution_time,
......
...@@ -173,7 +173,7 @@ class CryptAuthV2EnrollmentManagerImpl ...@@ -173,7 +173,7 @@ class CryptAuthV2EnrollmentManagerImpl
State state_ = State::kIdle; State state_ = State::kIdle;
// The time of the last state change. Used for execution time metrics. // The time of the last state change. Used for execution time metrics.
base::Time last_state_change_timestamp_; base::TimeTicks last_state_change_timestamp_;
base::Optional<cryptauthv2::ClientMetadata> current_client_metadata_; base::Optional<cryptauthv2::ClientMetadata> current_client_metadata_;
base::Optional<cryptauthv2::PolicyReference> base::Optional<cryptauthv2::PolicyReference>
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment