// Produce a reply to a RAFT-style RequestVote RPC; this is MongoDB ReplSetFresh command
// The caller should validate that the message is for the correct set, and has the required data
void TopologyCoordinatorImpl::prepareRequestVoteResponse(const Date_t now,
const BSONObj& cmdObj,
const OpTime& lastOpApplied,
std::string& errmsg,
BSONObjBuilder& result) {
string who = cmdObj["who"].String();
int cfgver = cmdObj["cfgver"].Int();
OpTime opTime(cmdObj["opTime"].Date());
bool weAreFresher = false;
if( _currentConfig.getConfigVersion() > cfgver ) {
log() << "replSet member " << who << " is not yet aware its cfg version "
<< cfgver << " is stale";
result.append("info", "config version stale");
weAreFresher = true;
}
// check not only our own optime, but any other member we can reach
else if( opTime < _commitOkayThrough ||
opTime < _latestKnownOpTime()) {
weAreFresher = true;
}
result.appendDate("opTime", lastOpApplied.asDate());
result.append("fresher", weAreFresher);
bool doVeto = _shouldVeto(cmdObj, errmsg);
result.append("veto",doVeto);
if (doVeto) {
result.append("errmsg", errmsg);
}
}
/** write an op to the oplog that is already built.
todo : make _logOpRS() call this so we don't repeat ourself?
*/
void _logOpObjRS(const BSONObj& op) {
DEV assertInWriteLock();
const OpTime ts = op["ts"]._opTime();
long long h = op["h"].numberLong();
{
const char *logns = rsoplog;
if ( rsOplogDetails == 0 ) {
Client::Context ctx( logns , dbpath, 0, false);
localDB = ctx.db();
assert( localDB );
rsOplogDetails = nsdetails(logns);
massert(13389, "local.oplog.rs missing. did you drop it? if so restart server", rsOplogDetails);
}
Client::Context ctx( logns , localDB, false );
{
int len = op.objsize();
Record *r = theDataFileMgr.fast_oplog_insert(rsOplogDetails, logns, len);
memcpy(getDur().writingPtr(r->data, len), op.objdata(), len);
}
/* todo: now() has code to handle clock skew. but if the skew server to server is large it will get unhappy.
this code (or code in now() maybe) should be improved.
*/
if( theReplSet ) {
if( !(theReplSet->lastOpTimeWritten<ts) ) {
log() << "replSet error possible failover clock skew issue? " << theReplSet->lastOpTimeWritten.toString() << ' ' << endl;
}
theReplSet->lastOpTimeWritten = ts;
theReplSet->lastH = h;
ctx.getClient()->setLastOp( ts.asDate() );
}
}
}
void OplogReader::tailingQueryGTE(const char *ns, OpTime optime, const BSONObj* fields ) {
BSONObjBuilder gte;
gte.appendTimestamp("$gte", optime.asDate());
BSONObjBuilder query;
query.append("ts", gte.done());
tailingQuery(ns, query.done(), fields);
}
/* Do we have the newest data of them all?
@param allUp - set to true if all members are up. Only set if true returned.
@return true if we are freshest. Note we may tie.
*/
bool Consensus::_weAreFreshest(bool& allUp, int& nTies) {
const OpTime ord = theReplSet->lastOpTimeWritten;
nTies = 0;
verify( !ord.isNull() );
BSONObj cmd = BSON(
"replSetFresh" << 1 <<
"set" << rs.name() <<
"opTime" << Date_t(ord.asDate()) <<
"who" << rs._self->fullName() <<
"cfgver" << rs._cfg->version <<
"id" << rs._self->id());
list<Target> L;
int ver;
/* the following queries arbiters, even though they are never fresh. wonder if that makes sense.
it doesn't, but it could, if they "know" what freshness it one day. so consider removing
arbiters from getTargets() here. although getTargets is used elsewhere for elections; there
arbiters are certainly targets - so a "includeArbs" bool would be necessary if we want to make
not fetching them herein happen.
*/
rs.getTargets(L, ver);
_multiCommand(cmd, L);
int nok = 0;
allUp = true;
for( list<Target>::iterator i = L.begin(); i != L.end(); i++ ) {
if( i->ok ) {
nok++;
if( i->result["fresher"].trueValue() ) {
log() << "not electing self, we are not freshest" << rsLog;
return false;
}
OpTime remoteOrd( i->result["opTime"].Date() );
if( remoteOrd == ord )
nTies++;
verify( remoteOrd <= ord );
if( i->result["veto"].trueValue() ) {
BSONElement msg = i->result["errmsg"];
if (!msg.eoo()) {
log() << "not electing self, " << i->toHost << " would veto with '" <<
msg.String() << "'" << rsLog;
}
else {
log() << "not electing self, " << i->toHost << " would veto" << rsLog;
}
return false;
}
}
else {
DEV log() << "replSet freshest returns " << i->result.toString() << rsLog;
allUp = false;
}
}
LOG(1) << "replSet dev we are freshest of up nodes, nok:" << nok << " nTies:" << nTies << rsLog;
verify( ord <= theReplSet->lastOpTimeWritten ); // <= as this may change while we are working...
return true;
}
// Adds a wOpTime and a wElectionId field to a set of gle options
static BSONObj buildGLECmdWithOpTime( const BSONObj& gleOptions,
const OpTime& opTime,
const OID& electionId ) {
BSONObjBuilder builder;
BSONObjIterator it( gleOptions );
for ( int i = 0; it.more(); ++i ) {
BSONElement el = it.next();
// Make sure first element is getLastError : 1
if ( i == 0 ) {
StringData elName( el.fieldName() );
if ( !elName.equalCaseInsensitive( "getLastError" ) ) {
builder.append( "getLastError", 1 );
}
}
builder.append( el );
}
builder.appendTimestamp( "wOpTime", opTime.asDate() );
builder.appendOID( "wElectionId", const_cast<OID*>(&electionId) );
return builder.obj();
}
/* we write to local.opload.$main:
{ ts : ..., op: ..., ns: ..., o: ... }
ts: an OpTime timestamp
op:
"i" insert
"u" update
"d" delete
"c" db cmd
"db" declares presence of a database (ns is set to the db name + '.')
"n" no op
logNS - e.g. "local.oplog.$main"
bb:
if not null, specifies a boolean to pass along to the other side as b: param.
used for "justOne" or "upsert" flags on 'd', 'u'
first: true
when set, indicates this is the first thing we have logged for this database.
thus, the slave does not need to copy down all the data when it sees this.
*/
static void _logOp(const char *opstr, const char *ns, const char *logNS, const BSONObj& obj, BSONObj *o2, bool *bb, const OpTime &ts ) {
if ( strncmp(ns, "local.", 6) == 0 ){
if ( strncmp(ns, "local.slaves", 12) == 0 ){
resetSlaveCache();
}
return;
}
DEV assertInWriteLock();
Client::Context context;
/* we jump through a bunch of hoops here to avoid copying the obj buffer twice --
instead we do a single copy to the destination position in the memory mapped file.
*/
BSONObjBuilder b;
b.appendTimestamp("ts", ts.asDate());
b.append("op", opstr);
b.append("ns", ns);
if ( bb )
b.appendBool("b", *bb);
if ( o2 )
b.append("o2", *o2);
BSONObj partial = b.done();
int posz = partial.objsize();
int len = posz + obj.objsize() + 1 + 2 /*o:*/;
Record *r;
if ( strncmp( logNS, "local.", 6 ) == 0 ) { // For now, assume this is olog main
if ( localOplogMainDetails == 0 ) {
Client::Context ctx("local.", dbpath, 0, false);
localOplogDB = ctx.db();
localOplogMainDetails = nsdetails(logNS);
}
Client::Context ctx( "" , localOplogDB, false );
r = theDataFileMgr.fast_oplog_insert(localOplogMainDetails, logNS, len);
} else {
Client::Context ctx( logNS, dbpath, 0, false );
assert( nsdetails( logNS ) );
r = theDataFileMgr.fast_oplog_insert( nsdetails( logNS ), logNS, len);
}
char *p = r->data;
memcpy(p, partial.objdata(), posz);
*((unsigned *)p) += obj.objsize() + 1 + 2;
p += posz - 1;
*p++ = (char) Object;
*p++ = 'o';
*p++ = 0;
memcpy(p, obj.objdata(), obj.objsize());
p += obj.objsize();
*p = EOO;
if ( logLevel >= 6 ) {
BSONObj temp(r);
log( 6 ) << "logging op:" << temp << endl;
}
context.getClient()->setLastOp( ts );
}
/* we write to local.opload.$main:
{ ts : ..., op: ..., ns: ..., o: ... }
ts: an OpTime timestamp
op:
"i" insert
"u" update
"d" delete
"c" db cmd
"db" declares presence of a database (ns is set to the db name + '.')
"n" no op
logNS - where to log it. 0/null means "local.oplog.$main".
bb:
if not null, specifies a boolean to pass along to the other side as b: param.
used for "justOne" or "upsert" flags on 'd', 'u'
first: true
when set, indicates this is the first thing we have logged for this database.
thus, the slave does not need to copy down all the data when it sees this.
note this is used for single collection logging even when --replSet is enabled.
*/
static void _logOpOld(const char *opstr, const char *ns, const char *logNS, const BSONObj& obj, BSONObj *o2, bool *bb ) {
DEV assertInWriteLock();
static BufBuilder bufbuilder(8*1024);
if ( strncmp(ns, "local.", 6) == 0 ) {
if ( strncmp(ns, "local.slaves", 12) == 0 ) {
resetSlaveCache();
}
return;
}
const OpTime ts = OpTime::now();
Client::Context context;
/* we jump through a bunch of hoops here to avoid copying the obj buffer twice --
instead we do a single copy to the destination position in the memory mapped file.
*/
bufbuilder.reset();
BSONObjBuilder b(bufbuilder);
b.appendTimestamp("ts", ts.asDate());
b.append("op", opstr);
b.append("ns", ns);
if ( bb )
b.appendBool("b", *bb);
if ( o2 )
b.append("o2", *o2);
BSONObj partial = b.done(); // partial is everything except the o:... part.
int po_sz = partial.objsize();
int len = po_sz + obj.objsize() + 1 + 2 /*o:*/;
Record *r;
if( logNS == 0 ) {
logNS = "local.oplog.$main";
if ( localOplogMainDetails == 0 ) {
Client::Context ctx( logNS , dbpath, 0, false);
localDB = ctx.db();
assert( localDB );
localOplogMainDetails = nsdetails(logNS);
assert( localOplogMainDetails );
}
Client::Context ctx( logNS , localDB, false );
r = theDataFileMgr.fast_oplog_insert(localOplogMainDetails, logNS, len);
}
else {
Client::Context ctx( logNS, dbpath, 0, false );
assert( nsdetails( logNS ) );
// first we allocate the space, then we fill it below.
r = theDataFileMgr.fast_oplog_insert( nsdetails( logNS ), logNS, len);
}
append_O_Obj(r->data, partial, obj);
context.getClient()->setLastOp( ts.asDate() );
if ( logLevel >= 6 ) {
BSONObj temp(r);
log( 6 ) << "logging op:" << temp << endl;
}
}
static void _logOpRS(const char *opstr, const char *ns, const char *logNS, const BSONObj& obj, BSONObj *o2, bool *bb ) {
DEV assertInWriteLock();
if ( strncmp(ns, "local.", 6) == 0 ) {
if ( strncmp(ns, "local.slaves", 12) == 0 )
resetSlaveCache();
return;
}
const OpTime ts = OpTime::now();
long long hashNew;
if( theReplSet ) {
massert(13312, "replSet error : logOp() but not primary?", theReplSet->box.getState().primary());
hashNew = (theReplSet->lastH * 131 + ts.asLL()) * 17 + theReplSet->selfId();
}
else {
// must be initiation
assert( *ns == 0 );
hashNew = 0;
}
/* we jump through a bunch of hoops here to avoid copying the obj buffer twice --
instead we do a single copy to the destination position in the memory mapped file.
*/
logopbufbuilder.reset();
BSONObjBuilder b(logopbufbuilder);
b.appendTimestamp("ts", ts.asDate());
b.append("h", hashNew);
b.append("op", opstr);
b.append("ns", ns);
if ( bb )
b.appendBool("b", *bb);
if ( o2 )
b.append("o2", *o2);
BSONObj partial = b.done();
int posz = partial.objsize();
int len = posz + obj.objsize() + 1 + 2 /*o:*/;
Record *r;
DEV assert( logNS == 0 );
{
const char *logns = rsoplog;
if ( rsOplogDetails == 0 ) {
Client::Context ctx( logns , dbpath, 0, false);
localDB = ctx.db();
assert( localDB );
rsOplogDetails = nsdetails(logns);
massert(13347, "local.oplog.rs missing. did you drop it? if so restart server", rsOplogDetails);
}
Client::Context ctx( logns , localDB, false );
r = theDataFileMgr.fast_oplog_insert(rsOplogDetails, logns, len);
/* todo: now() has code to handle clock skew. but if the skew server to server is large it will get unhappy.
this code (or code in now() maybe) should be improved.
*/
if( theReplSet ) {
if( !(theReplSet->lastOpTimeWritten<ts) ) {
log() << "replSet ERROR possible failover clock skew issue? " << theReplSet->lastOpTimeWritten << ' ' << ts << rsLog;
log() << "replSet " << theReplSet->isPrimary() << rsLog;
}
theReplSet->lastOpTimeWritten = ts;
theReplSet->lastH = hashNew;
ctx.getClient()->setLastOp( ts.asDate() );
}
}
append_O_Obj(r->data, partial, obj);
if ( logLevel >= 6 ) {
BSONObj temp(r);
log( 6 ) << "logOp:" << temp << endl;
}
}
/* initial oplog application, during initial sync, after cloning.
@return false on failure.
this method returns an error and doesn't throw exceptions (i think).
*/
bool ReplSetImpl::initialSyncOplogApplication(
const Member *source,
OpTime applyGTE,
OpTime minValid)
{
if( source == 0 ) return false;
const string hn = source->h().toString();
OpTime ts;
try {
OplogReader r;
if( !r.connect(hn) ) {
log() << "replSet initial sync error can't connect to " << hn << " to read " << rsoplog << rsLog;
return false;
}
{
BSONObjBuilder q;
q.appendDate("$gte", applyGTE.asDate());
BSONObjBuilder query;
query.append("ts", q.done());
BSONObj queryObj = query.done();
r.query(rsoplog, queryObj);
}
assert( r.haveCursor() );
/* we lock outside the loop to avoid the overhead of locking on every operation. server isn't usable yet anyway! */
writelock lk("");
{
if( !r.more() ) {
sethbmsg("replSet initial sync error reading remote oplog");
log() << "replSet initial sync error remote oplog (" << rsoplog << ") on host " << hn << " is empty?" << rsLog;
return false;
}
bo op = r.next();
OpTime t = op["ts"]._opTime();
r.putBack(op);
if( op.firstElement().fieldName() == string("$err") ) {
log() << "replSet initial sync error querying " << rsoplog << " on " << hn << " : " << op.toString() << rsLog;
return false;
}
uassert( 13508 , str::stream() << "no 'ts' in first op in oplog: " << op , !t.isNull() );
if( t > applyGTE ) {
sethbmsg(str::stream() << "error " << hn << " oplog wrapped during initial sync");
log() << "replSet initial sync expected first optime of " << applyGTE << rsLog;
log() << "replSet initial sync but received a first optime of " << t << " from " << hn << rsLog;
return false;
}
}
// todo : use exhaust
unsigned long long n = 0;
while( 1 ) {
if( !r.more() )
break;
BSONObj o = r.nextSafe(); /* note we might get "not master" at some point */
{
ts = o["ts"]._opTime();
/* if we have become primary, we dont' want to apply things from elsewhere
anymore. assumePrimary is in the db lock so we are safe as long as
we check after we locked above. */
if( (source->state() != MemberState::RS_PRIMARY &&
source->state() != MemberState::RS_SECONDARY) ||
replSetForceInitialSyncFailure ) {
int f = replSetForceInitialSyncFailure;
if( f > 0 ) {
replSetForceInitialSyncFailure = f-1;
log() << "replSet test code invoked, replSetForceInitialSyncFailure" << rsLog;
throw DBException("forced error",0);
}
log() << "replSet we are now primary" << rsLog;
throw DBException("primary changed",0);
}
if( ts >= applyGTE ) {
// optimes before we started copying need not be applied.
syncApply(o);
}
_logOpObjRS(o); /* with repl sets we write the ops to our oplog too */
}
if( ++n % 100000 == 0 ) {
// simple progress metering
log() << "replSet initialSyncOplogApplication " << n << rsLog;
}
}
}
catch(DBException& e) {
if( ts <= minValid ) {
// didn't make it far enough
log() << "replSet initial sync failing, error applying oplog " << e.toString() << rsLog;
return false;
}
}
return true;
}
virtual int doRun() {
// authenticate
enum Auth::Level authLevel = Auth::NONE;
auth("", &authLevel);
uassert(15935, "user does not have write access", authLevel == Auth::WRITE);
boost::filesystem::path root = getParam("dir");
// check if we're actually talking to a machine that can write
if (!isMaster()) {
return -1;
}
if (isMongos() && _db == "" && exists(root / "config")) {
log() << "Cannot do a full restore on a sharded system" << endl;
return -1;
}
_drop = hasParam( "drop" );
_keepIndexVersion = hasParam("keepIndexVersion");
_restoreOptions = !hasParam("noOptionsRestore");
_restoreIndexes = !hasParam("noIndexRestore");
_w = getParam( "w" , 1 );
bool doOplog = hasParam( "oplogReplay" );
if (doOplog) {
// fail early if errors
if (_db != "") {
log() << "Can only replay oplog on full restore" << endl;
return -1;
}
if ( ! exists(root / "oplog.bson") ) {
log() << "No oplog file to replay. Make sure you run mongodump with --oplog." << endl;
return -1;
}
BSONObj out;
if (! conn().simpleCommand("admin", &out, "buildinfo")) {
log() << "buildinfo command failed: " << out["errmsg"].String() << endl;
return -1;
}
StringData version = out["version"].valuestr();
if (versionCmp(version, "1.7.4-pre-") < 0) {
log() << "Can only replay oplog to server version >= 1.7.4" << endl;
return -1;
}
string oplogLimit = getParam( "oplogLimit", "" );
string oplogInc = "0";
if(!oplogLimit.empty()) {
size_t i = oplogLimit.find_first_of(':');
if ( i != string::npos ) {
if ( i + 1 < oplogLimit.length() ) {
oplogInc = oplogLimit.substr(i + 1);
}
oplogLimit = oplogLimit.substr(0, i);
}
try {
_oplogLimitTS.reset(new OpTime(
boost::lexical_cast<unsigned long>(oplogLimit.c_str()),
boost::lexical_cast<unsigned long>(oplogInc.c_str())));
} catch( const boost::bad_lexical_cast& error) {
log() << "Could not parse oplogLimit into Timestamp from values ( "
<< oplogLimit << " , " << oplogInc << " )"
<< endl;
return -1;
}
if (!oplogLimit.empty()) {
// Only for a replica set as master will have no-op entries so we would need to
// skip them all to find the real op
scoped_ptr<DBClientCursor> cursor(
conn().query("local.oplog.rs", Query().sort(BSON("$natural" << -1)),
1 /*return first*/));
OpTime tsOptime;
// get newest oplog entry and make sure it is older than the limit to apply.
if (cursor->more()) {
tsOptime = cursor->next().getField("ts")._opTime();
if (tsOptime > *_oplogLimitTS.get()) {
log() << "The oplogLimit is not newer than"
<< " the last oplog entry on the server."
<< endl;
return -1;
}
}
BSONObjBuilder tsRestrictBldr;
if (!tsOptime.isNull())
tsRestrictBldr.appendTimestamp("$gt", tsOptime.asDate());
tsRestrictBldr.appendTimestamp("$lt", _oplogLimitTS->asDate());
BSONObj query = BSON("ts" << tsRestrictBldr.obj());
if (!tsOptime.isNull()) {
log() << "Latest oplog entry on the server is " << tsOptime.getSecs()
<< ":" << tsOptime.getInc() << endl;
log() << "Only applying oplog entries matching this criteria: "
<< query.jsonString() << endl;
}
_opmatcher.reset(new Matcher(query));
}
}
}
/* If _db is not "" then the user specified a db name to restore as.
*
* In that case we better be given either a root directory that
* contains only .bson files or a single .bson file (a db).
*
* In the case where a collection name is specified we better be
* given either a root directory that contains only a single
* .bson file, or a single .bson file itself (a collection).
*/
drillDown(root, _db != "", _coll != "", !(_oplogLimitTS.get() == NULL), true);
// should this happen for oplog replay as well?
conn().getLastError(_db == "" ? "admin" : _db);
if (doOplog) {
log() << "\t Replaying oplog" << endl;
_curns = OPLOG_SENTINEL;
processFile( root / "oplog.bson" );
log() << "Applied " << _oplogEntryApplies << " oplog entries out of "
<< _oplogEntryApplies + _oplogEntrySkips << " (" << _oplogEntrySkips
<< " skipped)." << endl;
}
return EXIT_CLEAN;
}
static void _logOpOld(const char *opstr, const char *ns, const char *logNS, const BSONObj& obj, BSONObj *o2, bool *bb, bool fromMigrate ) {
Lock::DBWrite lk("local");
static BufBuilder bufbuilder(8*1024); // todo there is likely a mutex on this constructor
if ( strncmp(ns, "local.", 6) == 0 ) {
if ( strncmp(ns, "local.slaves", 12) == 0 ) {
resetSlaveCache();
}
return;
}
mutex::scoped_lock lk2(OpTime::m);
const OpTime ts = OpTime::now(lk2);
Client::Context context("", 0);
/* we jump through a bunch of hoops here to avoid copying the obj buffer twice --
instead we do a single copy to the destination position in the memory mapped file.
*/
bufbuilder.reset();
BSONObjBuilder b(bufbuilder);
b.appendTimestamp("ts", ts.asDate());
b.append("op", opstr);
b.append("ns", ns);
if (fromMigrate)
b.appendBool("fromMigrate", true);
if ( bb )
b.appendBool("b", *bb);
if ( o2 )
b.append("o2", *o2);
BSONObj partial = b.done(); // partial is everything except the o:... part.
int po_sz = partial.objsize();
int len = po_sz + obj.objsize() + 1 + 2 /*o:*/;
Record *r;
if( logNS == 0 ) {
logNS = "local.oplog.$main";
if ( localOplogMainDetails == 0 ) {
Client::Context ctx(logNS , dbpath);
localDB = ctx.db();
verify( localDB );
localOplogMainDetails = nsdetails(logNS);
verify( localOplogMainDetails );
}
Client::Context ctx(logNS , localDB);
r = theDataFileMgr.fast_oplog_insert(localOplogMainDetails, logNS, len);
}
else {
Client::Context ctx(logNS, dbpath);
verify( nsdetails( logNS ) );
// first we allocate the space, then we fill it below.
r = theDataFileMgr.fast_oplog_insert( nsdetails( logNS ), logNS, len);
}
append_O_Obj(r->data(), partial, obj);
context.getClient()->setLastOp( ts );
LOG( 6 ) << "logging op:" << BSONObj::make(r) << endl;
}