Merge "More logging and better retry logic." into sc-dev

This commit is contained in:
Alex Buynytskyy
2021-03-25 22:31:47 +00:00
committed by Android (Google) Code Review
2 changed files with 28 additions and 4 deletions

View File

@@ -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;

View File

@@ -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();
}