Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 5ac55538 authored by Alex Buynytskyy's avatar Alex Buynytskyy
Browse files

More logging and better retry logic. 

Bug: 183551663
Test: atest PackageManagerShellCommandTest PackageManagerShellCommandIncrementalTest IncrementalServiceTest PackageManagerServiceTest ChecksumsTest
Change-Id: I1b6da82cd4472cc5671b0b60fb12222b4ed08e17
parent f5386796

services/incremental/IncrementalService.cpp

+6 −3
Original line number Diff line number Diff line
@@ -2523,7 +2523,8 @@ std::optional<Milliseconds> IncrementalService::DataLoaderStub::needToBind() { 
        now - mCurrentStatusTs <= Constants::bindingTimeout) {

        LOG(INFO) << "Binding still in progress. "

                  << (healthy ? "The DL is healthy/freshly bound, ok to retry for a few times."

                              : "Already unhealthy, don't do anything.");

                              : "Already unhealthy, don't do anything.")

                  << " for storage " << mId;

        // Binding still in progress.

        if (!healthy) {

            // Already unhealthy, don't do anything.
@@ -2546,7 +2547,8 @@ std::optional<Milliseconds> IncrementalService::DataLoaderStub::needToBind() { 
    const auto previousBindTs = mPreviousBindTs;

    mPreviousBindTs = now;



    const auto nonCrashingInterval = std::max(castToMs(now - previousBindTs), 100ms);

    const auto nonCrashingInterval =

            std::max(castToMs(now - previousBindTs - mPreviousBindDelay), 100ms);

    if (previousBindTs.time_since_epoch() == Clock::duration::zero() ||

        nonCrashingInterval > Constants::healthyDataLoaderUptime) {

        mPreviousBindDelay = 0ms;
@@ -2575,7 +2577,8 @@ bool IncrementalService::DataLoaderStub::bind() { 
    const auto bindDelay = *maybeBindDelay;

    if (bindDelay > 1s) {

        LOG(INFO) << "Delaying bind to " << mParams.packageName << " by "

                  << bindDelay.count() / 1000 << "s";

                  << bindDelay.count() / 1000 << "s"

                  << " for storage " << mId;

    }



    bool result = false;

services/incremental/test/IncrementalServiceTest.cpp

+22 −1
Original line number Diff line number Diff line
@@ -245,6 +245,7 @@ public: 
        mId = mountId;

        mListener = listener;

        mDataLoader = mDataLoaderHolder;

        mBindDelayMs = bindDelayMs;

        *_aidl_return = true;

        if (mListener) {

            mListener->onStatusChanged(mId, IDataLoaderStatusListener::DATA_LOADER_BOUND);
@@ -341,14 +342,18 @@ public: 
            }

            mDataLoader = nullptr;

        }

        mBindDelayMs = -1;

        if (mListener) {

            mListener->onStatusChanged(id, IDataLoaderStatusListener::DATA_LOADER_DESTROYED);

        }

        return binder::Status::ok();

    }



    int bindDelayMs() const { return mBindDelayMs; }



private:

    int mId;

    int mId = -1;

    int mBindDelayMs = -1;

    sp<IDataLoaderStatusListener> mListener;

    sp<IDataLoader> mDataLoader;

    sp<IDataLoader> mDataLoaderHolder;
@@ -604,11 +609,14 @@ public: 
    MOCK_CONST_METHOD0(now, TimePoint());



    void start() { ON_CALL(*this, now()).WillByDefault(Invoke(this, &MockClockWrapper::getClock)); }



    template <class Delta>

    void advance(Delta delta) {

        mClock += delta;

    }



    void advanceMs(int deltaMs) { mClock += std::chrono::milliseconds(deltaMs); }



    TimePoint getClock() const { return mClock; }



    TimePoint mClock = Clock::now();
@@ -894,31 +902,38 @@ TEST_F(IncrementalServiceTest, testDataLoaderDestroyedAndDelayed) { 
    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith1sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith10sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith100sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith1000sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith10000sDelay));

    // Try the reduced delay, just in case.

    mClock->advanceMs(mDataLoaderManager->bindDelayMs() / 2);

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith10000sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();

}
@@ -1012,31 +1027,37 @@ TEST_F(IncrementalServiceTest, testDataLoaderOnRestart) { 
    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith1sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith10sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith100sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith1000sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith10000sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();



    ON_CALL(*mDataLoaderManager, bindToDataLoader(_, _, _, _, _))

            .WillByDefault(Invoke(mDataLoaderManager,

                                  &MockDataLoaderManager::bindToDataLoaderOkWith10000sDelay));

    mClock->advanceMs(mDataLoaderManager->bindDelayMs());

    mDataLoaderManager->setDataLoaderStatusDestroyed();

}