-
Type:
Bug
-
Resolution: Fixed
-
Priority:
Major - P3
-
Affects Version/s: 3.4.1
-
Component/s: None
In my failover test, retryWrites is turned on. "not master" errors are observed in a very high frequency.
On server side, I use a 3-node replica-set, setup by docker. There are 2 test files written in javascript and python respectively. What these test files do is to insert documents repeatedly for every 3 seconds. When these tests are running, I run 'rs.stepDown()' on the primary node from time to time. I expect that the insertions will be successful, assuming that the replica-set election doesn't take more than 30 seconds (default serverSelectionTimeoutMS) to complete. My tests show following result
- Nodejs version test, with retryWrites always turned on, received a lot of 'not master' error. The error rate is basically equal to the rate in python version test with retryWrites is turned off.
- Python version test, if retryWrites is not turned off explicitly, received almost no error, unless the replica-set takes too much time to elect a new primary.
- Nodejs version test may be blocked in 'await insertOne()', if the insertion has no wtimeout option.
Mongodb: 4.2.2
Nodejs driver: mongodb 3.4.1
Python driver: pymongo 3.10
Mongodb Replica-Set docker stack file
version: '3.4' services: mdb1: image: mongo:4.2 volumes: - ./test/mongodb-rs1:/data/db command: mongod --replSet gs --wiredTigerCacheSizeGB 1 networks: - flowers mdb2: image: mongo:4.2 volumes: - ./test/mongodb-rs2:/data/db command: mongod --replSet gs --wiredTigerCacheSizeGB 1 networks: - flowers mdb3: image: mongo:4.2 volumes: - ./test/mongodb-rs3:/data/db command: mongod --replSet gs --wiredTigerCacheSizeGB 1 networks: - flowers exp4: image: "node:12" user: node volumes: - ./test/nodejs:/usr/src/app networks: - flowers working_dir: /usr/src/app stdin_open: true tty: true command: bash exp5: image: "python" volumes: - ./test/python:/usr/src/app networks: - flowers working_dir: /usr/src/app stdin_open: true tty: true command: bash networks: flowers:
nodejs test
var MongoClient = require('mongodb').MongoClient;
var errs = 0, total = 0;
async function write(db, start) {
console.log('Writing', start);
total ++;
try {
await db.collection('test').insertOne(
{ time: start, by: 'nodejs' }, {wtimeout: 40000});
var now = new Date();
console.log(`Insert finished in ${now.getTime() - start.getTime()}, <= ${start}, Stats <${errs}/${total}>`);
} catch (error) {
errs ++;
console.error('Insertion test error:', start, error);
console.log(`Stats: <${errs}/${total}>`);
}
}
function delay(ms) {
return new Promise((resolve, reject) => {
setTimeout(() => resolve(), ms);
});
}
(async function(){
var url = 'mongodb://mdb1:27017,mdb2:27017,mdb3:27017/geekmooc?replicaSet=gs&retryWrites=true&w=majority&serverSelectionTimeoutMS=30000';
console.log(`Connecting to ${url}`);
try {
var client = await MongoClient.connect(url, {
useNewUrlParser: true, useUnifiedTopology: true,
replicaSet: 'gs',
});
var db = client.db('geekmooc');
while (true) {
await write(db, new Date());
await delay(3000);
}
} catch (error) {
console.error('Connection failure', error);
}
})();
Python test
import random, string, datetime, sys, time, logging, traceback
import pymongo
logger = logging.getLogger("test")
out_hdlr = logging.StreamHandler(sys.stdout)
out_hdlr.setFormatter(logging.Formatter('%(asctime)s %(message)s'))
out_hdlr.setLevel(logging.INFO)
logger.addHandler(out_hdlr)
logger.setLevel(logging.INFO)MONGO_URI = 'mongodb://mdb1:27017,mdb2:27017,mdb3:27017/geekmooc?replicaSet=gs&retryWrites=false&w=majority&serverSelectionTimeoutMS=30000'logger.info("Attempting to connect...")
client = pymongo.MongoClient(MONGO_URI)
logger.info("Connected")
db = client['test']
coll = db['test']
collection = coll.with_options(write_concern=pymongo.WriteConcern(w=2, wtimeout=40000))
i = 0
errs = 0
total = 0
while True:
try:
total += 1
start = datetime.datetime.utcnow()
logger.info("Inserting: %s" %start)
text = ''.join(random.choices(string.ascii_uppercase + string.digits, k = 3))
doc = { "idx": i, "date" : start, "text" : text}
i += 1
id = collection.insert_one(doc).inserted_id
logger.info("Record inserted - id: %s, stats: %d/%d" %(str(id), errs, total))
time.sleep(3)
except Exception as e: # pymongo.errors.ConnectionFailure
errs += 1
logger.error("Exception seen: " + str(e))
traceback.print_exc(file = sys.stdout)
logger.info("Retrying...")logger.info("Done...")
client.close()