[incremental] report new metrics from Incremental Service
BUG: 184844615
Test: atest service.incremental_test
Change-Id: Ibbfe68851a4adfd620db9652f1fda550a3c6fb2c
diff --git a/core/java/android/os/incremental/IIncrementalService.aidl b/core/java/android/os/incremental/IIncrementalService.aidl
index c68f878..8c9f2dd 100644
--- a/core/java/android/os/incremental/IIncrementalService.aidl
+++ b/core/java/android/os/incremental/IIncrementalService.aidl
@@ -186,7 +186,30 @@
* Metrics key for delay in milliseconds to retry data loader binding. The value is a long.
*/
const @utf8InCpp String METRICS_DATA_LOADER_BIND_DELAY_MILLIS = "dataLoaderBindDelayMillis";
-
+ /**
+ * Metrics key for total count of delayed reads caused by pending reads. The value is an int.
+ */
+ const @utf8InCpp String METRICS_TOTAL_DELAYED_READS = "totalDelayedReads";
+ /**
+ * Metrics key for total count of delayed reads caused by pending reads. The value is an int.
+ */
+ const @utf8InCpp String METRICS_TOTAL_DELAYED_READS_MILLIS = "totalDelayedReadsMillis";
+ /**
+ * Metrics key for total count of failed reads. The value is an int.
+ */
+ const @utf8InCpp String METRICS_TOTAL_FAILED_READS = "totalFailedReads";
+ /**
+ * Metrics key for the uid of the last read error. The value is an int.
+ */
+ const @utf8InCpp String METRICS_LAST_READ_ERROR_UID = "lastReadErrorUid";
+ /**
+ * Metrics key for duration in milliseconds since the last read error. The value is a long.
+ */
+ const @utf8InCpp String METRICS_MILLIS_SINCE_LAST_READ_ERROR = "millisSinceLastReadError";
+ /**
+ * Metrics key for the error number of the last read error. The value is an int.
+ */
+ const @utf8InCpp String METRICS_LAST_READ_ERROR_NUMBER = "lastReadErrorNo";
/**
* Return a bundle containing the requested metrics keys and their values.
*/
diff --git a/core/java/android/os/incremental/IncrementalMetrics.java b/core/java/android/os/incremental/IncrementalMetrics.java
index 98eb431..c44b7d9 100644
--- a/core/java/android/os/incremental/IncrementalMetrics.java
+++ b/core/java/android/os/incremental/IncrementalMetrics.java
@@ -71,4 +71,46 @@
public long getDataLoaderBindDelayMillis() {
return mData.getLong(IIncrementalService.METRICS_DATA_LOADER_BIND_DELAY_MILLIS, -1);
}
+
+ /**
+ * @return total count of delayed reads caused by pending reads
+ */
+ public int getTotalDelayedReads() {
+ return mData.getInt(IIncrementalService.METRICS_TOTAL_DELAYED_READS, -1);
+ }
+
+ /**
+ * @return total count of failed reads
+ */
+ public int getTotalFailedReads() {
+ return mData.getInt(IIncrementalService.METRICS_TOTAL_FAILED_READS, -1);
+ }
+
+ /**
+ * @return total duration in milliseconds of delayed reads
+ */
+ public long getTotalDelayedReadsDurationMillis() {
+ return mData.getInt(IIncrementalService.METRICS_TOTAL_DELAYED_READS_MILLIS, -1);
+ }
+
+ /**
+ * @return the uid of the last read error
+ */
+ public int getLastReadErrorUid() {
+ return mData.getInt(IIncrementalService.METRICS_LAST_READ_ERROR_UID, -1);
+ }
+
+ /**
+ * @return duration in milliseconds since the last read error
+ */
+ public long getMillisSinceLastReadError() {
+ return mData.getLong(IIncrementalService.METRICS_MILLIS_SINCE_LAST_READ_ERROR, -1);
+ }
+
+ /**
+ * @return the error number of the last read error
+ */
+ public int getLastReadErrorNumber() {
+ return mData.getInt(IIncrementalService.METRICS_LAST_READ_ERROR_NUMBER, -1);
+ }
}
diff --git a/services/incremental/IncrementalService.cpp b/services/incremental/IncrementalService.cpp
index 68b5bd9..42c6a8f 100644
--- a/services/incremental/IncrementalService.cpp
+++ b/services/incremental/IncrementalService.cpp
@@ -391,16 +391,14 @@
}
template <class Duration>
-static long elapsedMcs(Duration start, Duration end) {
+static int64_t elapsedMcs(Duration start, Duration end) {
return std::chrono::duration_cast<std::chrono::microseconds>(end - start).count();
}
-static uint64_t elapsedUsSinceMonoTs(uint64_t monoTsUs) {
- timespec now;
- if (clock_gettime(CLOCK_MONOTONIC, &now) != 0) {
- return 0;
- }
- uint64_t nowUs = now.tv_sec * 1000000LL + now.tv_nsec / 1000;
+int64_t IncrementalService::elapsedUsSinceMonoTs(uint64_t monoTsUs) {
+ const auto now = mClock->now();
+ const auto nowUs = static_cast<uint64_t>(
+ duration_cast<std::chrono::microseconds>(now.time_since_epoch()).count());
return nowUs - monoTsUs;
}
@@ -2450,10 +2448,37 @@
LOG(ERROR) << "getMetrics failed, invalid storageId: " << storageId;
return;
}
- const auto kMetricsReadLogsEnabled =
+ const auto& kMetricsReadLogsEnabled =
os::incremental::BnIncrementalService::METRICS_READ_LOGS_ENABLED();
- result->putBoolean(String16(kMetricsReadLogsEnabled.data()), ifs->readLogsEnabled() != 0);
-
+ result->putBoolean(String16(kMetricsReadLogsEnabled.c_str()), ifs->readLogsEnabled() != 0);
+ const auto incfsMetrics = mIncFs->getMetrics(path::basename(ifs->root));
+ if (incfsMetrics) {
+ const auto& kMetricsTotalDelayedReads =
+ os::incremental::BnIncrementalService::METRICS_TOTAL_DELAYED_READS();
+ const auto totalDelayedReads =
+ incfsMetrics->readsDelayedMin + incfsMetrics->readsDelayedPending;
+ result->putInt(String16(kMetricsTotalDelayedReads.c_str()), totalDelayedReads);
+ const auto& kMetricsTotalFailedReads =
+ os::incremental::BnIncrementalService::METRICS_TOTAL_FAILED_READS();
+ const auto totalFailedReads = incfsMetrics->readsFailedTimedOut +
+ incfsMetrics->readsFailedHashVerification + incfsMetrics->readsFailedOther;
+ result->putInt(String16(kMetricsTotalFailedReads.c_str()), totalFailedReads);
+ const auto& kMetricsTotalDelayedReadsMillis =
+ os::incremental::BnIncrementalService::METRICS_TOTAL_DELAYED_READS_MILLIS();
+ const int64_t totalDelayedReadsMillis =
+ (incfsMetrics->readsDelayedMinUs + incfsMetrics->readsDelayedPendingUs) / 1000;
+ result->putLong(String16(kMetricsTotalDelayedReadsMillis.c_str()), totalDelayedReadsMillis);
+ }
+ const auto lastReadError = mIncFs->getLastReadError(ifs->control);
+ if (lastReadError && lastReadError->timestampUs != 0) {
+ const auto& kMetricsMillisSinceLastReadError =
+ os::incremental::BnIncrementalService::METRICS_MILLIS_SINCE_LAST_READ_ERROR();
+ result->putLong(String16(kMetricsMillisSinceLastReadError.c_str()),
+ (int64_t)elapsedUsSinceMonoTs(lastReadError->timestampUs) / 1000);
+ const auto& kMetricsLastReadErrorNo =
+ os::incremental::BnIncrementalService::METRICS_LAST_READ_ERROR_NUMBER();
+ result->putInt(String16(kMetricsLastReadErrorNo.c_str()), lastReadError->errorNo);
+ }
std::unique_lock l(ifs->lock);
if (!ifs->dataLoaderStub) {
return;
@@ -2998,24 +3023,24 @@
void IncrementalService::DataLoaderStub::getMetrics(android::os::PersistableBundle* result) {
const auto duration = elapsedMsSinceOldestPendingRead();
if (duration >= 0) {
- const auto kMetricsMillisSinceOldestPendingRead =
+ const auto& kMetricsMillisSinceOldestPendingRead =
os::incremental::BnIncrementalService::METRICS_MILLIS_SINCE_OLDEST_PENDING_READ();
- result->putLong(String16(kMetricsMillisSinceOldestPendingRead.data()), duration);
+ result->putLong(String16(kMetricsMillisSinceOldestPendingRead.c_str()), duration);
}
- const auto kMetricsStorageHealthStatusCode =
+ const auto& kMetricsStorageHealthStatusCode =
os::incremental::BnIncrementalService::METRICS_STORAGE_HEALTH_STATUS_CODE();
- result->putInt(String16(kMetricsStorageHealthStatusCode.data()), mHealthStatus);
- const auto kMetricsDataLoaderStatusCode =
+ result->putInt(String16(kMetricsStorageHealthStatusCode.c_str()), mHealthStatus);
+ const auto& kMetricsDataLoaderStatusCode =
os::incremental::BnIncrementalService::METRICS_DATA_LOADER_STATUS_CODE();
- result->putInt(String16(kMetricsDataLoaderStatusCode.data()), mCurrentStatus);
- const auto kMetricsMillisSinceLastDataLoaderBind =
+ result->putInt(String16(kMetricsDataLoaderStatusCode.c_str()), mCurrentStatus);
+ const auto& kMetricsMillisSinceLastDataLoaderBind =
os::incremental::BnIncrementalService::METRICS_MILLIS_SINCE_LAST_DATA_LOADER_BIND();
- result->putLong(String16(kMetricsMillisSinceLastDataLoaderBind.data()),
- (long)(elapsedMcs(mPreviousBindTs, mService.mClock->now()) / 1000));
- const auto kMetricsDataLoaderBindDelayMillis =
+ result->putLong(String16(kMetricsMillisSinceLastDataLoaderBind.c_str()),
+ elapsedMcs(mPreviousBindTs, mService.mClock->now()) / 1000);
+ const auto& kMetricsDataLoaderBindDelayMillis =
os::incremental::BnIncrementalService::METRICS_DATA_LOADER_BIND_DELAY_MILLIS();
- result->putLong(String16(kMetricsDataLoaderBindDelayMillis.data()),
- (long)(mPreviousBindDelay.count()));
+ result->putLong(String16(kMetricsDataLoaderBindDelayMillis.c_str()),
+ mPreviousBindDelay.count());
}
long IncrementalService::DataLoaderStub::elapsedMsSinceOldestPendingRead() {
diff --git a/services/incremental/IncrementalService.h b/services/incremental/IncrementalService.h
index 8dc789f..a8434af 100644
--- a/services/incremental/IncrementalService.h
+++ b/services/incremental/IncrementalService.h
@@ -472,6 +472,7 @@
StorageLoadingProgressListener&& progressListener);
void trimReservedSpaceV1(const IncFsMount& ifs);
+ int64_t elapsedUsSinceMonoTs(uint64_t monoTsUs);
private:
const std::unique_ptr<VoldServiceWrapper> mVold;
diff --git a/services/incremental/test/IncrementalServiceTest.cpp b/services/incremental/test/IncrementalServiceTest.cpp
index da7f0db..6c9310b 100644
--- a/services/incremental/test/IncrementalServiceTest.cpp
+++ b/services/incremental/test/IncrementalServiceTest.cpp
@@ -635,6 +635,14 @@
void advanceMs(int deltaMs) { mClock += std::chrono::milliseconds(deltaMs); }
TimePoint getClock() const { return mClock; }
+ std::optional<timespec> getClockMono() const {
+ const auto nsSinceEpoch =
+ std::chrono::duration_cast<std::chrono::nanoseconds>(mClock.time_since_epoch())
+ .count();
+ timespec ts = {.tv_sec = static_cast<time_t>(nsSinceEpoch / 1000000000LL),
+ .tv_nsec = static_cast<long>(nsSinceEpoch % 1000000000LL)};
+ return ts;
+ }
TimePoint mClock = Clock::now();
};
@@ -2203,4 +2211,89 @@
ASSERT_EQ(6, (int)result.size());
}
+TEST_F(IncrementalServiceTest, testMetricsWithNoLastReadError) {
+ mVold->setIncFsMountOptionsSuccess();
+ ON_CALL(*mIncFs, getMetrics(_))
+ .WillByDefault(Return(Metrics{
+ .readsDelayedMin = 10,
+ .readsDelayedMinUs = 5000,
+ .readsDelayedPending = 10,
+ .readsDelayedPendingUs = 5000,
+ .readsFailedHashVerification = 10,
+ .readsFailedOther = 10,
+ .readsFailedTimedOut = 10,
+ }));
+ ON_CALL(*mIncFs, getLastReadError(_)).WillByDefault(Return(LastReadError{}));
+ TemporaryDir tempDir;
+ int storageId =
+ mIncrementalService->createStorage(tempDir.path, mDataLoaderParcel,
+ IncrementalService::CreateOptions::CreateNew);
+ ASSERT_GE(storageId, 0);
+ ASSERT_TRUE(mIncrementalService->startLoading(storageId, std::move(mDataLoaderParcel), {}, {},
+ {}, {}));
+ android::os::PersistableBundle result{};
+ mIncrementalService->getMetrics(storageId, &result);
+ ASSERT_EQ(9, (int)result.size());
+
+ int expectedtotalDelayedReads = 20, totalDelayedReads = -1;
+ ASSERT_TRUE(result.getInt(String16(BnIncrementalService::METRICS_TOTAL_DELAYED_READS().c_str()),
+ &totalDelayedReads));
+ ASSERT_EQ(expectedtotalDelayedReads, totalDelayedReads);
+ int expectedtotalFailedReads = 30, totalFailedReads = -1;
+ ASSERT_TRUE(result.getInt(String16(BnIncrementalService::METRICS_TOTAL_FAILED_READS().c_str()),
+ &totalFailedReads));
+ ASSERT_EQ(expectedtotalFailedReads, totalFailedReads);
+ int64_t expectedtotalDelayedReadsMillis = 10, totalDelayedReadsMillis = -1;
+ ASSERT_TRUE(result.getLong(String16(BnIncrementalService::METRICS_TOTAL_DELAYED_READS_MILLIS()
+ .c_str()),
+ &totalDelayedReadsMillis));
+ ASSERT_EQ(expectedtotalDelayedReadsMillis, totalDelayedReadsMillis);
+
+ int64_t expectedMillisSinceLastReadError = -1, millisSinceLastReadError = -1;
+ ASSERT_FALSE(
+ result.getLong(String16(BnIncrementalService::METRICS_MILLIS_SINCE_LAST_READ_ERROR()
+ .c_str()),
+ &millisSinceLastReadError));
+ ASSERT_EQ(expectedMillisSinceLastReadError, millisSinceLastReadError);
+ int expectedLastReadErrorNumber = -1, lastReadErrorNumber = -1;
+ ASSERT_FALSE(
+ result.getInt(String16(BnIncrementalService::METRICS_LAST_READ_ERROR_NUMBER().c_str()),
+ &lastReadErrorNumber));
+ ASSERT_EQ(expectedLastReadErrorNumber, lastReadErrorNumber);
+}
+
+TEST_F(IncrementalServiceTest, testMetricsWithLastReadError) {
+ mVold->setIncFsMountOptionsSuccess();
+ ON_CALL(*mIncFs, getMetrics(_)).WillByDefault(Return(Metrics{}));
+ mClock->advanceMs(5);
+ const auto now = mClock->getClock();
+ ON_CALL(*mIncFs, getLastReadError(_))
+ .WillByDefault(Return(LastReadError{.timestampUs = static_cast<uint64_t>(
+ duration_cast<std::chrono::microseconds>(
+ now.time_since_epoch())
+ .count()),
+ .errorNo = static_cast<uint32_t>(-ETIME)}));
+ TemporaryDir tempDir;
+ int storageId =
+ mIncrementalService->createStorage(tempDir.path, mDataLoaderParcel,
+ IncrementalService::CreateOptions::CreateNew);
+ ASSERT_GE(storageId, 0);
+ ASSERT_TRUE(mIncrementalService->startLoading(storageId, std::move(mDataLoaderParcel), {}, {},
+ {}, {}));
+ mClock->advanceMs(10);
+ android::os::PersistableBundle result{};
+ mIncrementalService->getMetrics(storageId, &result);
+ ASSERT_EQ(11, (int)result.size());
+ int64_t expectedMillisSinceLastReadError = 10, millisSinceLastReadError = -1;
+ ASSERT_TRUE(result.getLong(String16(BnIncrementalService::METRICS_MILLIS_SINCE_LAST_READ_ERROR()
+ .c_str()),
+ &millisSinceLastReadError));
+ ASSERT_EQ(expectedMillisSinceLastReadError, millisSinceLastReadError);
+ int expectedLastReadErrorNumber = -ETIME, lastReadErrorNumber = -1;
+ ASSERT_TRUE(
+ result.getInt(String16(BnIncrementalService::METRICS_LAST_READ_ERROR_NUMBER().c_str()),
+ &lastReadErrorNumber));
+ ASSERT_EQ(expectedLastReadErrorNumber, lastReadErrorNumber);
+}
+
} // namespace android::os::incremental