/**
* Copyright (C) 2008 10gen Inc.
*
* This program is free software: you can redistribute it and/or modify
* it under the terms of the GNU Affero General Public License, version 3,
* as published by the Free Software Foundation.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU Affero General Public License for more details.
*
* You should have received a copy of the GNU Affero General Public License
* along with this program. If not, see .
*
* As a special exception, the copyright holders give permission to link the
* code of portions of this program with the OpenSSL library under certain
* conditions as described in each individual source file and distribute
* linked combinations including the program with the OpenSSL library. You
* must comply with the GNU Affero General Public License in all respects for
* all of the code used other than as permitted herein. If you modify file(s)
* with this exception, you may extend this exception to your version of the
* file(s), but you are not obligated to do so. If you do not wish to do so,
* delete this exception statement from your version. If you delete this
* exception statement from all source files in the program, then also delete
* it in the license file.
*/
#define MONGO_LOG_DEFAULT_COMPONENT ::mongo::logger::LogComponent::kReplication
#include "mongo/platform/basic.h"
#include "mongo/platform/bits.h"
#include "mongo/db/repl/sync_tail.h"
#include
#include
#include "third_party/murmurhash3/MurmurHash3.h"
#include "mongo/base/counter.h"
#include "mongo/db/auth/authorization_session.h"
#include "mongo/db/catalog/collection.h"
#include "mongo/db/catalog/database_holder.h"
#include "mongo/db/catalog/database.h"
#include "mongo/db/catalog/document_validation.h"
#include "mongo/db/commands/fsync.h"
#include "mongo/db/commands/server_status_metric.h"
#include "mongo/db/concurrency/d_concurrency.h"
#include "mongo/db/concurrency/write_conflict_exception.h"
#include "mongo/db/dbhelpers.h"
#include "mongo/db/curop.h"
#include "mongo/db/db_raii.h"
#include "mongo/db/global_timestamp.h"
#include "mongo/db/operation_context_impl.h"
#include "mongo/db/prefetch.h"
#include "mongo/db/query/query_knobs.h"
#include "mongo/db/repl/bgsync.h"
#include "mongo/db/repl/minvalid.h"
#include "mongo/db/repl/oplog.h"
#include "mongo/db/repl/oplogreader.h"
#include "mongo/db/repl/repl_client_info.h"
#include "mongo/db/repl/replica_set_config.h"
#include "mongo/db/repl/replication_coordinator_global.h"
#include "mongo/db/server_parameters.h"
#include "mongo/db/service_context.h"
#include "mongo/db/stats/timer_stats.h"
#include "mongo/util/exit.h"
#include "mongo/util/fail_point_service.h"
#include "mongo/util/log.h"
#include "mongo/util/mongoutils/str.h"
#include "mongo/util/scopeguard.h"
namespace mongo {
using std::endl;
namespace repl {
#if defined(MONGO_PLATFORM_64)
int SyncTail::replWriterThreadCount = 16;
const int replPrefetcherThreadCount = 16;
#elif defined(MONGO_PLATFORM_32)
int SyncTail::replWriterThreadCount = 2;
const int replPrefetcherThreadCount = 2;
#else
#error need to include something that defines MONGO_PLATFORM_XX
#endif
class ExportedWriterThreadCountParameter
: public ExportedServerParameter {
public:
ExportedWriterThreadCountParameter()
: ExportedServerParameter(
ServerParameterSet::getGlobal(),
"replWriterThreadCount",
&SyncTail::replWriterThreadCount) {}
virtual Status validate(const int& potentialNewValue) {
if (potentialNewValue < 1 || potentialNewValue > 256) {
return Status(ErrorCodes::BadValue, "replWriterThreadCount must be between 1 and 256");
}
return Status::OK();
}
} exportedWriterThreadCountParam;
static Counter64 opsAppliedStats;
// The oplog entries applied
static ServerStatusMetricField displayOpsApplied("repl.apply.ops", &opsAppliedStats);
MONGO_FP_DECLARE(rsSyncApplyStop);
// Number and time of each ApplyOps worker pool round
static TimerStats applyBatchStats;
static ServerStatusMetricField displayOpBatchesApplied("repl.apply.batches",
&applyBatchStats);
void initializePrefetchThread() {
if (!ClientBasic::getCurrent()) {
Client::initThreadIfNotAlready();
AuthorizationSession::get(cc())->grantInternalAuthorization();
}
}
namespace {
bool isCrudOpType(const char* field) {
switch (field[0]) {
case 'd':
case 'i':
case 'u':
return field[1] == 0;
}
return false;
}
void handleSlaveDelay(const Timestamp& ts) {
ReplicationCoordinator* replCoord = getGlobalReplicationCoordinator();
int slaveDelaySecs = durationCount(replCoord->getSlaveDelaySecs());
// ignore slaveDelay if the box is still initializing. once
// it becomes secondary we can worry about it.
if (slaveDelaySecs > 0 && replCoord->getMemberState().secondary()) {
long long a = ts.getSecs();
long long b = time(0);
long long lag = b - a;
long long sleeptime = slaveDelaySecs - lag;
if (sleeptime > 0) {
uassert(12000,
"rs slaveDelay differential too big check clocks and systems",
sleeptime < 0x40000000);
if (sleeptime < 60) {
sleepsecs((int)sleeptime);
} else {
warning() << "slavedelay causing a long sleep of " << sleeptime << " seconds";
// sleep(hours) would prevent reconfigs from taking effect & such!
long long waitUntil = b + sleeptime;
while (time(0) < waitUntil) {
sleepsecs(6);
// Handle reconfigs that changed the slave delay
if (durationCount(replCoord->getSlaveDelaySecs()) != slaveDelaySecs)
break;
}
}
}
} // endif slaveDelay
}
}
namespace {
class ApplyBatchFinalizer {
public:
ApplyBatchFinalizer(ReplicationCoordinator* replCoord);
~ApplyBatchFinalizer();
/**
* In PV0, calls ReplicationCoordinator::setMyLastOptime with "newOp".
* In PV1, sets _latestOpTime to be "newOp" and signals the _waiterThread.
*/
void record(OpTime newOp);
private:
/**
* Loops continuously, waiting for writes to be flushed to disk and then calls
* ReplicationCoordinator::setMyLastOptime with _latestOpTime.
* Terminates once _shutdownSignaled is set true.
*/
void _run();
// Used to update the replication system's progress.
ReplicationCoordinator* _replCoord;
// Protects _cond, _shutdownSignaled, and _latestOpTime.
stdx::mutex _mutex;
// Used to alert our thread of a new OpTime.
stdx::condition_variable _cond;
// The next OpTime to set as the ReplicationCoordinator's lastOpTime after flushing.
OpTime _latestOpTime;
// Once this is set to true the _run method will terminate.
bool _shutdownSignaled;
// Thread that will _run(). Must be initialized last as it depends on the other variables.
stdx::thread _waiterThread;
};
ApplyBatchFinalizer::ApplyBatchFinalizer(ReplicationCoordinator* replCoord)
: _replCoord(replCoord),
_shutdownSignaled(false),
_waiterThread(&ApplyBatchFinalizer::_run, this) {}
ApplyBatchFinalizer::~ApplyBatchFinalizer() {
stdx::unique_lock lock(_mutex);
_shutdownSignaled = true;
_cond.notify_all();
lock.unlock();
_waiterThread.join();
}
void ApplyBatchFinalizer::record(OpTime newOp) {
// We have to use setMyLastAppliedOpTimeForward since this thread races with
// logTransitionToPrimaryToOplog.
_replCoord->setMyLastAppliedOpTimeForward(newOp);
stdx::unique_lock lock(_mutex);
_latestOpTime = newOp;
_cond.notify_all();
}
void ApplyBatchFinalizer::_run() {
Client::initThread("ApplyBatchFinalizer");
while (true) {
OpTime latestOpTime;
{
stdx::unique_lock lock(_mutex);
while (_latestOpTime.isNull() && !_shutdownSignaled) {
_cond.wait(lock);
}
if (_shutdownSignaled) {
return;
}
latestOpTime = _latestOpTime;
_latestOpTime = OpTime();
}
auto txn = cc().makeOperationContext();
txn->recoveryUnit()->goingToWaitUntilDurable();
txn->recoveryUnit()->waitUntilDurable();
// We have to use setMyLastDurableOpTimeForward since this thread races with
// logTransitionToPrimaryToOplog.
_replCoord->setMyLastDurableOpTimeForward(latestOpTime);
}
}
} // anonymous namespace containing ApplyBatchFinalizer definitions.
SyncTail::SyncTail(BackgroundSyncInterface* q, MultiSyncApplyFunc func)
: _networkQueue(q),
_applyFunc(func),
_writerPool(replWriterThreadCount, "repl writer worker "),
_prefetcherPool(replPrefetcherThreadCount, "repl prefetch worker ") {}
SyncTail::~SyncTail() {}
bool SyncTail::peek(BSONObj* op) {
return _networkQueue->peek(op);
}
// static
Status SyncTail::syncApply(OperationContext* txn,
const BSONObj& op,
bool convertUpdateToUpsert,
ApplyOperationInLockFn applyOperationInLock,
ApplyCommandInLockFn applyCommandInLock,
IncrementOpsAppliedStatsFn incrementOpsAppliedStats) {
if (inShutdown()) {
return Status::OK();
}
// Count each log op application as a separate operation, for reporting purposes
CurOp individualOp(txn);
const char* ns = op.getStringField("ns");
verify(ns);
const char* opType = op["op"].valuestrsafe();
bool isCommand(opType[0] == 'c');
bool isNoOp(opType[0] == 'n');
if ((*ns == '\0') || (*ns == '.')) {
// this is ugly
// this is often a no-op
// but can't be 100% sure
if (!isNoOp) {
error() << "skipping bad op in oplog: " << op.toString();
}
return Status::OK();
}
if (isCommand) {
MONGO_WRITE_CONFLICT_RETRY_LOOP_BEGIN {
// a command may need a global write lock. so we will conservatively go
// ahead and grab one here. suboptimal. :-(
Lock::GlobalWrite globalWriteLock(txn->lockState());
// special case apply for commands to avoid implicit database creation
Status status = applyCommandInLock(txn, op);
incrementOpsAppliedStats();
return status;
}
MONGO_WRITE_CONFLICT_RETRY_LOOP_END(txn, "syncApply_command", ns);
}
auto applyOp = [&](Database* db) {
// For non-initial-sync, we convert updates to upserts
// to suppress errors when replaying oplog entries.
txn->setReplicatedWrites(false);
DisableDocumentValidation validationDisabler(txn);
Status status =
applyOperationInLock(txn, db, op, convertUpdateToUpsert, incrementOpsAppliedStats);
if (!status.isOK() && status.code() == ErrorCodes::WriteConflict) {
throw WriteConflictException();
}
return status;
};
if (isNoOp || (opType[0] == 'i' && nsToCollectionSubstring(ns) == "system.indexes")) {
auto opStr = isNoOp ? "syncApply_noop" : "syncApply_indexBuild";
MONGO_WRITE_CONFLICT_RETRY_LOOP_BEGIN {
Lock::DBLock dbLock(txn->lockState(), nsToDatabaseSubstring(ns), MODE_X);
OldClientContext ctx(txn, ns);
return applyOp(ctx.db());
}
MONGO_WRITE_CONFLICT_RETRY_LOOP_END(txn, opStr, ns);
}
if (isCrudOpType(opType)) {
MONGO_WRITE_CONFLICT_RETRY_LOOP_BEGIN {
// DB lock always acquires the global lock
std::unique_ptr dbLock;
std::unique_ptr collectionLock;
std::unique_ptr ctx;
auto dbName = nsToDatabaseSubstring(ns);
auto resetLocks = [&](LockMode mode) {
collectionLock.reset();
dbLock.reset(new Lock::DBLock(txn->lockState(), dbName, mode));
collectionLock.reset(new Lock::CollectionLock(txn->lockState(), ns, mode));
};
resetLocks(MODE_IX);
if (!dbHolder().get(txn, dbName)) {
// need to create database, try again
resetLocks(MODE_X);
ctx.reset(new OldClientContext(txn, ns));
} else {
ctx.reset(new OldClientContext(txn, ns));
if (!ctx->db()->getCollection(ns)) {
// uh, oh, we need to create collection
// try again
ctx.reset();
resetLocks(MODE_X);
ctx.reset(new OldClientContext(txn, ns));
}
}
return applyOp(ctx->db());
}
MONGO_WRITE_CONFLICT_RETRY_LOOP_END(txn, "syncApply_CRUD", ns);
}
// unknown opType
str::stream ss;
ss << "bad opType '" << opType << "' in oplog entry: " << op.toString();
error() << std::string(ss);
return Status(ErrorCodes::BadValue, ss);
}
Status SyncTail::syncApply(OperationContext* txn, const BSONObj& op, bool convertUpdateToUpsert) {
return SyncTail::syncApply(txn,
op,
convertUpdateToUpsert,
applyOperation_inlock,
applyCommand_inlock,
stdx::bind(&Counter64::increment, &opsAppliedStats, 1ULL));
}
namespace {
// The pool threads call this to prefetch each op
void prefetchOp(const BSONObj& op) {
initializePrefetchThread();
const char* ns = op.getStringField("ns");
if (ns && (ns[0] != '\0')) {
try {
// one possible tweak here would be to stay in the read lock for this database
// for multiple prefetches if they are for the same database.
OperationContextImpl txn;
AutoGetCollectionForRead ctx(&txn, ns);
Database* db = ctx.getDb();
if (db) {
prefetchPagesForReplicatedOp(&txn, db, op);
}
} catch (const DBException& e) {
LOG(2) << "ignoring exception in prefetchOp(): " << e.what() << endl;
} catch (const std::exception& e) {
log() << "Unhandled std::exception in prefetchOp(): " << e.what() << endl;
fassertFailed(16397);
}
}
}
// Doles out all the work to the reader pool threads and waits for them to complete
void prefetchOps(const std::deque& ops, OldThreadPool* prefetcherPool) {
invariant(prefetcherPool);
for (auto&& op : ops) {
prefetcherPool->schedule(&prefetchOp, op.raw);
}
prefetcherPool->join();
}
// Doles out all the work to the writer pool threads and waits for them to complete
void applyOps(const std::vector>& writerVectors,
OldThreadPool* writerPool,
SyncTail::MultiSyncApplyFunc func,
SyncTail* sync) {
TimerHolder timer(&applyBatchStats);
for (std::vector>::const_iterator it = writerVectors.begin();
it != writerVectors.end();
++it) {
if (!it->empty()) {
writerPool->schedule(func, stdx::cref(*it), sync);
}
}
}
/**
* A caching functor that returns true if a namespace refers to a capped collection.
* Collections that don't exist are implicitly not capped.
*/
class CachingCappedChecker {
public:
bool operator()(OperationContext* txn, const StringMapTraits::HashedKey& ns) {
auto it = _cache.find(ns);
if (it != _cache.end()) {
return it->second;
}
bool isCapped = isCappedImpl(txn, ns.key());
_cache[ns] = isCapped;
return isCapped;
}
private:
bool isCappedImpl(OperationContext* txn, StringData ns) {
auto db = dbHolder().get(txn, ns);
if (!db)
return false;
auto collection = db->getCollection(ns);
return collection && collection->isCapped();
}
StringMap _cache;
};
void fillWriterVectors(OperationContext* txn,
const std::deque& ops,
std::vector>* writerVectors) {
const bool supportsDocLocking =
getGlobalServiceContext()->getGlobalStorageEngine()->supportsDocLocking();
const uint32_t numWriters = writerVectors->size();
Lock::GlobalRead globalReadLock(txn->lockState());
CachingCappedChecker isCapped;
for (auto&& op : ops) {
StringMapTraits::HashedKey hashedNs(op.ns);
uint32_t hash = hashedNs.hash();
const char* opType = op.opType.rawData();
// For doc locking engines, include the _id of the document in the hash so we get
// parallelism even if all writes are to a single collection. We can't do this for capped
// collections because the order of inserts is a guaranteed property, unlike for normal
// collections.
if (supportsDocLocking && isCrudOpType(opType) && !isCapped(txn, hashedNs)) {
BSONElement id;
switch (opType[0]) {
case 'u':
id = op.o2.Obj()["_id"];
break;
case 'd':
case 'i':
id = op.o.Obj()["_id"];
break;
}
const size_t idHash = BSONElement::Hasher()(id);
MurmurHash3_x86_32(&idHash, sizeof(idHash), hash, &hash);
}
(*writerVectors)[hash % numWriters].push_back(op.raw);
}
}
} // namespace
// Applies a batch of oplog entries, by using a set of threads to apply the operations and then
// writes the oplog entries to the local oplog.
OpTime SyncTail::multiApply(OperationContext* txn, const OpQueue& ops) {
invariant(_applyFunc);
if (getGlobalServiceContext()->getGlobalStorageEngine()->isMmapV1()) {
// Use a ThreadPool to prefetch all the operations in a batch.
prefetchOps(ops.getDeque(), &_prefetcherPool);
}
std::vector> writerVectors(replWriterThreadCount);
fillWriterVectors(txn, ops.getDeque(), &writerVectors);
LOG(2) << "replication batch size is " << ops.getDeque().size() << endl;
// We must grab this because we're going to grab write locks later.
// We hold this mutex the entire time we're writing; it doesn't matter
// because all readers are blocked anyway.
stdx::lock_guard fsynclk(filesLockedFsync);
// stop all readers until we're done
Lock::ParallelBatchWriterMode pbwm(txn->lockState());
ReplicationCoordinator* replCoord = getGlobalReplicationCoordinator();
if (replCoord->getMemberState().primary() && !replCoord->isWaitingForApplierToDrain()) {
severe() << "attempting to replicate ops while primary";
fassertFailed(28527);
}
applyOps(writerVectors, &_writerPool, _applyFunc, this);
OpTime lastOpTime;
{
ON_BLOCK_EXIT([&] { _writerPool.join(); });
std::vector raws;
raws.reserve(ops.getDeque().size());
for (auto&& op : ops.getDeque()) {
raws.emplace_back(op.raw);
}
lastOpTime = writeOpsToOplog(txn, raws);
}
if (inShutdownStrict()) {
log() << "Cannot apply operations due to shutdown in progress";
return OpTime();
}
// We have now written all database writes and updated the oplog to match.
return lastOpTime;
}
namespace {
void tryToGoLiveAsASecondary(OperationContext* txn,
ReplicationCoordinator* replCoord,
const BatchBoundaries& minValidBoundaries,
const OpTime& lastWriteOpTime) {
if (replCoord->isInPrimaryOrSecondaryState()) {
return;
}
ScopedTransaction transaction(txn, MODE_S);
Lock::GlobalRead readLock(txn->lockState());
if (replCoord->getMaintenanceMode()) {
// we're not actually going live
return;
}
// Only state RECOVERING can transition to SECONDARY.
MemberState state(replCoord->getMemberState());
if (!state.recovering()) {
return;
}
// If an apply batch is active then we cannot transition.
if (!minValidBoundaries.start.isNull()) {
return;
}
// Must have applied/written to minvalid, so return if not.
// -- If 'lastWriteOpTime' is null/uninitialized then we can't transition.
// -- If 'lastWriteOpTime' is less than the end of the last batch then we can't transition.
if (lastWriteOpTime.isNull() || minValidBoundaries.end > lastWriteOpTime) {
return;
}
bool worked = replCoord->setFollowerMode(MemberState::RS_SECONDARY);
if (!worked) {
warning() << "Failed to transition into " << MemberState(MemberState::RS_SECONDARY)
<< ". Current state: " << replCoord->getMemberState();
}
}
}
class SyncTail::OpQueueBatcher {
MONGO_DISALLOW_COPYING(OpQueueBatcher);
public:
explicit OpQueueBatcher(SyncTail* syncTail) : _syncTail(syncTail), _thread([&] { run(); }) {}
~OpQueueBatcher() {
_inShutdown.store(true);
_cv.notify_all();
_thread.join();
}
OpQueue getNextBatch(Seconds maxWaitTime) {
stdx::unique_lock lk(_mutex);
if (_ops.empty()) {
// We intentionally don't care about whether this returns due to signaling or timeout
// since we do the same thing either way: return whatever is in _ops.
(void)_cv.wait_for(lk, maxWaitTime);
}
OpQueue ops = std::move(_ops);
_ops = {};
_cv.notify_all();
return ops;
}
private:
void run() {
Client::initThread("ReplBatcher");
OperationContextImpl txn;
auto replCoord = ReplicationCoordinator::get(&txn);
while (!_inShutdown.load()) {
Timer batchTimer;
OpQueue ops;
// tryPopAndWaitForMore returns true when we need to end a batch early
while (!_syncTail->tryPopAndWaitForMore(&txn, &ops) &&
(ops.getSize() < replBatchLimitBytes) && !_inShutdown.load()) {
int now = batchTimer.seconds();
// apply replication batch limits
if (!ops.empty()) {
if (now > replBatchLimitSeconds)
break;
if (ops.getDeque().size() > replBatchLimitOperations)
break;
}
const int slaveDelaySecs = durationCount(replCoord->getSlaveDelaySecs());
if (!ops.empty() && slaveDelaySecs > 0) {
const BSONObj lastOp = ops.back().raw;
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(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
}
// For pausing replication in tests
while (MONGO_FAIL_POINT(rsSyncApplyStop) && !_inShutdown.load()) {
sleepmillis(0);
}
stdx::unique_lock lk(_mutex);
while (!_ops.empty()) {
// Block until the previous batch has been taken.
if (_inShutdown.load())
return;
_cv.wait(lk);
}
_ops = std::move(ops);
_cv.notify_all();
}
}
AtomicWord _inShutdown;
SyncTail* const _syncTail;
stdx::mutex _mutex; // Guards _ops.
stdx::condition_variable _cv;
OpQueue _ops;
stdx::thread _thread; // Must be last so all other members are initialized before starting.
};
/* 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->getMyLastAppliedOpTime()};
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);
}
// Reset when triggered in case it was from a rollback, safe to do at any time.
lastWriteOpTime = replCoord->getMyLastAppliedOpTime();
continue; // This wasn't a real op. Don't try to apply it.
}
const auto lastOpTime = fassertStatusOK(28773, OpTime::parseFromOplogEntry(lastOp));
if (lastWriteOpTime >= lastOpTime) {
// Error for the oplog to go back in time.
fassert(34361,
Status(ErrorCodes::OplogOutOfOrder,
str::stream() << "Attempted to apply an oplog entry ("
<< lastOpTime.toString()
<< ") which is not greater than our lastWrittenOptime ("
<< lastWriteOpTime.toString() << ")."));
}
handleSlaveDelay(lastOpTime.getTimestamp());
// 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.
// 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);
if (lastWriteOpTime.isNull()) {
// fassert if oplog application failed for any reasons other than shutdown.
error() << "Failed to apply " << ops.getDeque().size()
<< " operations - batch start:" << start << " end:" << end;
fassert(34360, inShutdownStrict());
// Return without setting minvalid in the case of shutdown.
return;
}
setNewTimestamp(lastWriteOpTime.getTimestamp());
setMinValid(&txn, end, DurableRequirement::None);
minValidBoundaries.start = {};
minValidBoundaries.end = end;
finalizer.record(lastWriteOpTime);
}
}
SyncTail::OplogEntry::OplogEntry(const BSONObj& rawInput) : raw(rawInput.getOwned()) {
for (auto elem : raw) {
const auto name = elem.fieldNameStringData();
if (name == "ns") {
ns = elem.valuestrsafe();
} else if (name == "op") {
opType = elem.valuestrsafe();
} else if (name == "o2") {
o2 = elem;
} else if (name == "v") {
version = elem;
} else if (name == "o") {
o = elem;
}
}
}
// Copies ops out of the bgsync queue into the deque passed in as a parameter.
// Returns true if the batch should be ended early.
// Batch should end early if we encounter a command, or if
// there are no further ops in the bgsync queue to read.
// This function also blocks 1 second waiting for new ops to appear in the bgsync
// queue. We can't block forever because there are maintenance things we need
// to periodically check in the loop.
bool SyncTail::tryPopAndWaitForMore(OperationContext* txn, SyncTail::OpQueue* ops) {
BSONObj op;
// Check to see if there are ops waiting in the bgsync queue
bool peek_success = peek(&op);
if (!peek_success) {
// if we don't have anything in the queue, wait a bit for something to appear
if (ops->empty()) {
// block up to 1 second
_networkQueue->waitForMore();
return false;
}
// otherwise, apply what we have
return true;
}
auto entry = OplogEntry(op);
// Check for ops that must be processed one at a time.
if (entry.raw.isEmpty() || // sentinel that network queue is drained.
(entry.opType[0] == 'c') || // commands.
// Index builds are acheived through the use of an insert op, not a command op.
// The following line is the same as what the insert code uses to detect an index build.
(!entry.ns.empty() && nsToCollectionSubstring(entry.ns) == "system.indexes")) {
if (ops->empty()) {
// apply commands one-at-a-time
ops->push_back(std::move(entry));
_networkQueue->consume();
}
// otherwise, apply what we have so far and come back for the command
return true;
}
// check for oplog version change
int curVersion = 0;
if (entry.version.eoo())
// missing version means version 1
curVersion = 1;
else
curVersion = entry.version.Int();
if (curVersion != OPLOG_VERSION) {
severe() << "expected oplog version " << OPLOG_VERSION << " but found version "
<< curVersion << " in oplog entry: " << op;
fassertFailedNoTrace(18820);
}
// Copy the op to the deque and remove it from the bgsync queue.
ops->push_back(std::move(entry));
_networkQueue->consume();
// Go back for more ops
return false;
}
void SyncTail::setHostname(const std::string& hostname) {
_hostname = hostname;
}
BSONObj SyncTail::getMissingDoc(OperationContext* txn, Database* db, const BSONObj& o) {
OplogReader missingObjReader; // why are we using OplogReader to run a non-oplog query?
const char* ns = o.getStringField("ns");
// capped collections
Collection* collection = db->getCollection(ns);
if (collection && collection->isCapped()) {
log() << "missing doc, but this is okay for a capped collection (" << ns << ")";
return BSONObj();
}
const int retryMax = 3;
for (int retryCount = 1; retryCount <= retryMax; ++retryCount) {
if (retryCount != 1) {
// if we are retrying, sleep a bit to let the network possibly recover
sleepsecs(retryCount * retryCount);
}
try {
bool ok = missingObjReader.connect(HostAndPort(_hostname));
if (!ok) {
warning() << "network problem detected while connecting to the "
<< "sync source, attempt " << retryCount << " of " << retryMax << endl;
continue; // try again
}
} catch (const SocketException&) {
warning() << "network problem detected while connecting to the "
<< "sync source, attempt " << retryCount << " of " << retryMax << endl;
continue; // try again
}
// get _id from oplog entry to create query to fetch document.
const BSONElement opElem = o.getField("op");
const bool isUpdate = !opElem.eoo() && opElem.str() == "u";
const BSONElement idElem = o.getObjectField(isUpdate ? "o2" : "o")["_id"];
if (idElem.eoo()) {
severe() << "cannot fetch missing document without _id field: " << o.toString();
fassertFailedNoTrace(28742);
}
BSONObj query = BSONObjBuilder().append(idElem).obj();
BSONObj missingObj;
try {
missingObj = missingObjReader.findOne(ns, query);
} catch (const SocketException&) {
warning() << "network problem detected while fetching a missing document from the "
<< "sync source, attempt " << retryCount << " of " << retryMax << endl;
continue; // try again
} catch (DBException& e) {
error() << "assertion fetching missing object: " << e.what() << endl;
throw;
}
// success!
return missingObj;
}
// retry count exceeded
msgasserted(15916,
str::stream() << "Can no longer connect to initial sync source: " << _hostname);
}
bool SyncTail::shouldRetry(OperationContext* txn, const BSONObj& o) {
const NamespaceString nss(o.getStringField("ns"));
MONGO_WRITE_CONFLICT_RETRY_LOOP_BEGIN {
// Take an X lock on the database in order to preclude other modifications.
// Also, the database might not exist yet, so create it.
AutoGetOrCreateDb autoDb(txn, nss.db(), MODE_X);
Database* const db = autoDb.getDb();
// we don't have the object yet, which is possible on initial sync. get it.
log() << "adding missing object" << endl; // rare enough we can log
BSONObj missingObj = getMissingDoc(txn, db, o);
if (missingObj.isEmpty()) {
log() << "missing object not found on source."
" presumably deleted later in oplog";
log() << "o2: " << o.getObjectField("o2").toString();
log() << "o firstfield: " << o.getObjectField("o").firstElementFieldName();
return false;
} else {
WriteUnitOfWork wunit(txn);
Collection* const coll = db->getOrCreateCollection(txn, nss.toString());
invariant(coll);
Status status = coll->insertDocument(txn, missingObj, true);
uassert(15917,
str::stream() << "failed to insert missing doc: " << status.toString(),
status.isOK());
LOG(1) << "inserted missing doc: " << missingObj.toString() << endl;
wunit.commit();
return true;
}
}
MONGO_WRITE_CONFLICT_RETRY_LOOP_END(txn, "InsertRetry", nss.ns());
// fixes compile errors on GCC - see SERVER-18219 for details
MONGO_UNREACHABLE;
}
static void initializeWriterThread() {
// Only do this once per thread
if (!ClientBasic::getCurrent()) {
Client::initThreadIfNotAlready();
AuthorizationSession::get(cc())->grantInternalAuthorization();
}
}
// This free function is used by the writer threads to apply each op
void multiSyncApply(const std::vector& ops, SyncTail* st) {
using OplogEntry = SyncTail::OplogEntry;
std::vector oplogEntries(ops.begin(), ops.end());
std::vector oplogEntryPointers(oplogEntries.size());
for (size_t i = 0; i < oplogEntries.size(); i++) {
oplogEntryPointers[i] = &oplogEntries[i];
}
if (oplogEntryPointers.size() > 1) {
std::stable_sort(oplogEntryPointers.begin(),
oplogEntryPointers.end(),
[](OplogEntry* l, OplogEntry* r) { return l->ns < r->ns; });
}
initializeWriterThread();
OperationContextImpl txn;
txn.setReplicatedWrites(false);
DisableDocumentValidation validationDisabler(&txn);
// allow us to get through the magic barrier
txn.lockState()->setIsBatchWriter(true);
bool convertUpdatesToUpserts = true;
// doNotGroupBeforePoint is used to prevent retrying bad group inserts by marking the final op
// of a failed group and not allowing further group inserts until that op has been processed.
std::vector::iterator doNotGroupBeforePoint = oplogEntryPointers.begin();
for (std::vector::iterator oplogEntriesIterator = oplogEntryPointers.begin();
oplogEntriesIterator != oplogEntryPointers.end();
++oplogEntriesIterator) {
OplogEntry* entry = *oplogEntriesIterator;
if (entry->opType[0] == 'i' && oplogEntriesIterator > doNotGroupBeforePoint) {
// Attempt to group inserts if possible.
std::vector toInsert;
int batchSize = 0;
int batchCount = 0;
auto endOfGroupableOpsIterator = std::find_if(
oplogEntriesIterator + 1,
oplogEntryPointers.end(),
[&](OplogEntry* nextEntry) {
return nextEntry->opType[0] != 'i' || // Must be an insert.
nextEntry->ns != entry->ns || // Must be the same namespace.
// Must not create too large an object.
(batchSize += nextEntry->o.Obj().objsize()) > insertVectorMaxBytes ||
++batchCount >= 64; // Or have too many entries.
});
if (endOfGroupableOpsIterator != oplogEntriesIterator + 1) {
// Since we found more than one document, create grouped insert of many docs.
BSONObjBuilder groupedInsertBuilder;
// Generate an op object of all elements except for "o", since we need to
// make the "o" field an array of all the o's.
for (auto elem : entry->raw) {
if (elem.fieldNameStringData() != "o") {
groupedInsertBuilder.append(elem);
}
}
// Populate the "o" field with all the groupable inserts.
BSONArrayBuilder insertArrayBuilder(groupedInsertBuilder.subarrayStart("o"));
for (std::vector::iterator groupingIterator = oplogEntriesIterator;
groupingIterator != endOfGroupableOpsIterator;
++groupingIterator) {
insertArrayBuilder.append((*groupingIterator)->o.Obj());
}
insertArrayBuilder.done();
try {
// Apply the group of inserts.
uassertStatusOK(SyncTail::syncApply(
&txn, groupedInsertBuilder.done(), convertUpdatesToUpserts));
// It succeeded, advance the oplogEntriesIterator to the end of the
// group of inserts.
oplogEntriesIterator = endOfGroupableOpsIterator - 1;
continue;
} catch (const DBException& e) {
// The group insert failed, log an error and fall through to the
// application of an individual op.
error() << "Error applying inserts in bulk " << causedBy(e)
<< " trying first insert as a lone insert";
if (inShutdown()) {
return;
}
// Avoid quadratic run time from failed insert by not retrying until we
// are beyond this group of ops.
doNotGroupBeforePoint = endOfGroupableOpsIterator - 1;
}
}
}
try {
// Apply an individual (non-grouped) op.
const Status s = SyncTail::syncApply(&txn, entry->raw, convertUpdatesToUpserts);
if (!s.isOK()) {
severe() << "Error applying operation (" << entry->raw.toString() << "): " << s;
fassertFailedNoTrace(16359);
}
} catch (const DBException& e) {
severe() << "writer worker caught exception: " << causedBy(e)
<< " on: " << entry->raw.toString();
if (inShutdown()) {
return;
}
fassertFailedNoTrace(16360);
}
}
}
// This free function is used by the initial sync writer threads to apply each op
void multiInitialSyncApply(const std::vector& ops, SyncTail* st) {
initializeWriterThread();
OperationContextImpl txn;
txn.setReplicatedWrites(false);
DisableDocumentValidation validationDisabler(&txn);
// allow us to get through the magic barrier
txn.lockState()->setIsBatchWriter(true);
bool convertUpdatesToUpserts = false;
for (std::vector::const_iterator it = ops.begin(); it != ops.end(); ++it) {
try {
const Status s = SyncTail::syncApply(&txn, *it, convertUpdatesToUpserts);
if (!s.isOK()) {
if (st->shouldRetry(&txn, *it)) {
const Status s2 = SyncTail::syncApply(&txn, *it, convertUpdatesToUpserts);
if (!s2.isOK()) {
severe() << "Error applying operation (" << it->toString() << "): " << s2;
fassertFailedNoTrace(15915);
}
}
// If shouldRetry() returns false, fall through.
// This can happen if the document that was moved and missed by Cloner
// subsequently got deleted and no longer exists on the Sync Target at all
}
} catch (const DBException& e) {
severe() << "writer worker caught exception: " << causedBy(e)
<< " on: " << it->toString();
if (inShutdown()) {
return;
}
fassertFailedNoTrace(16361);
}
}
}
} // namespace repl
} // namespace mongo