A lot of WriteConflict errors with MongoDB transactions

Question

I'm currently playing with transactions in latest available docker image of MongoDB 4.1.4 (using Node 8.12.0 and Mongoose 5.3.8 as client). I've made a simple replica set with 3 mongo instances, everything works fine and all until I do a lot of WriteConflict errors during short time.

My code looks like this:

// name, value are strings
// date is current time

const session = await createAnalyticsTransaction(); // returns 'session'

// _id is pregenerated
var stat = await Logger.findById(_id).session(session);

if (stat) {
    // do nothing if it already exists
    return true;
} 

await Logger.update({
    _id
}, {
    $setOnInsert: {
        _id,
        name,
        created: date.toDate(),
        modified: date.toDate()
    }
}, { 
    session, 
    upsert: true 
});

/*
    var period = 'month';
    var time = '2018-11'; 
    await Analytics.update({
        _id
    }, { 
        $setOnInsert: {
            _id,
            name,
            period,
            time,
            created: date.toDate()
        },
        $inc: inc
    }, {
        upsert: true,
        session: session 
    });
*/

await session.commitTransaction();
await session.endSession();

Everything works here so far until I uncomment an upsert into Analytics collection with $inc and $setOnInsert and run about 1000 simultaneous operations. The idea is that Analytics collection should be created if it wasn't created yet. And then I start getting a lot of MongoError: WriteConflict, with error's property errorLabels having TransientTransactionError.

I assume it's because of $inc or upsert: true? Did anyone experience this? What's the best solution in this case?

{ MongoError: WriteConflict
   at /Users/akuzmenok/Zend/MeteorLingua/lingua-analytics/node_modules/mongodb-core/lib/connection/pool.js:581:63
   at authenticateStragglers (/Users/akuzmenok/Zend/MeteorLingua/lingua-analytics/node_modules/mongodb-core/lib/connection/pool.js:504:16)
   at Connection.messageHandler (/Users/akuzmenok/Zend/MeteorLingua/lingua-analytics/node_modules/mongodb-core/lib/connection/pool.js:540:5)
   at emitMessageHandler (/Users/akuzmenok/Zend/MeteorLingua/lingua-analytics/node_modules/mongodb-core/lib/connection/connection.js:310:10)
   at Socket.<anonymous> (/Users/akuzmenok/Zend/MeteorLingua/lingua-analytics/node_modules/mongodb-core/lib/connection/connection.js:453:17)
   at emitOne (events.js:116:13)
   at Socket.emit (events.js:211:7)
   at addChunk (_stream_readable.js:263:12)
   at readableAddChunk (_stream_readable.js:250:11)
   at Socket.Readable.push (_stream_readable.js:208:10)
   at TCP.onread (net.js:597:20)
=> awaited here:
   at Function.Promise.await (/Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
   at Promise.asyncApply (imports/lib/analytics.js:97:9)
   at /Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
=> awaited here:
   at Function.Promise.await (/Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
   at Promise.asyncApply (imports/lib/analytics.js:139:5)
   at /Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
=> awaited here:
   at Function.Promise.await (/Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
   at Promise.asyncApply (imports/lib/analytics.js:158:5)
   at /Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
=> awaited here:
   at Function.Promise.await (/Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
   at Promise.asyncApply (imports/lib/analytics.js:49:23)
   at /Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
=> awaited here:
   at Function.Promise.await (/Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
   at Promise.asyncApply (imports/lib/analytics.js:14:23)
   at /Users/akuzmenok/.meteor/packages/promise/.0.11.1.1ugu6ow.mjjhg++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
 errorLabels: [ 'TransientTransactionError' ],
 operationTime: Timestamp { _bsontype: 'Timestamp', low_: 12, high_: 1541424838 },
 ok: 0,
 errmsg: 'WriteConflict',
 code: 112,
 codeName: 'WriteConflict',
 '$clusterTime':
  { clusterTime: Timestamp { _bsontype: 'Timestamp', low_: 12, high_: 1541424838 },
    signature: { hash: [Object], keyId: 0 } },
 name: 'MongoError',
 [Symbol(mongoErrorContextSymbol)]: {} }

Another note, I'm starting a transaction like this:

const session = await MongoAnalytics.startSession({ causalConsistency: true });
session.startTransaction({ readConcern: { level: 'snapshot' }, writeConcern: { w: 'majority' } });

Answer 1

You read data from database and then update it. It look like :

DATA (state 0) <---
UPDATED DATA (state 1) --->

---

When you perform two asynchronous call :

DATA (state 0) <---
DATA (state 0) <---
UPDATED DATA (state 1) --->
UPDATED DATA (state 1') ---> ERROR

---

It returns an error because the state of the data changed. This is how transactions are supposed to work.

---

---

To avoid the access conflict you can implement a custom queue system. Or catch the error and re-run the transaction with a setTimeout with a maximum number of try.

Queue system :

DATA (state 0) <---
UPDATED DATA (state 1) --->
DATA (state 1) <---
UPDATED DATA (state 2) --->

Re-run system

DATA (state 0) <---
DATA (state 0) <---
UPDATED DATA (state 1) --->
UPDATED DATA (state 1') ---> ERROR
DATA (state 1) <---
UPDATED DATA (state 2) --->