diff options
author | Tianjie Xu <xunchang@google.com> | 2017-10-10 17:39:03 -0700 |
---|---|---|
committer | Tianjie Xu <xunchang@google.com> | 2017-10-14 22:44:35 +0000 |
commit | 90aaa109e38f147ec4bfc772439d9949f1b237c0 (patch) | |
tree | 1a12f29bdb847a384dfacd3cce214bb3891d0ab8 | |
parent | 012aa5bc825f3efe810cc52864840ace6eae8275 (diff) |
Collect metrics for android update attempt
Report the update attempt/result metrics when an upate finishes;
and abnormally terminated updates/time to reboot when the device
reboots.
Bug: 30989466
Test: update_engine_unittest pass
Change-Id: Iea16b4e8003ae3dab5e9b7c65cf4b38d2219d203
-rw-r--r-- | Android.mk | 2 | ||||
-rw-r--r-- | metrics_utils.cc | 74 | ||||
-rw-r--r-- | metrics_utils.h | 32 | ||||
-rw-r--r-- | payload_state.cc | 102 | ||||
-rw-r--r-- | payload_state.h | 14 | ||||
-rw-r--r-- | payload_state_unittest.cc | 8 | ||||
-rw-r--r-- | update_attempter_android.cc | 158 | ||||
-rw-r--r-- | update_attempter_android.h | 36 | ||||
-rw-r--r-- | update_attempter_android_unittest.cc | 150 |
9 files changed, 465 insertions, 111 deletions
@@ -982,6 +982,8 @@ LOCAL_STATIC_LIBRARIES += \ $(ue_libupdate_engine_android_exported_static_libraries:-host=) LOCAL_SHARED_LIBRARIES += \ $(ue_libupdate_engine_android_exported_shared_libraries:-host=) +LOCAL_SRC_FILES += \ + update_attempter_android_unittest.cc endif # local_use_omaha == 1 ifeq ($(local_use_chrome_network_proxy),1) LOCAL_SRC_FILES += \ diff --git a/metrics_utils.cc b/metrics_utils.cc index 263bacd2..5cff2938 100644 --- a/metrics_utils.cc +++ b/metrics_utils.cc @@ -21,7 +21,8 @@ #include <base/time/time.h> #include "update_engine/common/clock_interface.h" -#include "update_engine/common/prefs_interface.h" +#include "update_engine/common/constants.h" +#include "update_engine/common/utils.h" #include "update_engine/system_state.h" using base::Time; @@ -305,5 +306,76 @@ bool MonotonicDurationHelper(SystemState* system_state, return ret; } +int64_t GetPersistedValue(const std::string& key, PrefsInterface* prefs) { + CHECK(prefs); + if (!prefs->Exists(key)) + return 0; + + int64_t stored_value; + if (!prefs->GetInt64(key, &stored_value)) + return 0; + + if (stored_value < 0) { + LOG(ERROR) << key << ": Invalid value (" << stored_value + << ") in persisted state. Defaulting to 0"; + return 0; + } + + return stored_value; +} + +void SetNumReboots(int64_t num_reboots, PrefsInterface* prefs) { + CHECK(prefs); + prefs->SetInt64(kPrefsNumReboots, num_reboots); + LOG(INFO) << "Number of Reboots during current update attempt = " + << num_reboots; +} + +void SetPayloadAttemptNumber(int64_t payload_attempt_number, + PrefsInterface* prefs) { + CHECK(prefs); + prefs->SetInt64(kPrefsPayloadAttemptNumber, payload_attempt_number); + LOG(INFO) << "Payload Attempt Number = " << payload_attempt_number; +} + +void SetSystemUpdatedMarker(ClockInterface* clock, PrefsInterface* prefs) { + CHECK(prefs); + CHECK(clock); + Time update_finish_time = clock->GetMonotonicTime(); + prefs->SetInt64(kPrefsSystemUpdatedMarker, + update_finish_time.ToInternalValue()); + LOG(INFO) << "Updated Marker = " << utils::ToString(update_finish_time); +} + +void SetUpdateTimestampStart(const Time& update_start_time, + PrefsInterface* prefs) { + CHECK(prefs); + prefs->SetInt64(kPrefsUpdateTimestampStart, + update_start_time.ToInternalValue()); + LOG(INFO) << "Update Timestamp Start = " + << utils::ToString(update_start_time); +} + +bool LoadAndReportTimeToReboot(MetricsReporterInterface* metrics_reporter, + PrefsInterface* prefs, + ClockInterface* clock) { + CHECK(prefs); + CHECK(clock); + int64_t stored_value = GetPersistedValue(kPrefsSystemUpdatedMarker, prefs); + if (stored_value == 0) + return false; + + Time system_updated_at = Time::FromInternalValue(stored_value); + base::TimeDelta time_to_reboot = + clock->GetMonotonicTime() - system_updated_at; + if (time_to_reboot.ToInternalValue() < 0) { + LOG(ERROR) << "time_to_reboot is negative - system_updated_at: " + << utils::ToString(system_updated_at); + return false; + } + metrics_reporter->ReportTimeToReboot(time_to_reboot.InMinutes()); + return true; +} + } // namespace metrics_utils } // namespace chromeos_update_engine diff --git a/metrics_utils.h b/metrics_utils.h index 2d62dc07..d08cc4a7 100644 --- a/metrics_utils.h +++ b/metrics_utils.h @@ -17,11 +17,16 @@ #ifndef UPDATE_ENGINE_METRICS_UTILS_H_ #define UPDATE_ENGINE_METRICS_UTILS_H_ +#include <string> + #include <base/time/time.h> +#include "update_engine/common/clock_interface.h" #include "update_engine/common/error_code.h" +#include "update_engine/common/prefs_interface.h" #include "update_engine/connection_utils.h" #include "update_engine/metrics_constants.h" +#include "update_engine/metrics_reporter_interface.h" namespace chromeos_update_engine { @@ -68,6 +73,33 @@ bool MonotonicDurationHelper(SystemState* system_state, int64_t* storage, base::TimeDelta* out_duration); +// Returns the persisted value from prefs for the given key. It also +// validates that the value returned is non-negative. +int64_t GetPersistedValue(const std::string& key, PrefsInterface* prefs); + +// Persists the reboot count of the update attempt to |kPrefsNumReboots|. +void SetNumReboots(int64_t num_reboots, PrefsInterface* prefs); + +// Persists the payload attempt number to |kPrefsPayloadAttemptNumber|. +void SetPayloadAttemptNumber(int64_t payload_attempt_number, + PrefsInterface* prefs); + +// Persists the finished time of an update to the |kPrefsSystemUpdatedMarker|. +void SetSystemUpdatedMarker(ClockInterface* clock, PrefsInterface* prefs); + +// Persists the start time of an update to |kPrefsUpdateTimestampStart|. +void SetUpdateTimestampStart(const base::Time& update_start_time, + PrefsInterface* prefs); + +// Called at program startup if the device booted into a new update. +// The |time_to_reboot| parameter contains the (monotonic-clock) duration +// from when the update successfully completed (the value in +// |kPrefsSystemUpdatedMarker|) until the device was booted into the update +// (current monotonic-clock time). +bool LoadAndReportTimeToReboot(MetricsReporterInterface* metrics_reporter, + PrefsInterface* prefs, + ClockInterface* clock); + } // namespace metrics_utils } // namespace chromeos_update_engine diff --git a/payload_state.cc b/payload_state.cc index 410a0bfb..1ec32c51 100644 --- a/payload_state.cc +++ b/payload_state.cc @@ -45,6 +45,8 @@ using std::string; namespace chromeos_update_engine { +using metrics_utils::GetPersistedValue; + const TimeDelta PayloadState::kDurationSlack = TimeDelta::FromSeconds(600); // We want to upperbound backoffs to 16 days @@ -247,7 +249,7 @@ void PayloadState::UpdateSucceeded() { SetNumResponsesSeen(0); SetPayloadIndex(0); - CreateSystemUpdatedMarkerFile(); + metrics_utils::SetSystemUpdatedMarker(system_state_->clock(), prefs_); } void PayloadState::UpdateFailed(ErrorCode error) { @@ -762,11 +764,8 @@ void PayloadState::UpdateNumReboots() { } void PayloadState::SetNumReboots(uint32_t num_reboots) { - CHECK(prefs_); num_reboots_ = num_reboots; - prefs_->SetInt64(kPrefsNumReboots, num_reboots); - LOG(INFO) << "Number of Reboots during current update attempt = " - << num_reboots_; + metrics_utils::SetNumReboots(num_reboots, prefs_); } void PayloadState::ResetPersistedState() { @@ -803,24 +802,6 @@ void PayloadState::ResetDownloadSourcesOnNewUpdate() { } } -int64_t PayloadState::GetPersistedValue(const string& key) { - CHECK(prefs_); - if (!prefs_->Exists(key)) - return 0; - - int64_t stored_value; - if (!prefs_->GetInt64(key, &stored_value)) - return 0; - - if (stored_value < 0) { - LOG(ERROR) << key << ": Invalid value (" << stored_value - << ") in persisted state. Defaulting to 0"; - return 0; - } - - return stored_value; -} - string PayloadState::CalculateResponseSignature() { string response_sign; for (size_t i = 0; i < response_.packages.size(); i++) { @@ -871,19 +852,18 @@ void PayloadState::SetResponseSignature(const string& response_signature) { } void PayloadState::LoadPayloadAttemptNumber() { - SetPayloadAttemptNumber(GetPersistedValue(kPrefsPayloadAttemptNumber)); + SetPayloadAttemptNumber( + GetPersistedValue(kPrefsPayloadAttemptNumber, prefs_)); } void PayloadState::LoadFullPayloadAttemptNumber() { - SetFullPayloadAttemptNumber(GetPersistedValue( - kPrefsFullPayloadAttemptNumber)); + SetFullPayloadAttemptNumber( + GetPersistedValue(kPrefsFullPayloadAttemptNumber, prefs_)); } void PayloadState::SetPayloadAttemptNumber(int payload_attempt_number) { - CHECK(prefs_); payload_attempt_number_ = payload_attempt_number; - LOG(INFO) << "Payload Attempt Number = " << payload_attempt_number_; - prefs_->SetInt64(kPrefsPayloadAttemptNumber, payload_attempt_number_); + metrics_utils::SetPayloadAttemptNumber(payload_attempt_number, prefs_); } void PayloadState::SetFullPayloadAttemptNumber( @@ -910,7 +890,7 @@ bool PayloadState::NextPayload() { } void PayloadState::LoadUrlIndex() { - SetUrlIndex(GetPersistedValue(kPrefsCurrentUrlIndex)); + SetUrlIndex(GetPersistedValue(kPrefsCurrentUrlIndex, prefs_)); } void PayloadState::SetUrlIndex(uint32_t url_index) { @@ -925,8 +905,8 @@ void PayloadState::SetUrlIndex(uint32_t url_index) { } void PayloadState::LoadScatteringWaitPeriod() { - SetScatteringWaitPeriod( - TimeDelta::FromSeconds(GetPersistedValue(kPrefsWallClockWaitPeriod))); + SetScatteringWaitPeriod(TimeDelta::FromSeconds( + GetPersistedValue(kPrefsWallClockWaitPeriod, prefs_))); } void PayloadState::SetScatteringWaitPeriod(TimeDelta wait_period) { @@ -943,7 +923,7 @@ void PayloadState::SetScatteringWaitPeriod(TimeDelta wait_period) { } void PayloadState::LoadUrlSwitchCount() { - SetUrlSwitchCount(GetPersistedValue(kPrefsUrlSwitchCount)); + SetUrlSwitchCount(GetPersistedValue(kPrefsUrlSwitchCount, prefs_)); } void PayloadState::SetUrlSwitchCount(uint32_t url_switch_count) { @@ -954,7 +934,7 @@ void PayloadState::SetUrlSwitchCount(uint32_t url_switch_count) { } void PayloadState::LoadUrlFailureCount() { - SetUrlFailureCount(GetPersistedValue(kPrefsCurrentUrlFailureCount)); + SetUrlFailureCount(GetPersistedValue(kPrefsCurrentUrlFailureCount, prefs_)); } void PayloadState::SetUrlFailureCount(uint32_t url_failure_count) { @@ -1037,12 +1017,8 @@ void PayloadState::LoadUpdateTimestampStart() { } void PayloadState::SetUpdateTimestampStart(const Time& value) { - CHECK(prefs_); update_timestamp_start_ = value; - prefs_->SetInt64(kPrefsUpdateTimestampStart, - update_timestamp_start_.ToInternalValue()); - LOG(INFO) << "Update Timestamp Start = " - << utils::ToString(update_timestamp_start_); + metrics_utils::SetUpdateTimestampStart(value, prefs_); } void PayloadState::SetUpdateTimestampEnd(const Time& value) { @@ -1088,7 +1064,7 @@ void PayloadState::LoadUpdateDurationUptime() { } void PayloadState::LoadNumReboots() { - SetNumReboots(GetPersistedValue(kPrefsNumReboots)); + SetNumReboots(GetPersistedValue(kPrefsNumReboots, prefs_)); } void PayloadState::LoadRollbackVersion() { @@ -1140,7 +1116,7 @@ string PayloadState::GetPrefsKey(const string& prefix, DownloadSource source) { void PayloadState::LoadCurrentBytesDownloaded(DownloadSource source) { string key = GetPrefsKey(kPrefsCurrentBytesDownloaded, source); - SetCurrentBytesDownloaded(source, GetPersistedValue(key), true); + SetCurrentBytesDownloaded(source, GetPersistedValue(key, prefs_), true); } void PayloadState::SetCurrentBytesDownloaded( @@ -1164,7 +1140,7 @@ void PayloadState::SetCurrentBytesDownloaded( void PayloadState::LoadTotalBytesDownloaded(DownloadSource source) { string key = GetPrefsKey(kPrefsTotalBytesDownloaded, source); - SetTotalBytesDownloaded(source, GetPersistedValue(key), true); + SetTotalBytesDownloaded(source, GetPersistedValue(key, prefs_), true); } void PayloadState::SetTotalBytesDownloaded( @@ -1188,7 +1164,7 @@ void PayloadState::SetTotalBytesDownloaded( } void PayloadState::LoadNumResponsesSeen() { - SetNumResponsesSeen(GetPersistedValue(kPrefsNumResponsesSeen)); + SetNumResponsesSeen(GetPersistedValue(kPrefsNumResponsesSeen, prefs_)); } void PayloadState::SetNumResponsesSeen(int num_responses_seen) { @@ -1229,18 +1205,6 @@ void PayloadState::ComputeCandidateUrls() { } } -void PayloadState::CreateSystemUpdatedMarkerFile() { - CHECK(prefs_); - int64_t value = system_state_->clock()->GetWallclockTime().ToInternalValue(); - prefs_->SetInt64(kPrefsSystemUpdatedMarker, value); -} - -void PayloadState::BootedIntoUpdate(TimeDelta time_to_reboot) { - // Send |time_to_reboot| as a UMA stat. - system_state_->metrics_reporter()->ReportTimeToReboot( - time_to_reboot.InMinutes()); -} - void PayloadState::UpdateEngineStarted() { // Flush previous state from abnormal attempt failure, if any. ReportAndClearPersistedAttemptMetrics(); @@ -1250,24 +1214,11 @@ void PayloadState::UpdateEngineStarted() { if (!system_state_->system_rebooted()) return; - // Figure out if we just booted into a new update - if (prefs_->Exists(kPrefsSystemUpdatedMarker)) { - int64_t stored_value; - if (prefs_->GetInt64(kPrefsSystemUpdatedMarker, &stored_value)) { - Time system_updated_at = Time::FromInternalValue(stored_value); - if (!system_updated_at.is_null()) { - TimeDelta time_to_reboot = - system_state_->clock()->GetWallclockTime() - system_updated_at; - if (time_to_reboot.ToInternalValue() < 0) { - LOG(ERROR) << "time_to_reboot is negative - system_updated_at: " - << utils::ToString(system_updated_at); - } else { - BootedIntoUpdate(time_to_reboot); - } - } - } - prefs_->Delete(kPrefsSystemUpdatedMarker); - } + // Report time_to_reboot if we booted into a new update. + metrics_utils::LoadAndReportTimeToReboot( + system_state_->metrics_reporter(), prefs_, system_state_->clock()); + prefs_->Delete(kPrefsSystemUpdatedMarker); + // Check if it is needed to send metrics about a failed reboot into a new // version. ReportFailedBootIfNeeded(); @@ -1359,7 +1310,7 @@ void PayloadState::SetP2PNumAttempts(int value) { } void PayloadState::LoadP2PNumAttempts() { - SetP2PNumAttempts(GetPersistedValue(kPrefsP2PNumAttempts)); + SetP2PNumAttempts(GetPersistedValue(kPrefsP2PNumAttempts, prefs_)); } Time PayloadState::GetP2PFirstAttemptTimestamp() { @@ -1376,7 +1327,8 @@ void PayloadState::SetP2PFirstAttemptTimestamp(const Time& time) { } void PayloadState::LoadP2PFirstAttemptTimestamp() { - int64_t stored_value = GetPersistedValue(kPrefsP2PFirstAttemptTimestamp); + int64_t stored_value = + GetPersistedValue(kPrefsP2PFirstAttemptTimestamp, prefs_); Time stored_time = Time::FromInternalValue(stored_value); SetP2PFirstAttemptTimestamp(stored_time); } diff --git a/payload_state.h b/payload_state.h index 98f21e85..24e99001 100644 --- a/payload_state.h +++ b/payload_state.h @@ -17,6 +17,7 @@ #ifndef UPDATE_ENGINE_PAYLOAD_STATE_H_ #define UPDATE_ENGINE_PAYLOAD_STATE_H_ +#include <algorithm> #include <string> #include <vector> @@ -240,10 +241,6 @@ class PayloadState : public PayloadStateInterface { // reset on a new update. void ResetDownloadSourcesOnNewUpdate(); - // Returns the persisted value from prefs_ for the given key. It also - // validates that the value returned is non-negative. - int64_t GetPersistedValue(const std::string& key); - // Calculates the response "signature", which is basically a string composed // of the subset of the fields in the current response that affect the // behavior of the PayloadState. @@ -404,16 +401,7 @@ class PayloadState : public PayloadStateInterface { // increments num_reboots. void UpdateNumReboots(); - // Writes the current wall-clock time to the kPrefsSystemUpdatedMarker - // state variable. - void CreateSystemUpdatedMarkerFile(); - // Called at program startup if the device booted into a new update. - // The |time_to_reboot| parameter contains the (wall-clock) duration - // from when the update successfully completed (the value written - // into the kPrefsSystemUpdatedMarker state variable) until the device - // was booted into the update (current wall-clock time). - void BootedIntoUpdate(base::TimeDelta time_to_reboot); // Loads the |kPrefsP2PFirstAttemptTimestamp| state variable from disk // into |p2p_first_attempt_timestamp_|. diff --git a/payload_state_unittest.cc b/payload_state_unittest.cc index a69c5ac6..c47e3894 100644 --- a/payload_state_unittest.cc +++ b/payload_state_unittest.cc @@ -1095,8 +1095,8 @@ TEST(PayloadStateTest, RebootAfterSuccessfulUpdateTest) { FakePrefs fake_prefs; // Set the clock to a well-known time (t = 30 seconds). - fake_clock.SetWallclockTime(Time::FromInternalValue( - 30 * Time::kMicrosecondsPerSecond)); + fake_clock.SetMonotonicTime( + Time::FromInternalValue(30 * Time::kMicrosecondsPerSecond)); fake_system_state.set_clock(&fake_clock); fake_system_state.set_prefs(&fake_prefs); @@ -1114,8 +1114,8 @@ TEST(PayloadStateTest, RebootAfterSuccessfulUpdateTest) { // (t = 500 seconds). We do this by using a new PayloadState object // and checking that it emits the right UMA metric with the right // value. - fake_clock.SetWallclockTime(Time::FromInternalValue( - 500 * Time::kMicrosecondsPerSecond)); + fake_clock.SetMonotonicTime( + Time::FromInternalValue(500 * Time::kMicrosecondsPerSecond)); PayloadState payload_state2; EXPECT_TRUE(payload_state2.Initialize(&fake_system_state)); diff --git a/update_attempter_android.cc b/update_attempter_android.cc index f6b9702e..22bb4c29 100644 --- a/update_attempter_android.cc +++ b/update_attempter_android.cc @@ -18,8 +18,10 @@ #include <algorithm> #include <map> +#include <memory> #include <utility> +#include <android-base/properties.h> #include <base/bind.h> #include <base/logging.h> #include <base/strings/string_number_conversions.h> @@ -47,6 +49,7 @@ #endif using base::Bind; +using base::Time; using base::TimeDelta; using base::TimeTicks; using std::shared_ptr; @@ -89,6 +92,7 @@ UpdateAttempterAndroid::UpdateAttempterAndroid( boot_control_(boot_control), hardware_(hardware), processor_(new ActionProcessor()), + clock_(new Clock()), metrics_reporter_(new MetricsReporterAndroid()) { network_selector_ = network::CreateNetworkSelector(); } @@ -102,10 +106,12 @@ UpdateAttempterAndroid::~UpdateAttempterAndroid() { void UpdateAttempterAndroid::Init() { // In case of update_engine restart without a reboot we need to restore the // reboot needed state. - if (UpdateCompletedOnThisBoot()) + if (UpdateCompletedOnThisBoot()) { SetStatusAndNotify(UpdateStatus::UPDATED_NEED_REBOOT); - else + } else { SetStatusAndNotify(UpdateStatus::IDLE); + UpdatePrefsAndReportUpdateMetricsOnReboot(); + } } bool UpdateAttempterAndroid::ApplyPayload( @@ -225,6 +231,10 @@ bool UpdateAttempterAndroid::ApplyPayload( // Just in case we didn't update boot flags yet, make sure they're updated // before any update processing starts. This will start the update process. UpdateBootFlags(); + + UpdatePrefsOnUpdateStart(install_plan_.is_resume); + // TODO(xunchang) report the metrics for unresumable updates + return true; } @@ -262,6 +272,7 @@ bool UpdateAttempterAndroid::ResetStatus(brillo::ErrorPtr* error) { // after resetting to idle state, it doesn't go back to // UpdateStatus::UPDATED_NEED_REBOOT state. bool ret_value = prefs_->Delete(kPrefsUpdateCompletedOnBootId); + ClearMetricsPrefs(); // Update the boot flags so the current slot has higher priority. if (!boot_control_->SetActiveBootSlot(boot_control_->GetCurrentSlot())) @@ -431,22 +442,11 @@ void UpdateAttempterAndroid::TerminateUpdateAndNotify(ErrorCode error_code) { for (auto observer : daemon_state_->service_observers()) observer->SendPayloadApplicationComplete(error_code); - // TODO(xunchang): assign proper values to the metrics. - PayloadType payload_type = kNumPayloadTypes; - metrics::AttemptResult attempt_result = - metrics_utils::GetAttemptResult(error_code); - TimeDelta duration; - TimeDelta duration_uptime; - // Report the android metrics when we terminate the update. Currently we are - // reporting error_code only. - metrics_reporter_->ReportUpdateAttemptMetrics(nullptr, // system_state - 0, // attempt_number - payload_type, - duration, - duration_uptime, - 0, // payload_size - attempt_result, - error_code); + CollectAndReportUpdateMetricsOnUpdateFinished(error_code); + ClearMetricsPrefs(); + if (error_code == ErrorCode::kSuccess) { + metrics_utils::SetSystemUpdatedMarker(clock_.get(), prefs_); + } } void UpdateAttempterAndroid::SetStatusAndNotify(UpdateStatus status) { @@ -540,4 +540,126 @@ bool UpdateAttempterAndroid::UpdateCompletedOnThisBoot() { update_completed_on_boot_id == boot_id); } +// Collect and report the android metrics when we terminate the update. +void UpdateAttempterAndroid::CollectAndReportUpdateMetricsOnUpdateFinished( + ErrorCode error_code) { + int64_t attempt_number = + metrics_utils::GetPersistedValue(kPrefsPayloadAttemptNumber, prefs_); + PayloadType payload_type = kPayloadTypeFull; + int64_t payload_size = 0; + for (const auto& p : install_plan_.payloads) { + if (p.type == InstallPayloadType::kDelta) + payload_type = kPayloadTypeDelta; + payload_size += p.size; + } + + metrics::AttemptResult attempt_result = + metrics_utils::GetAttemptResult(error_code); + Time attempt_start_time = Time::FromInternalValue( + metrics_utils::GetPersistedValue(kPrefsUpdateTimestampStart, prefs_)); + TimeDelta duration_uptime = clock_->GetMonotonicTime() - attempt_start_time; + + metrics_reporter_->ReportUpdateAttemptMetrics( + nullptr, // system_state + static_cast<int>(attempt_number), + payload_type, + TimeDelta(), + duration_uptime, + payload_size, + attempt_result, + error_code); + + if (error_code == ErrorCode::kSuccess) { + int64_t reboot_count = + metrics_utils::GetPersistedValue(kPrefsNumReboots, prefs_); + string build_version; + prefs_->GetString(kPrefsPreviousVersion, &build_version); + metrics_reporter_->ReportSuccessfulUpdateMetrics( + static_cast<int>(attempt_number), + 0, // update abandoned count + payload_type, + payload_size, + nullptr, // num bytes downloaded + 0, // download overhead percentage + duration_uptime, + static_cast<int>(reboot_count), + 0); // url_switch_count + } +} + +void UpdateAttempterAndroid::UpdatePrefsAndReportUpdateMetricsOnReboot() { + string current_boot_id; + TEST_AND_RETURN(utils::GetBootId(¤t_boot_id)); + // Example: [ro.build.version.incremental]: [4292972] + string current_version = + android::base::GetProperty("ro.build.version.incremental", ""); + TEST_AND_RETURN(!current_version.empty()); + + // If there's no record of previous version (e.g. due to a data wipe), we + // save the info of current boot and skip the metrics report. + if (!prefs_->Exists(kPrefsPreviousVersion)) { + prefs_->SetString(kPrefsBootId, current_boot_id); + prefs_->SetString(kPrefsPreviousVersion, current_version); + ClearMetricsPrefs(); + return; + } + string previous_version; + // update_engine restarted under the same build. + // TODO(xunchang) identify and report rollback by checking UpdateMarker. + if (prefs_->GetString(kPrefsPreviousVersion, &previous_version) && + previous_version == current_version) { + string last_boot_id; + bool is_reboot = prefs_->Exists(kPrefsBootId) && + (prefs_->GetString(kPrefsBootId, &last_boot_id) && + last_boot_id != current_boot_id); + // Increment the reboot number if |kPrefsNumReboots| exists. That pref is + // set when we start a new update. + if (is_reboot && prefs_->Exists(kPrefsNumReboots)) { + prefs_->SetString(kPrefsBootId, current_boot_id); + int64_t reboot_count = + metrics_utils::GetPersistedValue(kPrefsNumReboots, prefs_); + metrics_utils::SetNumReboots(reboot_count + 1, prefs_); + } + return; + } + + // Now that the build version changes, report the update metrics. + // TODO(xunchang) check the build version is larger than the previous one. + prefs_->SetString(kPrefsBootId, current_boot_id); + prefs_->SetString(kPrefsPreviousVersion, current_version); + + bool previous_attempt_exists = prefs_->Exists(kPrefsPayloadAttemptNumber); + // |kPrefsPayloadAttemptNumber| should be cleared upon successful update. + if (previous_attempt_exists) { + metrics_reporter_->ReportAbnormallyTerminatedUpdateAttemptMetrics(); + } + + metrics_utils::LoadAndReportTimeToReboot( + metrics_reporter_.get(), prefs_, clock_.get()); + ClearMetricsPrefs(); +} + +// Save the update start time. Reset the reboot count and attempt number if the +// update isn't a resume; otherwise increment the attempt number. +void UpdateAttempterAndroid::UpdatePrefsOnUpdateStart(bool is_resume) { + if (!is_resume) { + metrics_utils::SetNumReboots(0, prefs_); + metrics_utils::SetPayloadAttemptNumber(1, prefs_); + } else { + int64_t attempt_number = + metrics_utils::GetPersistedValue(kPrefsPayloadAttemptNumber, prefs_); + metrics_utils::SetPayloadAttemptNumber(attempt_number + 1, prefs_); + } + Time update_start_time = clock_->GetMonotonicTime(); + metrics_utils::SetUpdateTimestampStart(update_start_time, prefs_); +} + +void UpdateAttempterAndroid::ClearMetricsPrefs() { + CHECK(prefs_); + prefs_->Delete(kPrefsNumReboots); + prefs_->Delete(kPrefsPayloadAttemptNumber); + prefs_->Delete(kPrefsSystemUpdatedMarker); + prefs_->Delete(kPrefsUpdateTimestampStart); +} + } // namespace chromeos_update_engine diff --git a/update_attempter_android.h b/update_attempter_android.h index a347e521..911ab81c 100644 --- a/update_attempter_android.h +++ b/update_attempter_android.h @@ -28,10 +28,12 @@ #include "update_engine/client_library/include/update_engine/update_status.h" #include "update_engine/common/action_processor.h" #include "update_engine/common/boot_control_interface.h" +#include "update_engine/common/clock.h" #include "update_engine/common/hardware_interface.h" #include "update_engine/common/prefs_interface.h" #include "update_engine/daemon_state_interface.h" #include "update_engine/metrics_reporter_interface.h" +#include "update_engine/metrics_utils.h" #include "update_engine/network_selector_interface.h" #include "update_engine/payload_consumer/download_action.h" #include "update_engine/payload_consumer/postinstall_runner_action.h" @@ -87,6 +89,8 @@ class UpdateAttempterAndroid void ProgressUpdate(double progress) override; private: + friend class UpdateAttempterAndroidTest; + // Asynchronously marks the current slot as successful if needed. If already // marked as good, CompleteUpdateBootFlags() is called starting the action // processor. @@ -118,6 +122,36 @@ class UpdateAttempterAndroid // Returns whether an update was completed in the current boot. bool UpdateCompletedOnThisBoot(); + // Prefs to use for metrics report + // |kPrefsPayloadAttemptNumber|: number of update attempts for the current + // payload_id. + // |KprefsNumReboots|: number of reboots when applying the current update. + // |kPrefsSystemUpdatedMarker|: end timestamp of the last successful update. + // |kPrefsUpdateTimestampStart|: start timestamp of the current update. + + // Metrics report function to call: + // |ReportUpdateAttemptMetrics| + // |ReportSuccessfulUpdateMetrics| + // Prefs to update: + // |kPrefsSystemUpdatedMarker| + void CollectAndReportUpdateMetricsOnUpdateFinished(ErrorCode error_code); + + // Metrics report function to call: + // |ReportAbnormallyTerminatedUpdateAttemptMetrics| + // |ReportTimeToRebootMetrics| + // Prefs to update: + // |kPrefsBootId|, |kPrefsPreviousVersion| + void UpdatePrefsAndReportUpdateMetricsOnReboot(); + + // Prefs to update: + // |kPrefsPayloadAttemptNumber|, |kPrefsUpdateTimestampStart| + void UpdatePrefsOnUpdateStart(bool is_resume); + + // Prefs to delete: + // |kPrefsNumReboots|, |kPrefsPayloadAttemptNumber|, + // |kPrefsSystemUpdatedMarker|, |kPrefsUpdateTimestampStart| + void ClearMetricsPrefs(); + DaemonStateInterface* daemon_state_; // DaemonStateAndroid pointers. @@ -163,6 +197,8 @@ class UpdateAttempterAndroid // before applying an update to the other slot. bool updated_boot_flags_ = false; + std::unique_ptr<ClockInterface> clock_; + std::unique_ptr<MetricsReporterInterface> metrics_reporter_; DISALLOW_COPY_AND_ASSIGN(UpdateAttempterAndroid); diff --git a/update_attempter_android_unittest.cc b/update_attempter_android_unittest.cc new file mode 100644 index 00000000..6c0718af --- /dev/null +++ b/update_attempter_android_unittest.cc @@ -0,0 +1,150 @@ +// +// Copyright (C) 2017 The Android Open Source Project +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// + +#include "update_engine/update_attempter_android.h" + +#include <memory> +#include <string> + +#include <android-base/properties.h> +#include <base/time/time.h> +#include <gtest/gtest.h> + +#include "update_engine/common/fake_boot_control.h" +#include "update_engine/common/fake_clock.h" +#include "update_engine/common/fake_hardware.h" +#include "update_engine/common/fake_prefs.h" +#include "update_engine/common/mock_action_processor.h" +#include "update_engine/common/utils.h" +#include "update_engine/daemon_state_android.h" +#include "update_engine/mock_metrics_reporter.h" + +using base::Time; +using base::TimeDelta; +using testing::_; +using update_engine::UpdateStatus; + +namespace chromeos_update_engine { +class UpdateAttempterAndroidTest : public ::testing::Test { + protected: + UpdateAttempterAndroidTest() = default; + + void SetUp() override { + clock_ = new FakeClock(); + metrics_reporter_ = new testing::NiceMock<MockMetricsReporter>(); + update_attempter_android_.metrics_reporter_.reset(metrics_reporter_); + update_attempter_android_.clock_.reset(clock_); + update_attempter_android_.processor_.reset( + new testing::NiceMock<MockActionProcessor>()); + } + + void SetUpdateStatus(update_engine::UpdateStatus status) { + update_attempter_android_.status_ = status; + } + + UpdateAttempterAndroid update_attempter_android_{ + &daemon_state_, &prefs_, &boot_control_, &hardware_}; + + DaemonStateAndroid daemon_state_; + FakePrefs prefs_; + FakeBootControl boot_control_; + FakeHardware hardware_; + + FakeClock* clock_; + testing::NiceMock<MockMetricsReporter>* metrics_reporter_; +}; + +TEST_F(UpdateAttempterAndroidTest, UpdatePrefsSameBuildVersionOnInit) { + std::string build_version = + android::base::GetProperty("ro.build.version.incremental", ""); + prefs_.SetString(kPrefsPreviousVersion, build_version); + prefs_.SetString(kPrefsBootId, "oldboot"); + prefs_.SetInt64(kPrefsNumReboots, 1); + + EXPECT_CALL(*metrics_reporter_, ReportTimeToReboot(_)).Times(0); + update_attempter_android_.Init(); + + // Check that the boot_id and reboot_count are updated. + std::string boot_id; + utils::GetBootId(&boot_id); + EXPECT_TRUE(prefs_.Exists(kPrefsBootId)); + std::string prefs_boot_id; + EXPECT_TRUE(prefs_.GetString(kPrefsBootId, &prefs_boot_id)); + EXPECT_EQ(boot_id, prefs_boot_id); + + EXPECT_TRUE(prefs_.Exists(kPrefsNumReboots)); + int64_t reboot_count; + EXPECT_TRUE(prefs_.GetInt64(kPrefsNumReboots, &reboot_count)); + EXPECT_EQ(2, reboot_count); +} + +TEST_F(UpdateAttempterAndroidTest, UpdatePrefsBuildVersionChangeOnInit) { + prefs_.SetString(kPrefsPreviousVersion, "00001"); // Set the fake version + prefs_.SetInt64(kPrefsPayloadAttemptNumber, 1); + prefs_.SetInt64(kPrefsSystemUpdatedMarker, 23456); + + EXPECT_CALL(*metrics_reporter_, + ReportAbnormallyTerminatedUpdateAttemptMetrics()) + .Times(1); + + Time now = Time::FromInternalValue(34456); + clock_->SetMonotonicTime(now); + TimeDelta duration = now - Time::FromInternalValue(23456); + EXPECT_CALL(*metrics_reporter_, ReportTimeToReboot(duration.InMinutes())) + .Times(1); + + update_attempter_android_.Init(); + // Check that we reset the metric prefs. + EXPECT_FALSE(prefs_.Exists(kPrefsNumReboots)); + EXPECT_FALSE(prefs_.Exists(kPrefsPayloadAttemptNumber)); + EXPECT_FALSE(prefs_.Exists(kPrefsUpdateTimestampStart)); + EXPECT_FALSE(prefs_.Exists(kPrefsSystemUpdatedMarker)); +} + +TEST_F(UpdateAttempterAndroidTest, ReportMetricsOnUpdateTerminated) { + prefs_.SetInt64(kPrefsNumReboots, 3); + prefs_.SetInt64(kPrefsPayloadAttemptNumber, 2); + prefs_.SetString(kPrefsPreviousVersion, "56789"); + prefs_.SetInt64(kPrefsUpdateTimestampStart, 12345); + + Time now = Time::FromInternalValue(22345); + clock_->SetMonotonicTime(now); + TimeDelta duration = now - Time::FromInternalValue(12345); + EXPECT_CALL( + *metrics_reporter_, + ReportUpdateAttemptMetrics(_, + 2, + _, + _, + duration, + _, + metrics::AttemptResult::kUpdateSucceeded, + ErrorCode::kSuccess)) + .Times(1); + EXPECT_CALL(*metrics_reporter_, + ReportSuccessfulUpdateMetrics(2, 0, _, _, _, _, duration, 3, _)) + .Times(1); + + SetUpdateStatus(UpdateStatus::UPDATE_AVAILABLE); + update_attempter_android_.ProcessingDone(nullptr, ErrorCode::kSuccess); + + EXPECT_FALSE(prefs_.Exists(kPrefsNumReboots)); + EXPECT_FALSE(prefs_.Exists(kPrefsPayloadAttemptNumber)); + EXPECT_FALSE(prefs_.Exists(kPrefsUpdateTimestampStart)); + EXPECT_TRUE(prefs_.Exists(kPrefsSystemUpdatedMarker)); +} + +} // namespace chromeos_update_engine |