BSONObj Sync::getMissingDoc(const BSONObj& o) {
OplogReader missingObjReader;
const char *ns = o.getStringField("ns");
// capped collections
NamespaceDetails *nsd = nsdetails(ns);
if ( nsd && nsd->isCapped() ) {
log() << "replication missing doc, but this is okay for a capped collection (" << ns << ")" << endl;
return BSONObj();
}
uassert(15916, str::stream() << "Can no longer connect to initial sync source: " << hn, missingObjReader.connect(hn));
// might be more than just _id in the update criteria
BSONObj query = BSONObjBuilder().append(o.getObjectField("o2")["_id"]).obj();
BSONObj missingObj;
try {
missingObj = missingObjReader.findOne(ns, query);
} catch(DBException& e) {
log() << "replication assertion fetching missing object: " << e.what() << endl;
throw;
}
return missingObj;
}
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);
}
void ReplSetImpl::syncTail() {
// todo : locking vis a vis the mgr...
const Member *primary = box.getPrimary();
if( primary == 0 ) return;
string hn = primary->h().toString();
OplogReader r;
if( !r.connect(primary->h().toString()) ) {
log(2) << "replSet can't connect to " << hn << " to read operations" << rsLog;
return;
}
/* first make sure we are not hopelessly out of sync by being very stale. */
{
BSONObj remoteOldestOp = r.findOne(rsoplog, Query());
OpTime ts = remoteOldestOp["ts"]._opTime();
DEV log() << "remoteOldestOp: " << ts.toStringPretty() << endl;
else log(3) << "remoteOldestOp: " << ts.toStringPretty() << endl;
if( lastOpTimeWritten < ts ) {
log() << "replSet error too stale to catch up, at least from primary " << hn << rsLog;
log() << "replSet our last optime : " << lastOpTimeWritten.toStringPretty() << rsLog;
log() << "replSet oldest at " << hn << " : " << ts.toStringPretty() << rsLog;
log() << "replSet See http://www.mongodb.org/display/DOCS/Resyncing+a+Very+Stale+Replica+Set+Member" << rsLog;
sethbmsg("error too stale to catch up");
sleepsecs(120);
return;
}
}
BSONObj Sync::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() << "replication missing doc, but this is okay for a capped collection (" << ns << ")" << endl;
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(hn));
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
}
// might be more than just _id in the update criteria
BSONObj query = BSONObjBuilder().append(o.getObjectField("o2")["_id"]).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) {
log() << "replication 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: " << hn);
}
bool BackgroundSync::isStale(OpTime lastOpTimeFetched,
OplogReader& r,
BSONObj& remoteOldestOp) {
remoteOldestOp = r.findOne(rsoplog, Query());
OpTime remoteTs = remoteOldestOp["ts"]._opTime();
{
boost::unique_lock<boost::mutex> lock(_mutex);
if (lastOpTimeFetched >= remoteTs) {
return false;
}
log() << "replSet remoteOldestOp: " << remoteTs.toStringLong() << rsLog;
log() << "replSet lastOpTimeFetched: " << lastOpTimeFetched.toStringLong() << rsLog;
}
return true;
}
/**
* Checks if the oplog given is too far ahead to read from.
*
* @param r the oplog
* @param hn the hostname (for log messages)
*
* @return if we are stale compared to the oplog on hn
*/
bool ReplSetImpl::_isStale(OplogReader& r, const string& hn) {
BSONObj remoteOldestOp = r.findOne(rsoplog, Query());
OpTime ts = remoteOldestOp["ts"]._opTime();
DEV log() << "replSet remoteOldestOp: " << ts.toStringLong() << rsLog;
else log(3) << "replSet remoteOldestOp: " << ts.toStringLong() << rsLog;
bool ReplSetImpl::_initialSyncOplogApplication(OplogReader& r, const Member *source,
const OpTime& applyGTE, const OpTime& minValid) {
const string hn = source->fullName();
OplogReader missingObjReader;
try {
r.tailingQueryGTE( rsoplog, applyGTE );
if ( !r.haveCursor() ) {
log() << "replSet initial sync oplog query error" << rsLog;
return false;
}
{
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.firstElementFieldName() == 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;
}
sethbmsg(str::stream() << "initial oplog application from " << hn << " starting at "
<< t.toStringPretty() << " to " << minValid.toStringPretty());
}
}
catch(DBException& e) {
log() << "replSet initial sync failing: " << e.toString() << rsLog;
return false;
}
/* we lock outside the loop to avoid the overhead of locking on every operation. */
writelock lk("");
// todo : use exhaust
OpTime ts;
time_t start = time(0);
unsigned long long n = 0;
while( 1 ) {
try {
if( !r.more() )
break;
BSONObj o = r.nextSafe(); /* note we might get "not master" at some point */
ts = o["ts"]._opTime();
{
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.
bool failedUpdate = syncApply(o);
if( failedUpdate ) {
// we don't have the object yet, which is possible on initial sync. get it.
log() << "replSet info adding missing object" << endl; // rare enough we can log
if( !missingObjReader.connect(hn) ) { // ok to call more than once
log() << "replSet initial sync fails, couldn't connect to " << hn << endl;
return false;
}
const char *ns = o.getStringField("ns");
BSONObj query = BSONObjBuilder().append(o.getObjectField("o2")["_id"]).obj(); // might be more than just _id in the update criteria
BSONObj missingObj;
try {
missingObj = missingObjReader.findOne(
ns,
query );
} catch(...) {
log() << "replSet assertion fetching missing object" << endl;
throw;
}
if( missingObj.isEmpty() ) {
log() << "replSet missing object not found on source. presumably deleted later in oplog" << endl;
log() << "replSet o2: " << o.getObjectField("o2").toString() << endl;
log() << "replSet o firstfield: " << o.getObjectField("o").firstElementFieldName() << endl;
}
else {
Client::Context ctx(ns);
try {
DiskLoc d = theDataFileMgr.insert(ns, (void*) missingObj.objdata(), missingObj.objsize());
assert( !d.isNull() );
} catch(...) {
log() << "replSet assertion during insert of missing object" << endl;
throw;
}
// now reapply the update from above
bool failed = syncApply(o);
if( failed ) {
log() << "replSet update still fails after adding missing object " << ns << endl;
assert(false);
}
}
}
}
_logOpObjRS(o); /* with repl sets we write the ops to our oplog too */
}
if ( ++n % 1000 == 0 ) {
time_t now = time(0);
if (now - start > 10) {
// simple progress metering
log() << "replSet initialSyncOplogApplication applied " << n << " operations, synced to "
<< ts.toStringPretty() << rsLog;
start = now;
}
}
if ( ts > minValid ) {
break;
}
getDur().commitIfNeeded();
}
catch (DBException& e) {
// skip duplicate key exceptions
if( e.getCode() == 11000 || e.getCode() == 11001 ) {
continue;
}
// handle cursor not found (just requery)
if( e.getCode() == 13127 ) {
log() << "replSet requerying oplog after cursor not found condition, ts: " << ts.toStringPretty() << endl;
r.resetCursor();
r.tailingQueryGTE(rsoplog, ts);
if( r.haveCursor() ) {
continue;
}
}
// TODO: handle server restart
if( ts <= minValid ) {
// didn't make it far enough
log() << "replSet initial sync failing, error applying oplog : " << e.toString() << rsLog;
return false;
}
// otherwise, whatever
break;
}
}
return true;
}
bool ReplSetImpl::_isStale(OplogReader& r, const OpTime& startTs, BSONObj& remoteOldestOp) {
remoteOldestOp = r.findOne(rsoplog, Query());
OpTime remoteTs = remoteOldestOp["ts"]._opTime();
DEV log() << "replSet remoteOldestOp: " << remoteTs.toStringLong() << rsLog;
else LOG(3) << "replSet remoteOldestOp: " << remoteTs.toStringLong() << rsLog;