mongodb/mongo
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

SERVER-118514 DelayableTimeoutCallback ignores earlier timeout values… (#48924)

Browse Source 
GitOrigin-RevId: 056bc4e207314fe74288bcd42c71915c1ca5171c
This commit is contained in:
Moustafa Maher 2026-03-05 09:08:15 -08:00 committed by MongoDB Bot
parent f90fbdb88e
commit 58a1f4e2c7
7 changed files with 191 additions and 180 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

76
jstests/noPassthrough/replication/decreasing_election_timeout.js Normal file
View File

@ -0,0 +1,76 @@
/**
* decreasing_election_timeout.js
*
* Test that election timeout can be decreased via reconfig and that the election timeout callback
* is rescheduled accordingly.
*
* Steps:
* 1. Start a 2-node replica set with a large electionTimeoutMillis (default) and election log
* verbosity set to 5.
* 2. Wait for log: "Scheduled election timeout callback" (should be far in the future).
* 3. Reconfig to set electionTimeoutMillis to 1000 ms (1 second).
* 4. Wait for logs:
* - "Canceling election timeout callback and not rescheduling"
* - "Rescheduled election timeout callback"
* 5. Step down primary with force:true.
* 6. Wait for secondary to become primary (should be <2s).
*
* @tags: [requires_replication]
*/
import {ReplSetTest} from "jstests/libs/replsettest.js";
const rst = new ReplSetTest({
nodes: 2,
nodeOptions: {
setParameter: {logComponentVerbosity: tojson({replication: 5})},
},
});
rst.startSet();
rst.initiate();
const primary = rst.getPrimary();
const secondary = rst.getSecondary();
// Log the initial election timeout (set to default high value).
const initialConfig = rst.getReplSetConfigFromNode();
const initialElectionTimeout = initialConfig.settings.electionTimeoutMillis;
jsTestLog("Initial electionTimeoutMillis is set to default high value: " + initialElectionTimeout +
"ms");
jsTestLog("Waiting for 'Scheduled election timeout callback' log on secondary");
checkLog.containsWithCount(secondary, "Scheduled election timeout callback", 1);
jsTestLog("Saw 'Scheduled election timeout callback' log");
// Reconfig to decrease electionTimeoutMillis to 1 second
jsTestLog("Reconfiguring to set electionTimeoutMillis to 1000ms (down from " +
initialElectionTimeout + "ms)");
let config = rst.getReplSetConfigFromNode();
config.version++;
config.settings = config.settings || {};
config.settings.electionTimeoutMillis = 1000;
assert.commandWorked(primary.adminCommand({replSetReconfig: config}));
jsTestLog("Waiting for 'Canceling election timeout callback' log");
checkLog.containsWithAtLeastCount(
secondary,
"Moving a delayable timeout call backwards, which requires canceling and rescheduling",
1,
);
jsTestLog("Saw 'Canceling election timeout callback' log");
// Step down primary with force:true so election handoff won't work.
// The 600 second stepdown period prevents the old primary from running for election.
jsTestLog("Stepping down primary with force:true");
const oldPrimary = primary;
assert.commandWorked(oldPrimary.adminCommand({replSetStepDown: 600, force: true}));
// Wait for secondary to become primary (should be <2s with 1s election timeout)
jsTestLog("Waiting for secondary to become primary");
rst.awaitNodesAgreeOnPrimary();
const newPrimary = rst.getPrimary();
assert.eq(newPrimary.host, secondary.host, "Expected secondary to become primary");
jsTestLog("Secondary became primary successfully");
rst.stopSet();

3
jstests/sharding/OWNERS.yml
View File

@ -76,3 +76,6 @@ filters:
- "shard_drain_chunk_size_behavior.js":
approvers:
- 10gen/server-cluster-scalability
- "heal_config_shards_on_fcv_upgrade.js":
approvers:
- 10gen/server-catalog-and-routing

5
jstests/sharding/heal_config_shards_on_fcv_upgrade.js
View File

@ -2,10 +2,11 @@
* Tests the fix-up mechanism added to the upgrade path on setFCV(9.0), which adds a topologyTime
* field to config.shards entries which do not have one due to originating from a pre-5.0 cluster.
*
* TODO (SERVER-102087): remove after 9.0 is branched.
*
* TODO (SERVER-102087): remove multiversion_incompatible after 9.0 is branched.
* TODO (SERVER-120391): remove does_not_support_stepdowns.
* @tags: [
* multiversion_incompatible,
* does_not_support_stepdowns,
* ]
* */
import {ShardingTest} from "jstests/libs/shardingtest.js";

52
src/mongo/db/repl/delayable_timeout_callback.cpp
View File

@ -74,22 +74,18 @@ Status DelayableTimeoutCallback::scheduleAt(Date_t when) {
Status DelayableTimeoutCallback::_scheduleAt(WithLock lk, Date_t when) {
if (_cbHandle && when < _nextCall) {
LOGV2_DEBUG(6602300,
3,
"Moving a delayable timeout call backwards, which is inefficient",
"timerName"_attr = _timerName,
"when"_attr = when,
"nextCall"_attr = _nextCall);
LOGV2_DEBUG(
6602300,
3,
"Moving a delayable timeout call backwards, which requires canceling and rescheduling.",
"timerName"_attr = _timerName,
"when"_attr = when,
"nextCall"_attr = _nextCall);
_cancel(lk);
}
return _delayUntil(lk, when);
}
Status DelayableTimeoutCallback::delayUntil(Date_t when) {
stdx::lock_guard lk(_mutex);
return _delayUntil(lk, when);
}
Status DelayableTimeoutCallback::_delayUntil(WithLock lk, Date_t when) {
if (!_cbHandle) {
// No timeout is active; just schedule it
@ -166,24 +162,7 @@ void DelayableTimeoutCallbackWithJitter::_resetRandomization(WithLock) {
_currentJitter = Milliseconds(0);
}
Status DelayableTimeoutCallbackWithJitter::scheduleAt(Date_t when) {
stdx::lock_guard lk(_mutex);
_resetRandomization(lk);
return _scheduleAt(lk, when);
}
Status DelayableTimeoutCallbackWithJitter::delayUntil(Date_t when) {
stdx::lock_guard lk(_mutex);
_resetRandomization(lk);
return _delayUntil(lk, when);
}
Status DelayableTimeoutCallbackWithJitter::delayUntilWithJitter(WithLock,
Date_t when,
Milliseconds jitterUpperBound) {
if (jitterUpperBound == Milliseconds::zero())
return delayUntil(when);
stdx::lock_guard lk(_mutex);
void DelayableTimeoutCallbackWithJitter::_updateJitter(WithLock lk, Milliseconds jitterUpperBound) {
Date_t now = _getExecutor()->now();
Milliseconds elapsed = now - _lastRandomizationTime;
if (_lastRandomizationTime == Date_t() || elapsed < Milliseconds::zero() ||
@ -192,7 +171,20 @@ Status DelayableTimeoutCallbackWithJitter::delayUntilWithJitter(WithLock,
_currentJitter =
Milliseconds(_randomSource(lk, durationCount<Milliseconds>(jitterUpperBound)));
}
return _delayUntil(lk, when + _currentJitter);
}
Status DelayableTimeoutCallbackWithJitter::scheduleAtWithJitter(WithLock,
Date_t when,
Milliseconds jitterUpperBound) {
if (jitterUpperBound == Milliseconds::zero()) {
stdx::lock_guard lk(_mutex);
_resetRandomization(lk);
return _scheduleAt(lk, when);
}
stdx::lock_guard lk(_mutex);
_updateJitter(lk, jitterUpperBound);
return _scheduleAt(lk, when + _currentJitter);
}
} // namespace repl

21
src/mongo/db/repl/delayable_timeout_callback.h
View File

@ -72,20 +72,12 @@ public:
/**
* Schedule the timeout to occur at "when", regardless of if or when it is already scheduled.
* If it is already scheduled to occur after "when", it is canceled and rescheduled
* If it is already scheduled to occur after "when", it is canceled and rescheduled.
*
* Returns status of the attempt to schedule on the executor.
*/
Status scheduleAt(Date_t when);
/**
* Schedule the timeout to occur at "when" if it is not scheduled or scheduled to occur before
* "when". If it is already scheduled to occur before "when", this call has no effect.
*
* Returns status of the attempt to schedule on the executor.
*/
Status delayUntil(Date_t when);
/**
* Returns whether the callback is scheduled at all.
*/
@ -134,9 +126,9 @@ private:
*
* Synchronization of the randomSource is up to the caller; it is provided externally to
* avoid having a separate random number generator per timer. The randomSource function will
* be called with the maximum jitter value passed to delayUntilWithJitter; it should return
* a value in the range [0, maxJitter) or [0, maxJitter] depending on what you want the
* actual jitter range to be.
* be called with the maximum jitter value passed to scheduleAtWithJitter; it should return a value
* in the range [0, maxJitter) or [0, maxJitter] depending on what you want the actual jitter range
* to be.
*/
class DelayableTimeoutCallbackWithJitter : public DelayableTimeoutCallback {
public:
@ -149,12 +141,11 @@ public:
: DelayableTimeoutCallback(executor, std::move(callback), timerName),
_randomSource(std::move(randomSource)) {}
Status scheduleAt(Date_t when);
Status delayUntil(Date_t when);
Status delayUntilWithJitter(WithLock, Date_t when, Milliseconds maxJitter);
Status scheduleAtWithJitter(WithLock, Date_t when, Milliseconds maxJitter);
private:
void _resetRandomization(WithLock);
void _updateJitter(WithLock, Milliseconds jitterUpperBound);
RandomSource _randomSource;
Date_t _lastRandomizationTime;

210
src/mongo/db/repl/delayable_timeout_callback_test.cpp
View File

@ -127,23 +127,6 @@ TEST_F(DelayableTimeoutCallbackTest, ScheduleAtSchedulesFirstCallback) {
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackTest, DelayUntilSchedulesFirstCallback) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
ASSERT_OK(_delayableTimeoutCallback->delayUntil(_net->now() + Seconds(2)));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
_net->runUntil(_net->now() + Seconds(1));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
_net->runUntil(_net->now() + Seconds(1));
ASSERT_EQ(1, callbackRan);
ASSERT_EQ(0, callbackRanWithError);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackTest, ScheduleAtMovesCallbackLater) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
@ -167,29 +150,6 @@ TEST_F(DelayableTimeoutCallbackTest, ScheduleAtMovesCallbackLater) {
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackTest, DelayUntilMovesCallbackLater) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
ASSERT_OK(_delayableTimeoutCallback->delayUntil(_net->now() + Seconds(2)));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
_net->runUntil(_net->now() + Seconds(1));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
ASSERT_OK(_delayableTimeoutCallback->delayUntil(_net->now() + Seconds(2)));
_net->runUntil(_net->now() + Seconds(1));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
_net->runUntil(_net->now() + Seconds(1));
ASSERT_EQ(1, callbackRan);
ASSERT_EQ(0, callbackRanWithError);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackTest, ScheduleAtMovesCallbackEarlier) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
@ -210,29 +170,6 @@ TEST_F(DelayableTimeoutCallbackTest, ScheduleAtMovesCallbackEarlier) {
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackTest, DelayUntilDoesNotMoveCallbackEarlier) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
ASSERT_OK(_delayableTimeoutCallback->delayUntil(_net->now() + Seconds(3)));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
_net->runUntil(_net->now() + Seconds(1));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
ASSERT_OK(_delayableTimeoutCallback->delayUntil(_net->now() + Seconds(1)));
_net->runUntil(_net->now() + Seconds(1));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
_net->runUntil(_net->now() + Seconds(1));
ASSERT_EQ(1, callbackRan);
ASSERT_EQ(0, callbackRanWithError);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackTest, ScheduleAtInPastRunsImmediately) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
// Make sure there's a past to schedule in.
@ -249,22 +186,6 @@ TEST_F(DelayableTimeoutCallbackTest, ScheduleAtInPastRunsImmediately) {
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackTest, DelayUntilInPastRunsImmediately) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
// Make sure there's a past to schedule in.
_net->runUntil(_net->now() + Days(1));
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
ASSERT_OK(_delayableTimeoutCallback->delayUntil(_net->now() - Seconds(1)));
// Needed to trigger anything scheduled.
_net->runReadyNetworkOperations();
ASSERT_EQ(1, callbackRan);
ASSERT_EQ(0, callbackRanWithError);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackTest, Cancellation) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
@ -305,63 +226,13 @@ TEST_F(DelayableTimeoutCallbackTest, Shutdown) {
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackWithJitterTest, DelayUntilWithJitter) {
TEST_F(DelayableTimeoutCallbackWithJitterTest, ScheduleAtWithZeroJitter) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
stdx::lock_guard lk(_mutex);
ASSERT_OK(_delayableTimeoutCallback->delayUntilWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(100)));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
// Our "random" generator is just 10,20,30,...
ASSERT_EQ(_net->now() + Milliseconds(10010), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
// Setting it again in the same time shouldn't change jitter.
ASSERT_OK(_delayableTimeoutCallback->delayUntilWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(100)));
ASSERT_EQ(_net->now() + Milliseconds(10010), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
// Move forward less than the max jitter shouldn't change jitter.
for (int i = 0; i < 3; i++) {
_net->runUntil(_net->now() + Milliseconds(25));
ASSERT_OK(_delayableTimeoutCallback->delayUntilWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(100)));
ASSERT_EQ(_net->now() + Milliseconds(10010), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
}
// Move forward to the max jitter should recalculate jitter.
_net->runUntil(_net->now() + Milliseconds(25));
ASSERT_OK(_delayableTimeoutCallback->delayUntilWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(100)));
ASSERT_EQ(_net->now() + Milliseconds(10020), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
// Setting max jitter to less than actual jitter should recalculate jitter.
ASSERT_OK(_delayableTimeoutCallback->delayUntilWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(19)));
// Jitter value will be 30 % 19 = 11
ASSERT_EQ(_net->now() + Milliseconds(10011), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
_net->runUntil(_net->now() + Milliseconds(10011));
ASSERT_EQ(1, callbackRan);
ASSERT_EQ(0, callbackRanWithError);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackWithJitterTest, DelayUntilWithZeroJitter) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
stdx::lock_guard lk(_mutex);
ASSERT_OK(
_delayableTimeoutCallback->delayUntilWithJitter(lk, _net->now() + Seconds(10), Seconds(0)));
_delayableTimeoutCallback->scheduleAtWithJitter(lk, _net->now() + Seconds(10), Seconds(0)));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(_net->now() + Milliseconds(10000), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
@ -372,5 +243,82 @@ TEST_F(DelayableTimeoutCallbackWithJitterTest, DelayUntilWithZeroJitter) {
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackWithJitterTest, ScheduleAtWithJitterMovesCallbackEarlier) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
stdx::lock_guard lk(_mutex);
ASSERT_OK(_delayableTimeoutCallback->scheduleAtWithJitter(
lk, _net->now() + Seconds(3), Milliseconds(100)));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
_net->runUntil(_net->now() + Seconds(1));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
ASSERT_EQ(0, callbackRan);
// Schedule at an earlier time (move backward); should cancel and reschedule like scheduleAt().
ASSERT_OK(_delayableTimeoutCallback->scheduleAtWithJitter(
lk, _net->now() + Seconds(1), Milliseconds(100)));
// Jitter refreshed (elapsed >= 100ms); next call is at base time + jitter in [0, 100)ms.
const auto expectedWhen = _delayableTimeoutCallback->getNextCall();
ASSERT_GTE(expectedWhen, _net->now() + Seconds(1));
ASSERT_LT(expectedWhen, _net->now() + Seconds(1) + Milliseconds(100));
_net->runUntil(expectedWhen);
ASSERT_EQ(1, callbackRan);
ASSERT_EQ(0, callbackRanWithError);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
TEST_F(DelayableTimeoutCallbackWithJitterTest, ScheduleAtWithJitter) {
executor::NetworkInterfaceMock::InNetworkGuard guard(_net);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
stdx::lock_guard lk(_mutex);
ASSERT_OK(_delayableTimeoutCallback->scheduleAtWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(100)));
ASSERT_TRUE(_delayableTimeoutCallback->isActive());
// Our "random" generator is 10,20,30,...; after ScheduleAtWithJitterMovesCallbackEarlier used
// 10 and 20, first value here is 30.
ASSERT_EQ(_net->now() + Milliseconds(10030), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
// Setting it again in the same time shouldn't change jitter.
ASSERT_OK(_delayableTimeoutCallback->scheduleAtWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(100)));
ASSERT_EQ(_net->now() + Milliseconds(10030), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
// Move forward less than the max jitter shouldn't change jitter.
for (int i = 0; i < 3; i++) {
_net->runUntil(_net->now() + Milliseconds(25));
ASSERT_OK(_delayableTimeoutCallback->scheduleAtWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(100)));
ASSERT_EQ(_net->now() + Milliseconds(10030), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
}
// Move forward to the max jitter should recalculate jitter.
_net->runUntil(_net->now() + Milliseconds(25));
ASSERT_OK(_delayableTimeoutCallback->scheduleAtWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(100)));
ASSERT_EQ(_net->now() + Milliseconds(10040), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
// Setting max jitter to less than actual jitter should recalculate jitter.
ASSERT_OK(_delayableTimeoutCallback->scheduleAtWithJitter(
lk, _net->now() + Seconds(10), Milliseconds(19)));
// Jitter value will be 50 % 19 = 12 (next in sequence after 40)
ASSERT_EQ(_net->now() + Milliseconds(10012), _delayableTimeoutCallback->getNextCall());
ASSERT_EQ(0, callbackRan);
_net->runUntil(_net->now() + Milliseconds(10012));
ASSERT_EQ(1, callbackRan);
ASSERT_EQ(0, callbackRanWithError);
ASSERT_FALSE(_delayableTimeoutCallback->isActive());
}
} // namespace repl
} // namespace mongo

4
src/mongo/db/repl/replication_coordinator_impl_heartbeat.cpp
View File

@ -1213,7 +1213,7 @@ void ReplicationCoordinatorImpl::_scheduleNextLivenessUpdate(WithLock lk, bool r
// check to continue conducting liveness checks and be able to step down from primary if we
// lose contact with a majority of nodes.
// We ignore shutdown errors; any other error triggers an fassert.
_handleLivenessTimeoutCallback.delayUntil(nextTimeout).ignore();
_handleLivenessTimeoutCallback.scheduleAt(nextTimeout).ignore();
_earliestMemberId = earliestMemberId.getData();
}
@ -1280,7 +1280,7 @@ void ReplicationCoordinatorImpl::_cancelAndRescheduleElectionTimeout(WithLock lk
auto requestedWhen = now + _rsConfig.unsafePeek().getElectionTimeoutPeriod();
invariant(requestedWhen > now);
Status delayStatus =
_handleElectionTimeoutCallback.delayUntilWithJitter(lk, requestedWhen, upperBound);
_handleElectionTimeoutCallback.scheduleAtWithJitter(lk, requestedWhen, upperBound);
Date_t when = _handleElectionTimeoutCallback.getNextCall();
if (wasActive) {
// The log level here is 4 once per second, otherwise 5.