From 0dc7772746f3c1a67849ae4e6e8a4733227b895d Mon Sep 17 00:00:00 2001 From: Songchun Fan Date: Mon, 3 May 2021 17:13:52 -0700 Subject: [incremental] report new metrics from Incremental Service BUG: 184844615 Test: atest service.incremental_test Change-Id: Ibbfe68851a4adfd620db9652f1fda550a3c6fb2c --- services/incremental/IncrementalService.cpp | 69 +++++++++++----- services/incremental/IncrementalService.h | 1 + .../incremental/test/IncrementalServiceTest.cpp | 93 ++++++++++++++++++++++ 3 files changed, 141 insertions(+), 22 deletions(-) (limited to 'services/incremental') diff --git a/services/incremental/IncrementalService.cpp b/services/incremental/IncrementalService.cpp index 68b5bd975dbc..42c6a8f062de 100644 --- a/services/incremental/IncrementalService.cpp +++ b/services/incremental/IncrementalService.cpp @@ -391,16 +391,14 @@ static const char* toString(IncrementalService::BindKind kind) { } template -static long elapsedMcs(Duration start, Duration end) { +static int64_t elapsedMcs(Duration start, Duration end) { return std::chrono::duration_cast(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( + duration_cast(now.time_since_epoch()).count()); return nowUs - monoTsUs; } @@ -2450,10 +2448,37 @@ void IncrementalService::getMetrics(StorageId storageId, android::os::Persistabl 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 @@ BootClockTsUs IncrementalService::DataLoaderStub::getOldestTsFromLastPendingRead 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 8dc789f4a328..a8434afe29ba 100644 --- a/services/incremental/IncrementalService.h +++ b/services/incremental/IncrementalService.h @@ -472,6 +472,7 @@ private: StorageLoadingProgressListener&& progressListener); void trimReservedSpaceV1(const IncFsMount& ifs); + int64_t elapsedUsSinceMonoTs(uint64_t monoTsUs); private: const std::unique_ptr mVold; diff --git a/services/incremental/test/IncrementalServiceTest.cpp b/services/incremental/test/IncrementalServiceTest.cpp index da7f0db5efc1..6c9310bbf052 100644 --- a/services/incremental/test/IncrementalServiceTest.cpp +++ b/services/incremental/test/IncrementalServiceTest.cpp @@ -635,6 +635,14 @@ public: void advanceMs(int deltaMs) { mClock += std::chrono::milliseconds(deltaMs); } TimePoint getClock() const { return mClock; } + std::optional getClockMono() const { + const auto nsSinceEpoch = + std::chrono::duration_cast(mClock.time_since_epoch()) + .count(); + timespec ts = {.tv_sec = static_cast(nsSinceEpoch / 1000000000LL), + .tv_nsec = static_cast(nsSinceEpoch % 1000000000LL)}; + return ts; + } TimePoint mClock = Clock::now(); }; @@ -2203,4 +2211,89 @@ TEST_F(IncrementalServiceTest, testInvalidMetricsKeys) { 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( + duration_cast( + now.time_since_epoch()) + .count()), + .errorNo = static_cast(-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 -- cgit v1.2.3-59-g8ed1b