[incremental] expose duration since oldest pending read

As requested by go/incremental-disablement-metrics, we will expose the
duration since oldest pending read as part of the crash/ANR metrics.
This is the first step that exposes the value to Incremental Service.

BUG: 180951530
Test: unit test
Change-Id: Ic67460072556ef01780a1794b40924ca2092060d

5 files changed, 136 insertions, 7 deletions

diff --git a/services/incremental/BinderIncrementalService.cpp b/services/incremental/BinderIncrementalService.cpp
index 42360d82afe9..8f12b2e5c132 100644
--- a/services/incremental/BinderIncrementalService.cpp
+++ b/services/incremental/BinderIncrementalService.cpp
@@ -348,6 +348,12 @@ binder::Status BinderIncrementalService::unregisterStorageHealthListener(int32_t
     return ok();
 }
 
+binder::Status BinderIncrementalService::getMetrics(int32_t storageId,
+                                                    android::os::PersistableBundle* _aidl_return) {
+    mImpl.getMetrics(storageId, _aidl_return);
+    return ok();
+}
+
 } // namespace android::os::incremental
 
 jlong Incremental_IncrementalService_Start(JNIEnv* env) {
diff --git a/services/incremental/BinderIncrementalService.h b/services/incremental/BinderIncrementalService.h
index 740c542f9759..ebb23dc25bac 100644
--- a/services/incremental/BinderIncrementalService.h
+++ b/services/incremental/BinderIncrementalService.h
@@ -18,6 +18,7 @@
 
 #include <binder/BinderService.h>
 #include <binder/IServiceManager.h>
+#include <binder/PersistableBundle.h>
 #include <jni.h>
 
 #include "IncrementalService.h"
@@ -97,6 +98,8 @@ public:
             const ::android::os::incremental::StorageHealthCheckParams& healthCheckParams,
             const ::android::sp<IStorageHealthListener>& healthListener, bool* _aidl_return) final;
     binder::Status unregisterStorageHealthListener(int32_t storageId) final;
+    binder::Status getMetrics(int32_t storageId,
+                              android::os::PersistableBundle* _aidl_return) final;
 
 private:
     android::incremental::IncrementalService mImpl;
diff --git a/services/incremental/IncrementalService.cpp b/services/incremental/IncrementalService.cpp
index ce6e6ab1e29c..1fcc2843bd43 100644
--- a/services/incremental/IncrementalService.cpp
+++ b/services/incremental/IncrementalService.cpp
@@ -2118,6 +2118,29 @@ bool IncrementalService::removeTimedJobs(TimedQueueWrapper& timedQueue, MountId
     return true;
 }
 
+void IncrementalService::getMetrics(StorageId storageId, android::os::PersistableBundle* result) {
+    const auto duration = getMillsSinceOldestPendingRead(storageId);
+    if (duration >= 0) {
+        const auto kMetricsMillisSinceOldestPendingRead =
+                os::incremental::BnIncrementalService::METRICS_MILLIS_SINCE_OLDEST_PENDING_READ();
+        result->putLong(String16(kMetricsMillisSinceOldestPendingRead.data()), duration);
+    }
+}
+
+long IncrementalService::getMillsSinceOldestPendingRead(StorageId storageId) {
+    std::unique_lock l(mLock);
+    const auto ifs = getIfsLocked(storageId);
+    if (!ifs) {
+        LOG(ERROR) << "getMillsSinceOldestPendingRead failed, invalid storageId: " << storageId;
+        return -EINVAL;
+    }
+    if (!ifs->dataLoaderStub) {
+        LOG(ERROR) << "getMillsSinceOldestPendingRead failed, no data loader: " << storageId;
+        return -EINVAL;
+    }
+    return ifs->dataLoaderStub->elapsedMsSinceOldestPendingRead();
+}
+
 IncrementalService::DataLoaderStub::DataLoaderStub(IncrementalService& service, MountId id,
                                                    DataLoaderParamsParcel&& params,
                                                    FileSystemControlParcel&& control,
@@ -2516,9 +2539,7 @@ void IncrementalService::DataLoaderStub::updateHealthStatus(bool baseline) {
                 std::max(1000ms,
                          std::chrono::milliseconds(mHealthCheckParams.unhealthyMonitoringMs));
 
-        const auto kernelDeltaUs = kernelTsUs - mHealthBase.kernelTsUs;
-        const auto userTs = mHealthBase.userTs + std::chrono::microseconds(kernelDeltaUs);
-        const auto delta = std::chrono::duration_cast<std::chrono::milliseconds>(now - userTs);
+        const auto delta = elapsedMsSinceKernelTs(now, kernelTsUs);
 
         Milliseconds checkBackAfter;
         if (delta + kTolerance < blockedTimeout) {
@@ -2550,6 +2571,13 @@ void IncrementalService::DataLoaderStub::updateHealthStatus(bool baseline) {
     fsmStep();
 }
 
+Milliseconds IncrementalService::DataLoaderStub::elapsedMsSinceKernelTs(TimePoint now,
+                                                                        BootClockTsUs kernelTsUs) {
+    const auto kernelDeltaUs = kernelTsUs - mHealthBase.kernelTsUs;
+    const auto userTs = mHealthBase.userTs + std::chrono::microseconds(kernelDeltaUs);
+    return std::chrono::duration_cast<Milliseconds>(now - userTs);
+}
+
 const incfs::UniqueControl& IncrementalService::DataLoaderStub::initializeHealthControl() {
     if (mHealthPath.empty()) {
         resetHealthControl();
@@ -2581,16 +2609,15 @@ BootClockTsUs IncrementalService::DataLoaderStub::getOldestPendingReadTs() {
     if (mService.mIncFs->waitForPendingReads(control, 0ms, &mLastPendingReads) !=
                 android::incfs::WaitResult::HaveData ||
         mLastPendingReads.empty()) {
+        // Clear previous pending reads
+        mLastPendingReads.clear();
         return result;
     }
 
     LOG(DEBUG) << id() << ": pendingReads: " << control.pendingReads() << ", "
                << mLastPendingReads.size() << ": " << mLastPendingReads.front().bootClockTsUs;
 
-    for (auto&& pendingRead : mLastPendingReads) {
-        result = std::min(result, pendingRead.bootClockTsUs);
-    }
-    return result;
+    return getOldestTsFromLastPendingReads();
 }
 
 void IncrementalService::DataLoaderStub::registerForPendingReads() {
@@ -2612,6 +2639,22 @@ void IncrementalService::DataLoaderStub::registerForPendingReads() {
     mService.mLooper->wake();
 }
 
+BootClockTsUs IncrementalService::DataLoaderStub::getOldestTsFromLastPendingReads() {
+    auto result = kMaxBootClockTsUs;
+    for (auto&& pendingRead : mLastPendingReads) {
+        result = std::min(result, pendingRead.bootClockTsUs);
+    }
+    return result;
+}
+
+long IncrementalService::DataLoaderStub::elapsedMsSinceOldestPendingRead() {
+    const auto oldestPendingReadKernelTs = getOldestTsFromLastPendingReads();
+    if (oldestPendingReadKernelTs == kMaxBootClockTsUs) {
+        return 0;
+    }
+    return elapsedMsSinceKernelTs(Clock::now(), oldestPendingReadKernelTs).count();
+}
+
 void IncrementalService::DataLoaderStub::unregisterFromPendingReads() {
     const auto pendingReadsFd = mHealthControl.pendingReads();
     if (pendingReadsFd < 0) {
diff --git a/services/incremental/IncrementalService.h b/services/incremental/IncrementalService.h
index d8f2c91a971c..14e5a7734172 100644
--- a/services/incremental/IncrementalService.h
+++ b/services/incremental/IncrementalService.h
@@ -20,12 +20,14 @@
 #include <android/content/pm/DataLoaderParamsParcel.h>
 #include <android/content/pm/FileSystemControlParcel.h>
 #include <android/content/pm/IDataLoaderStatusListener.h>
+#include <android/os/incremental/BnIncrementalService.h>
 #include <android/os/incremental/BnIncrementalServiceConnector.h>
 #include <android/os/incremental/BnStorageHealthListener.h>
 #include <android/os/incremental/BnStorageLoadingProgressListener.h>
 #include <android/os/incremental/PerUidReadTimeouts.h>
 #include <android/os/incremental/StorageHealthCheckParams.h>
 #include <binder/IAppOpsCallback.h>
+#include <binder/PersistableBundle.h>
 #include <utils/String16.h>
 #include <utils/StrongPointer.h>
 #include <ziparchive/zip_archive.h>
@@ -181,6 +183,8 @@ public:
                                  bool extractNativeLibs);
     bool waitForNativeBinariesExtraction(StorageId storage);
 
+    void getMetrics(int32_t storageId, android::os::PersistableBundle* _aidl_return);
+
     class AppOpsListener : public android::BnAppOpsCallback {
     public:
         AppOpsListener(IncrementalService& incrementalService, std::string packageName)
@@ -229,6 +233,7 @@ private:
         const content::pm::DataLoaderParamsParcel& params() const { return mParams; }
         void setHealthListener(StorageHealthCheckParams&& healthCheckParams,
                                const StorageHealthListener* healthListener);
+        long elapsedMsSinceOldestPendingRead();
 
     private:
         binder::Status onStatusChanged(MountId mount, int newStatus) final;
@@ -259,6 +264,8 @@ private:
         void resetHealthControl();
 
         BootClockTsUs getOldestPendingReadTs();
+        BootClockTsUs getOldestTsFromLastPendingReads();
+        Milliseconds elapsedMsSinceKernelTs(TimePoint now, BootClockTsUs kernelTsUs);
 
         Milliseconds updateBindDelay();
 
@@ -424,6 +431,7 @@ private:
     bool removeTimedJobs(TimedQueueWrapper& timedQueue, MountId id);
     bool updateLoadingProgress(int32_t storageId,
                                const StorageLoadingProgressListener& progressListener);
+    long getMillsSinceOldestPendingRead(StorageId storage);
 
 private:
     const std::unique_ptr<VoldServiceWrapper> mVold;
diff --git a/services/incremental/test/IncrementalServiceTest.cpp b/services/incremental/test/IncrementalServiceTest.cpp
index b00a84fcd003..5236983c83ff 100644
--- a/services/incremental/test/IncrementalServiceTest.cpp
+++ b/services/incremental/test/IncrementalServiceTest.cpp
@@ -21,6 +21,7 @@
 #include <gmock/gmock.h>
 #include <gtest/gtest.h>
 #include <utils/Log.h>
+#include <utils/String16.h>
 
 #include <chrono>
 #include <future>
@@ -701,6 +702,18 @@ public:
         mDataLoaderManager->getDataLoaderSuccess();
     }
 
+    void checkMillisSinceOldestPendingRead(int storageId, long expected) {
+        android::os::PersistableBundle result{};
+        mIncrementalService->getMetrics(storageId, &result);
+        int64_t value = -1;
+        ASSERT_TRUE(result.getLong(String16(BnIncrementalService::
+                                                    METRICS_MILLIS_SINCE_OLDEST_PENDING_READ()
+                                                            .c_str()),
+                                   &value));
+        ASSERT_EQ(expected, value);
+        ASSERT_EQ(1, (int)result.size());
+    }
+
 protected:
     NiceMock<MockVoldService>* mVold = nullptr;
     NiceMock<MockIncFs>* mIncFs = nullptr;
@@ -995,6 +1008,7 @@ TEST_F(IncrementalServiceTest, testStartDataLoaderUnhealthyStorage) {
     ASSERT_NE(nullptr, mLooper->mCallbackData);
     ASSERT_EQ(storageId, listener->mStorageId);
     ASSERT_EQ(IStorageHealthListener::HEALTH_STATUS_OK, listener->mStatus);
+    checkMillisSinceOldestPendingRead(storageId, 0);
 
     // Looper/epoll callback.
     mIncFs->waitForPendingReadsSuccess(kFirstTimestampUs);
@@ -1020,6 +1034,8 @@ TEST_F(IncrementalServiceTest, testStartDataLoaderUnhealthyStorage) {
     ASSERT_EQ(nullptr, mLooper->mCallbackData);
     ASSERT_EQ(storageId, listener->mStorageId);
     ASSERT_EQ(IStorageHealthListener::HEALTH_STATUS_BLOCKED, listener->mStatus);
+    checkMillisSinceOldestPendingRead(storageId, params.blockedTimeoutMs);
+
     // Timed callback present.
     ASSERT_EQ(storageId, mTimedQueue->mId);
     ASSERT_GE(mTimedQueue->mAfter, 1000ms);
@@ -1035,6 +1051,8 @@ TEST_F(IncrementalServiceTest, testStartDataLoaderUnhealthyStorage) {
     ASSERT_EQ(nullptr, mLooper->mCallbackData);
     ASSERT_EQ(storageId, listener->mStorageId);
     ASSERT_EQ(IStorageHealthListener::HEALTH_STATUS_UNHEALTHY, listener->mStatus);
+    checkMillisSinceOldestPendingRead(storageId, params.unhealthyTimeoutMs);
+
     // Timed callback present.
     ASSERT_EQ(storageId, mTimedQueue->mId);
     ASSERT_GE(mTimedQueue->mAfter, unhealthyMonitoring);
@@ -1050,6 +1068,8 @@ TEST_F(IncrementalServiceTest, testStartDataLoaderUnhealthyStorage) {
     ASSERT_EQ(nullptr, mLooper->mCallbackData);
     ASSERT_EQ(storageId, listener->mStorageId);
     ASSERT_EQ(IStorageHealthListener::HEALTH_STATUS_UNHEALTHY, listener->mStatus);
+    checkMillisSinceOldestPendingRead(storageId, params.unhealthyTimeoutMs);
+
     // Timed callback present.
     ASSERT_EQ(storageId, mTimedQueue->mId);
     ASSERT_GE(mTimedQueue->mAfter, unhealthyMonitoring);
@@ -1065,6 +1085,7 @@ TEST_F(IncrementalServiceTest, testStartDataLoaderUnhealthyStorage) {
     ASSERT_NE(nullptr, mLooper->mCallbackData);
     ASSERT_EQ(storageId, listener->mStorageId);
     ASSERT_EQ(IStorageHealthListener::HEALTH_STATUS_OK, listener->mStatus);
+    checkMillisSinceOldestPendingRead(storageId, 0);
 }
 
 TEST_F(IncrementalServiceTest, testSetIncFsMountOptionsSuccess) {
@@ -1581,4 +1602,52 @@ TEST_F(IncrementalServiceTest, testPerUidTimeoutsSuccess) {
     ASSERT_EQ(mTimedQueue->mAfter, Milliseconds());
 }
 
+TEST_F(IncrementalServiceTest, testInvalidMetricsQuery) {
+    const auto invalidStorageId = 100;
+    android::os::PersistableBundle result{};
+    mIncrementalService->getMetrics(invalidStorageId, &result);
+    int64_t expected = -1, value = -1;
+    ASSERT_FALSE(
+            result.getLong(String16(BnIncrementalService::METRICS_MILLIS_SINCE_OLDEST_PENDING_READ()
+                                            .c_str()),
+                           &value));
+    ASSERT_EQ(expected, value);
+    ASSERT_TRUE(result.empty());
+}
+
+TEST_F(IncrementalServiceTest, testNoMetrics) {
+    mVold->setIncFsMountOptionsSuccess();
+    TemporaryDir tempDir;
+    int storageId =
+            mIncrementalService->createStorage(tempDir.path, mDataLoaderParcel,
+                                               IncrementalService::CreateOptions::CreateNew);
+    ASSERT_GE(storageId, 0);
+    android::os::PersistableBundle result{};
+    mIncrementalService->getMetrics(storageId, &result);
+    int64_t expected = -1, value = -1;
+    ASSERT_FALSE(
+            result.getLong(String16(BnIncrementalService::METRICS_MILLIS_SINCE_OLDEST_PENDING_READ()
+                                            .c_str()),
+                           &value));
+    ASSERT_EQ(expected, value);
+    ASSERT_EQ(0, (int)result.size());
+}
+
+TEST_F(IncrementalServiceTest, testInvalidMetricsKeys) {
+    mVold->setIncFsMountOptionsSuccess();
+    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);
+    int64_t expected = -1, value = -1;
+    ASSERT_FALSE(result.getLong(String16("invalid"), &value));
+    ASSERT_EQ(expected, value);
+    ASSERT_EQ(1, (int)result.size());
+}
+
 } // namespace android::os::incremental