More logging and better retry logic.
Bug: 183551663
Test: atest PackageManagerShellCommandTest PackageManagerShellCommandIncrementalTest IncrementalServiceTest PackageManagerServiceTest ChecksumsTest
Change-Id: I1b6da82cd4472cc5671b0b60fb12222b4ed08e17
diff --git a/services/incremental/IncrementalService.cpp b/services/incremental/IncrementalService.cpp
index 94f8e59..6695ba8 100644
--- a/services/incremental/IncrementalService.cpp
+++ b/services/incremental/IncrementalService.cpp
@@ -2523,7 +2523,8 @@
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 @@
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 @@
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;
diff --git a/services/incremental/test/IncrementalServiceTest.cpp b/services/incremental/test/IncrementalServiceTest.cpp
index ddb7784..1ec446d 100644
--- a/services/incremental/test/IncrementalServiceTest.cpp
+++ b/services/incremental/test/IncrementalServiceTest.cpp
@@ -245,6 +245,7 @@
mId = mountId;
mListener = listener;
mDataLoader = mDataLoaderHolder;
+ mBindDelayMs = bindDelayMs;
*_aidl_return = true;
if (mListener) {
mListener->onStatusChanged(mId, IDataLoaderStatusListener::DATA_LOADER_BOUND);
@@ -341,14 +342,18 @@
}
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 @@
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 @@
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 @@
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();
}