/* should be in RECOVERING state on arrival here.
readlocks
@return true if transitioned to SECONDARY
*/
bool ReplSetImpl::tryToGoLiveAsASecondary(OperationContext* txn, OpTime& /*out*/ minvalid) {
bool golive = false;
lock rsLock( this );
if (_maintenanceMode > 0) {
// we're not actually going live
return true;
}
// if we're blocking sync, don't change state
if (_blockSync) {
return false;
}
Lock::GlobalWrite writeLock(txn->lockState());
// make sure we're not primary, secondary, rollback, or fatal already
if (box.getState().primary() || box.getState().secondary() ||
box.getState().fatal()) {
return false;
}
minvalid = getMinValid(txn);
if( minvalid <= lastOpTimeWritten ) {
golive=true;
}
else {
sethbmsg(str::stream() << "still syncing, not yet to minValid optime " <<
minvalid.toString());
}
if( golive ) {
sethbmsg("");
changeState(MemberState::RS_SECONDARY);
}
return golive;
}
/* tail an oplog. ok to return, will be re-called. */
void SyncTail::oplogApplication() {
ReplicationCoordinator* replCoord = getGlobalReplicationCoordinator();
ApplyBatchFinalizer finalizer(replCoord);
OperationContextImpl txn;
OpTime originalEndOpTime(getMinValid(&txn).end);
while (!inShutdown()) {
OpQueue ops;
Timer batchTimer;
int lastTimeChecked = 0;
do {
int now = batchTimer.seconds();
// apply replication batch limits
if (!ops.empty()) {
if (now > replBatchLimitSeconds)
break;
if (ops.getDeque().size() > replBatchLimitOperations)
break;
}
// occasionally check some things
// (always checked in the first iteration of this do-while loop, because
// ops is empty)
if (ops.empty() || now > lastTimeChecked) {
BackgroundSync* bgsync = BackgroundSync::get();
if (bgsync->getInitialSyncRequestedFlag()) {
// got a resync command
return;
}
lastTimeChecked = now;
// can we become secondary?
// we have to check this before calling mgr, as we must be a secondary to
// become primary
tryToGoLiveAsASecondary(&txn, replCoord);
}
const int slaveDelaySecs = durationCount<Seconds>(replCoord->getSlaveDelaySecs());
if (!ops.empty() && slaveDelaySecs > 0) {
const BSONObj lastOp = ops.back();
const unsigned int opTimestampSecs = lastOp["ts"].timestamp().getSecs();
// Stop the batch as the lastOp is too new to be applied. If we continue
// on, we can get ops that are way ahead of the delay and this will
// make this thread sleep longer when handleSlaveDelay is called
// and apply ops much sooner than we like.
if (opTimestampSecs > static_cast<unsigned int>(time(0) - slaveDelaySecs)) {
break;
}
}
if (MONGO_FAIL_POINT(rsSyncApplyStop)) {
break;
}
// keep fetching more ops as long as we haven't filled up a full batch yet
} while (!tryPopAndWaitForMore(&txn, &ops, replCoord) && // tryPopAndWaitForMore returns
// true when we need to end a
// batch early
(ops.getSize() < replBatchLimitBytes) &&
!inShutdown());
// For pausing replication in tests
while (MONGO_FAIL_POINT(rsSyncApplyStop)) {
sleepmillis(0);
if (inShutdown())
return;
}
if (ops.empty()) {
continue;
}
const BSONObj lastOp = ops.back();
handleSlaveDelay(lastOp);
// Set minValid to the last OpTime that needs to be applied, in this batch or from the
// (last) failed batch, whichever is larger.
// This will cause this node to go into RECOVERING state
// if we should crash and restart before updating finishing.
const OpTime start(getLastSetTimestamp(), OpTime::kUninitializedTerm);
// Take the max of the first endOptime (if we recovered) and the end of our batch.
const auto lastOpTime = fassertStatusOK(28773, OpTime::parseFromOplogEntry(lastOp));
// Setting end to the max of originalEndOpTime and lastOpTime (the end of the batch)
// ensures that we keep pushing out the point where we can become consistent
// and allow reads. If we recover and end up doing smaller batches we must pass the
// originalEndOpTime before we are good.
//
// For example:
// batch apply, 20-40, end = 40
// batch failure,
// restart
// batch apply, 20-25, end = max(25, 40) = 40
// batch apply, 25-45, end = 45
const OpTime end(std::max(originalEndOpTime, lastOpTime));
// This write will not journal/checkpoint.
setMinValid(&txn, {start, end});
OpTime finalOpTime = multiApply(&txn, ops);
setNewTimestamp(finalOpTime.getTimestamp());
setMinValid(&txn, end, DurableRequirement::None);
finalizer.record(finalOpTime);
}
}
void BackgroundSync::_produce(OperationContext* txn) {
// this oplog reader does not do a handshake because we don't want the server it's syncing
// from to track how far it has synced
{
stdx::unique_lock<stdx::mutex> lock(_mutex);
if (_lastOpTimeFetched.isNull()) {
// then we're initial syncing and we're still waiting for this to be set
lock.unlock();
sleepsecs(1);
// if there is no one to sync from
return;
}
if (_replCoord->isWaitingForApplierToDrain() || _replCoord->getMemberState().primary() ||
inShutdownStrict()) {
return;
}
}
while (MONGO_FAIL_POINT(rsBgSyncProduce)) {
sleepmillis(0);
}
// find a target to sync from the last optime fetched
OpTime lastOpTimeFetched;
HostAndPort source;
{
stdx::unique_lock<stdx::mutex> lock(_mutex);
lastOpTimeFetched = _lastOpTimeFetched;
_syncSourceHost = HostAndPort();
}
SyncSourceResolverResponse syncSourceResp =
_syncSourceResolver.findSyncSource(txn, lastOpTimeFetched);
if (syncSourceResp.syncSourceStatus == ErrorCodes::OplogStartMissing) {
// All (accessible) sync sources were too stale.
error() << "too stale to catch up -- entering maintenance mode";
log() << "Our newest OpTime : " << lastOpTimeFetched;
log() << "Earliest OpTime available is " << syncSourceResp.earliestOpTimeSeen;
log() << "See http://dochub.mongodb.org/core/resyncingaverystalereplicasetmember";
setMinValid(txn, {lastOpTimeFetched, syncSourceResp.earliestOpTimeSeen});
auto status = _replCoord->setMaintenanceMode(true);
if (!status.isOK()) {
warning() << "Failed to transition into maintenance mode.";
}
bool worked = _replCoord->setFollowerMode(MemberState::RS_RECOVERING);
if (!worked) {
warning() << "Failed to transition into " << MemberState(MemberState::RS_RECOVERING)
<< ". Current state: " << _replCoord->getMemberState();
}
return;
} else if (syncSourceResp.isOK() && !syncSourceResp.getSyncSource().empty()) {
stdx::lock_guard<stdx::mutex> lock(_mutex);
_syncSourceHost = syncSourceResp.getSyncSource();
source = _syncSourceHost;
} else {
if (!syncSourceResp.isOK()) {
log() << "failed to find sync source, received error "
<< syncSourceResp.syncSourceStatus.getStatus();
}
// No sync source found.
sleepsecs(1);
return;
}
long long lastHashFetched;
{
stdx::lock_guard<stdx::mutex> lock(_mutex);
if (_stopped) {
return;
}
lastOpTimeFetched = _lastOpTimeFetched;
lastHashFetched = _lastFetchedHash;
_replCoord->signalUpstreamUpdater();
}
const auto isV1ElectionProtocol = _replCoord->isV1ElectionProtocol();
// Under protocol version 1, make the awaitData timeout (maxTimeMS) dependent on the election
// timeout. This enables the sync source to communicate liveness of the primary to secondaries.
// Under protocol version 0, use a default timeout of 2 seconds for awaitData.
const Milliseconds fetcherMaxTimeMS(
isV1ElectionProtocol ? _replCoord->getConfig().getElectionTimeoutPeriod() / 2 : Seconds(2));
Status fetcherReturnStatus = Status::OK();
auto fetcherCallback = stdx::bind(&BackgroundSync::_fetcherCallback,
this,
stdx::placeholders::_1,
stdx::placeholders::_3,
stdx::cref(source),
lastOpTimeFetched,
lastHashFetched,
fetcherMaxTimeMS,
&fetcherReturnStatus);
BSONObjBuilder cmdBob;
cmdBob.append("find", nsToCollectionSubstring(rsOplogName));
cmdBob.append("filter", BSON("ts" << BSON("$gte" << lastOpTimeFetched.getTimestamp())));
cmdBob.append("tailable", true);
cmdBob.append("oplogReplay", true);
cmdBob.append("awaitData", true);
cmdBob.append("maxTimeMS", durationCount<Milliseconds>(Minutes(1))); // 1 min initial find.
BSONObjBuilder metadataBob;
if (isV1ElectionProtocol) {
cmdBob.append("term", _replCoord->getTerm());
metadataBob.append(rpc::kReplSetMetadataFieldName, 1);
}
auto dbName = nsToDatabase(rsOplogName);
auto cmdObj = cmdBob.obj();
auto metadataObj = metadataBob.obj();
Fetcher fetcher(&_threadPoolTaskExecutor,
source,
dbName,
cmdObj,
fetcherCallback,
metadataObj,
_replCoord->getConfig().getElectionTimeoutPeriod());
LOG(1) << "scheduling fetcher to read remote oplog on " << source << " starting at "
<< cmdObj["filter"];
auto scheduleStatus = fetcher.schedule();
if (!scheduleStatus.isOK()) {
warning() << "unable to schedule fetcher to read remote oplog on " << source << ": "
<< scheduleStatus;
return;
}
fetcher.wait();
LOG(1) << "fetcher stopped reading remote oplog on " << source;
// If the background sync is stopped after the fetcher is started, we need to
// re-evaluate our sync source and oplog common point.
if (isStopped()) {
return;
}
if (fetcherReturnStatus.code() == ErrorCodes::OplogOutOfOrder) {
// This is bad because it means that our source
// has not returned oplog entries in ascending ts order, and they need to be.
warning() << fetcherReturnStatus.toString();
// Do not blacklist the server here, it will be blacklisted when we try to reuse it,
// if it can't return a matching oplog start from the last fetch oplog ts field.
return;
} else if (fetcherReturnStatus.code() == ErrorCodes::OplogStartMissing ||
fetcherReturnStatus.code() == ErrorCodes::RemoteOplogStale) {
// Rollback is a synchronous operation that uses the task executor and may not be
// executed inside the fetcher callback.
const int messagingPortTags = 0;
ConnectionPool connectionPool(messagingPortTags);
std::unique_ptr<ConnectionPool::ConnectionPtr> connection;
auto getConnection = [&connection, &connectionPool, source]() -> DBClientBase* {
if (!connection.get()) {
connection.reset(new ConnectionPool::ConnectionPtr(
&connectionPool, source, Date_t::now(), oplogSocketTimeout));
};
return connection->get();
};
{
stdx::lock_guard<stdx::mutex> lock(_mutex);
lastOpTimeFetched = _lastOpTimeFetched;
}
log() << "Starting rollback due to " << fetcherReturnStatus;
// Wait till all buffered oplog entries have drained and been applied.
auto lastApplied = _replCoord->getMyLastAppliedOpTime();
if (lastApplied != lastOpTimeFetched) {
log() << "Waiting for all operations from " << lastApplied << " until "
<< lastOpTimeFetched << " to be applied before starting rollback.";
while (lastOpTimeFetched > (lastApplied = _replCoord->getMyLastAppliedOpTime())) {
sleepmillis(10);
if (isStopped() || inShutdown()) {
return;
}
}
}
// check that we are at minvalid, otherwise we cannot roll back as we may be in an
// inconsistent state
BatchBoundaries boundaries = getMinValid(txn);
if (!boundaries.start.isNull() || boundaries.end > lastApplied) {
fassertNoTrace(18750,
Status(ErrorCodes::UnrecoverableRollbackError,
str::stream()
<< "need to rollback, but in inconsistent state. "
<< "minvalid: " << boundaries.end.toString()
<< " > our last optime: " << lastApplied.toString()));
}
_rollback(txn, source, getConnection);
stop();
} else if (fetcherReturnStatus == ErrorCodes::InvalidBSON) {
Seconds blacklistDuration(60);
warning() << "Fetcher got invalid BSON while querying oplog. Blacklisting sync source "
<< source << " for " << blacklistDuration << ".";
_replCoord->blacklistSyncSource(source, Date_t::now() + blacklistDuration);
} else if (!fetcherReturnStatus.isOK()) {
warning() << "Fetcher error querying oplog: " << fetcherReturnStatus.toString();
}
}
/* tail an oplog. ok to return, will be re-called. */
void SyncTail::oplogApplication() {
OpQueueBatcher batcher(this);
OperationContextImpl txn;
auto replCoord = ReplicationCoordinator::get(&txn);
ApplyBatchFinalizer finalizer(replCoord);
auto minValidBoundaries = getMinValid(&txn);
OpTime originalEndOpTime(minValidBoundaries.end);
OpTime lastWriteOpTime{replCoord->getMyLastOptime()};
while (!inShutdown()) {
OpQueue ops;
do {
if (BackgroundSync::get()->getInitialSyncRequestedFlag()) {
// got a resync command
return;
}
tryToGoLiveAsASecondary(&txn, replCoord, minValidBoundaries, lastWriteOpTime);
// Blocks up to a second waiting for a batch to be ready to apply. If one doesn't become
// ready in time, we'll loop again so we can do the above checks periodically.
ops = batcher.getNextBatch(Seconds(1));
} while (!inShutdown() && ops.empty());
if (inShutdown())
return;
invariant(!ops.empty());
const BSONObj lastOp = ops.back().raw;
if (lastOp.isEmpty()) {
// This means that the network thread has coalesced and we have processed all of its
// data.
invariant(ops.getDeque().size() == 1);
if (replCoord->isWaitingForApplierToDrain()) {
replCoord->signalDrainComplete(&txn);
}
continue; // This wasn't a real op. Don't try to apply it.
}
handleSlaveDelay(lastOp);
// Set minValid to the last OpTime that needs to be applied, in this batch or from the
// (last) failed batch, whichever is larger.
// This will cause this node to go into RECOVERING state
// if we should crash and restart before updating finishing.
const OpTime start(getLastSetTimestamp(), OpTime::kUninitializedTerm);
// Take the max of the first endOptime (if we recovered) and the end of our batch.
const auto lastOpTime = fassertStatusOK(28773, OpTime::parseFromOplogEntry(lastOp));
// Setting end to the max of originalEndOpTime and lastOpTime (the end of the batch)
// ensures that we keep pushing out the point where we can become consistent
// and allow reads. If we recover and end up doing smaller batches we must pass the
// originalEndOpTime before we are good.
//
// For example:
// batch apply, 20-40, end = 40
// batch failure,
// restart
// batch apply, 20-25, end = max(25, 40) = 40
// batch apply, 25-45, end = 45
const OpTime end(std::max(originalEndOpTime, lastOpTime));
// This write will not journal/checkpoint.
setMinValid(&txn, {start, end});
lastWriteOpTime = multiApply(&txn, ops);
setNewTimestamp(lastWriteOpTime.getTimestamp());
setMinValid(&txn, end, DurableRequirement::None);
minValidBoundaries.start = {};
minValidBoundaries.end = end;
finalizer.record(lastWriteOpTime);
}
}
