Fix two android metrics reporting in update engine
1. The AttemptCurrentBytesDownloadedMiB was reported in bytes.
2. We were using the same start timestamp (in monotonic_time) for both
boot_time and monotonic_time. This leads to an inaccurate update
duration reporting. This cl saves an extra perf for the boot time and
calculates the duration accordingly.
Also report these information with a different metrics name.
Bug: 30989466
Test: Run an update and check the report
Change-Id: I69e20648501a736a59ff60ca9202ce7bdd9b6e34
diff --git a/common/constants.cc b/common/constants.cc
index 2edfbb7..26adbe0 100644
--- a/common/constants.cc
+++ b/common/constants.cc
@@ -90,6 +90,7 @@
const char kPrefsUpdateStateSignatureBlob[] = "update-state-signature-blob";
const char kPrefsUpdateStateSignedSHA256Context[] =
"update-state-signed-sha-256-context";
+const char kPrefsUpdateBootTimestampStart[] = "update-boot-timestamp-start";
const char kPrefsUpdateTimestampStart[] = "update-timestamp-start";
const char kPrefsUrlSwitchCount[] = "url-switch-count";
const char kPrefsWallClockScatteringWaitPeriod[] = "wall-clock-wait-period";
diff --git a/common/constants.h b/common/constants.h
index d97c5fb..897d2e2 100644
--- a/common/constants.h
+++ b/common/constants.h
@@ -88,6 +88,7 @@
extern const char kPrefsUpdateStateSHA256Context[];
extern const char kPrefsUpdateStateSignatureBlob[];
extern const char kPrefsUpdateStateSignedSHA256Context[];
+extern const char kPrefsUpdateBootTimestampStart[];
extern const char kPrefsUpdateTimestampStart[];
extern const char kPrefsUrlSwitchCount[];
extern const char kPrefsWallClockScatteringWaitPeriod[];
diff --git a/metrics_reporter_android.cc b/metrics_reporter_android.cc
index a5877cb..9165f0d 100644
--- a/metrics_reporter_android.cc
+++ b/metrics_reporter_android.cc
@@ -41,7 +41,7 @@
constexpr char kMetricsUpdateEngineAttemptResult[] =
"ota_update_engine_attempt_result";
constexpr char kMetricsUpdateEngineAttemptDurationInMinutes[] =
- "ota_update_engine_attempt_duration_boottime_in_minutes";
+ "ota_update_engine_attempt_fixed_duration_boottime_in_minutes";
constexpr char kMetricsUpdateEngineAttemptDurationUptimeInMinutes[] =
"ota_update_engine_attempt_duration_monotonic_in_minutes";
constexpr char kMetricsUpdateEngineAttemptErrorCode[] =
@@ -51,12 +51,12 @@
constexpr char kMetricsUpdateEngineAttemptPayloadType[] =
"ota_update_engine_attempt_payload_type";
constexpr char kMetricsUpdateEngineAttemptCurrentBytesDownloadedMiB[] =
- "ota_update_engine_attempt_current_bytes_downloaded_mib";
+ "ota_update_engine_attempt_fixed_current_bytes_downloaded_mib";
constexpr char kMetricsUpdateEngineSuccessfulUpdateAttemptCount[] =
"ota_update_engine_successful_update_attempt_count";
constexpr char kMetricsUpdateEngineSuccessfulUpdateTotalDurationInMinutes[] =
- "ota_update_engine_successful_update_total_duration_in_minutes";
+ "ota_update_engine_successful_update_fixed_total_duration_in_minutes";
constexpr char kMetricsUpdateEngineSuccessfulUpdatePayloadSizeMiB[] =
"ota_update_engine_successful_update_payload_size_mib";
constexpr char kMetricsUpdateEngineSuccessfulUpdatePayloadType[] =
@@ -109,7 +109,7 @@
metrics::DownloadErrorCode /* payload_download_error_code */,
metrics::ConnectionType /* connection_type */) {
LogHistogram(metrics::kMetricsUpdateEngineAttemptCurrentBytesDownloadedMiB,
- payload_bytes_downloaded);
+ payload_bytes_downloaded / kNumBytesInOneMiB);
}
void MetricsReporterAndroid::ReportSuccessfulUpdateMetrics(
diff --git a/metrics_utils.cc b/metrics_utils.cc
index d80d394..e7b2347 100644
--- a/metrics_utils.cc
+++ b/metrics_utils.cc
@@ -366,10 +366,19 @@
CHECK(prefs);
prefs->SetInt64(kPrefsUpdateTimestampStart,
update_start_time.ToInternalValue());
- LOG(INFO) << "Update Timestamp Start = "
+ LOG(INFO) << "Update Monotonic Timestamp Start = "
<< utils::ToString(update_start_time);
}
+void SetUpdateBootTimestampStart(const base::Time& update_start_boot_time,
+ PrefsInterface* prefs) {
+ CHECK(prefs);
+ prefs->SetInt64(kPrefsUpdateBootTimestampStart,
+ update_start_boot_time.ToInternalValue());
+ LOG(INFO) << "Update Boot Timestamp Start = "
+ << utils::ToString(update_start_boot_time);
+}
+
bool LoadAndReportTimeToReboot(MetricsReporterInterface* metrics_reporter,
PrefsInterface* prefs,
ClockInterface* clock) {
diff --git a/metrics_utils.h b/metrics_utils.h
index d08cc4a..8f1aad1 100644
--- a/metrics_utils.h
+++ b/metrics_utils.h
@@ -87,10 +87,16 @@
// 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|.
+// Persists the start monotonic time of an update to
+// |kPrefsUpdateTimestampStart|.
void SetUpdateTimestampStart(const base::Time& update_start_time,
PrefsInterface* prefs);
+// Persists the start boot time of an update to
+// |kPrefsUpdateBootTimestampStart|.
+void SetUpdateBootTimestampStart(const base::Time& update_start_boot_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
diff --git a/update_attempter_android.cc b/update_attempter_android.cc
index 9443869..4d21de6 100644
--- a/update_attempter_android.cc
+++ b/update_attempter_android.cc
@@ -669,10 +669,12 @@
metrics::AttemptResult attempt_result =
metrics_utils::GetAttemptResult(error_code);
- Time attempt_start_time = Time::FromInternalValue(
+ Time boot_time_start = Time::FromInternalValue(
+ metrics_utils::GetPersistedValue(kPrefsUpdateBootTimestampStart, prefs_));
+ Time monotonic_time_start = Time::FromInternalValue(
metrics_utils::GetPersistedValue(kPrefsUpdateTimestampStart, prefs_));
- TimeDelta duration = clock_->GetBootTime() - attempt_start_time;
- TimeDelta duration_uptime = clock_->GetMonotonicTime() - attempt_start_time;
+ TimeDelta duration = clock_->GetBootTime() - boot_time_start;
+ TimeDelta duration_uptime = clock_->GetMonotonicTime() - monotonic_time_start;
metrics_reporter_->ReportUpdateAttemptMetrics(
nullptr, // system_state
@@ -791,8 +793,8 @@
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_);
+ metrics_utils::SetUpdateTimestampStart(clock_->GetMonotonicTime(), prefs_);
+ metrics_utils::SetUpdateBootTimestampStart(clock_->GetBootTime(), prefs_);
}
void UpdateAttempterAndroid::ClearMetricsPrefs() {
@@ -802,6 +804,7 @@
prefs_->Delete(kPrefsPayloadAttemptNumber);
prefs_->Delete(kPrefsSystemUpdatedMarker);
prefs_->Delete(kPrefsUpdateTimestampStart);
+ prefs_->Delete(kPrefsUpdateBootTimestampStart);
}
} // namespace chromeos_update_engine
diff --git a/update_attempter_android.h b/update_attempter_android.h
index 3faeac9..641374a 100644
--- a/update_attempter_android.h
+++ b/update_attempter_android.h
@@ -130,7 +130,10 @@
// 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.
+ // |kPrefsUpdateTimestampStart|: start timestamp in monotonic time of the
+ // current update.
+ // |kPrefsUpdateBootTimestampStart|: start timestamp in boot time of
+ // the current update.
// |kPrefsCurrentBytesDownloaded|: number of bytes downloaded for the current
// payload_id.
// |kPrefsTotalBytesDownloaded|: number of bytes downloaded in total since
@@ -151,13 +154,14 @@
void UpdatePrefsAndReportUpdateMetricsOnReboot();
// Prefs to update:
- // |kPrefsPayloadAttemptNumber|, |kPrefsUpdateTimestampStart|
+ // |kPrefsPayloadAttemptNumber|, |kPrefsUpdateTimestampStart|,
+ // |kPrefsUpdateBootTimestampStart|
void UpdatePrefsOnUpdateStart(bool is_resume);
// Prefs to delete:
// |kPrefsNumReboots|, |kPrefsPayloadAttemptNumber|,
// |kPrefsSystemUpdatedMarker|, |kPrefsUpdateTimestampStart|,
- // |kPrefsCurrentBytesDownloaded|
+ // |kPrefsUpdateBootTimestampStart|, |kPrefsCurrentBytesDownloaded|
void ClearMetricsPrefs();
DaemonStateInterface* daemon_state_;
diff --git a/update_attempter_android_unittest.cc b/update_attempter_android_unittest.cc
index 6b53a21..2593d44 100644
--- a/update_attempter_android_unittest.cc
+++ b/update_attempter_android_unittest.cc
@@ -120,13 +120,14 @@
prefs_.SetInt64(kPrefsNumReboots, 3);
prefs_.SetInt64(kPrefsPayloadAttemptNumber, 2);
prefs_.SetString(kPrefsPreviousVersion, "56789");
+ prefs_.SetInt64(kPrefsUpdateBootTimestampStart, 10000);
prefs_.SetInt64(kPrefsUpdateTimestampStart, 12345);
Time boot_time = Time::FromInternalValue(22345);
Time up_time = Time::FromInternalValue(21345);
clock_->SetBootTime(boot_time);
clock_->SetMonotonicTime(up_time);
- TimeDelta duration = boot_time - Time::FromInternalValue(12345);
+ TimeDelta duration = boot_time - Time::FromInternalValue(10000);
TimeDelta duration_uptime = up_time - Time::FromInternalValue(12345);
EXPECT_CALL(
*metrics_reporter_,
