Data race when creating a new set causing forum restart

[JhnW]

NodeBB version

v3.6.6

NodeBB git hash

6604bf3

NodeJS version

v20.3.0

Installed NodeBB plugins

    * nodebb-plugin-2factor@7.4.0 (installed, disabled)
    * nodebb-plugin-composer-default@10.2.31 (installed, enabled)
    * nodebb-plugin-custom-pages (not installed, enabled)
    * nodebb-plugin-dbsearch@6.2.3 (installed, enabled)
    * nodebb-plugin-emoji@5.1.13 (installed, enabled)
    * nodebb-plugin-emoji-android@4.0.0 (installed, enabled)
    * nodebb-plugin-extended-markdown (not installed, enabled)
    * nodebb-plugin-markdown@12.2.5 (installed, enabled)
    * nodebb-plugin-mentions@4.3.7 (installed, enabled)
    * nodebb-plugin-ntfy@1.7.3 (installed, disabled)
    * nodebb-plugin-spam-be-gone@2.2.0 (installed, disabled)
    * nodebb-rewards-essentials@1.0.0 (installed, enabled)
    * nodebb-theme-harmony@1.1.108 (installed, enabled)
    * nodebb-theme-lavender@7.1.7 (installed, disabled)
    * nodebb-theme-peace@2.1.26 (installed, disabled)
    * nodebb-theme-persona@13.2.50 (installed, disabled)
    * nodebb-widget-essentials@7.0.14 (installed, enabled)
    * my custom plugin (i find this bug inside it)

Database type

MongoDB

Database version

7.0.5 providef by docker image

Exact steps to cause this issue

1. Pick arbitrarily set key which does not exist in your repository. In my example this key is rpg_session:50:topics
2. You need execute following code (for example, in plugin):
   await Promise.all(db.setAdd(your_key, 1), db.setAdd(your_key, 2), db.setAdd(your_key, 3));

What you expected

Just working forum.

What happened instead

Forum crashes with following log output:
{"date":"Wed Feb 21 2024 15:56:36 GMT+0100 (czas środkowoeuropejski standardowy)","error":{"code":11000,"index":0,"keyPattern":{"_key":1,"value":-1},"keyValue":{"_key":"rpg_session:50:topics","value":null}},"exception":true,"os":{"loadavg":[1.8,1.68,1.14],"uptime":1204.41},"process":{"argv":["/home/jhnw/.nvm/versions/node/v20.3.0/bin/node","/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/app.js"],"cwd":"/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB","execPath":"/home/jhnw/.nvm/versions/node/v20.3.0/bin/node","gid":1000,"memoryUsage":{"arrayBuffers":19470098,"external":22901059,"heapTotal":83689472,"heapUsed":76777344,"rss":158019584},"pid":10218,"uid":1000,"version":"v20.3.0"},"stack":"MongoServerError: E11000 duplicate key error collection: nodebb.objects index: _key_1_value_-1 dup key: { _key: \"rpg_session:50:topics\", value: null }\n at UpdateOneOperation.execute (/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/node_modules/mongodb/lib/operations/update.js:70:19)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n at async executeOperationAsync (/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/node_modules/mongodb/lib/operations/execute_operation.js:106:16)\n at async module.setAdd (/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/src/database/mongo/sets.js:16:3)\n at async Promise.all (index 0)\n at async Promise.all (index 1)\n at async Object.createSessionFromTopicFilterPayload (/home/jhnw/Dokumenty/repo/project_rolltelling/nodebb-plugin-rolltellingrpg/build/server/backend/rpg/sessions.js:105:5)","trace":[{"column":19,"file":"/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/node_modules/mongodb/lib/operations/update.js","function":"UpdateOneOperation.execute","line":70,"method":"execute","native":false},{"column":5,"file":"node:internal/process/task_queues","function":"process.processTicksAndRejections","line":95,"method":"processTicksAndRejections","native":false},{"column":16,"file":"/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/node_modules/mongodb/lib/operations/execute_operation.js","function":"async executeOperationAsync","line":106,"method":null,"native":false},{"column":3,"file":"/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/src/database/mongo/sets.js","function":"async module.setAdd","line":16,"method":"setAdd","native":false},{"column":null,"file":null,"function":"async Promise.all","line":null,"method":"all","native":false},{"column":null,"file":null,"function":"async Promise.all","line":null,"method":"all","native":false},{"column":5,"file":"/home/jhnw/Dokumenty/repo/project_rolltelling/nodebb-plugin-rolltellingrpg/build/server/backend/rpg/sessions.js","function":"async Object.createSessionFromTopicFilterPayload","line":105,"method":"createSessionFromTopicFilterPayload","native":false}]} 2024-02-21T14:56:36.538Z [4567/10218] - error: MongoServerError: E11000 duplicate key error collection: nodebb.objects index: _key_1_value_-1 dup key: { _key: "rpg_session:50:topics", value: null } at UpdateOneOperation.execute (/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/node_modules/mongodb/lib/operations/update.js:70:19) at process.processTicksAndRejections (node:internal/process/task_queues:95:5) at async executeOperationAsync (/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/node_modules/mongodb/lib/operations/execute_operation.js:106:16) at async module.setAdd (/home/jhnw/Dokumenty/repo/forum/rolltelling/engine/NodeBB/src/database/mongo/sets.js:16:3) at async Promise.all (index 0) at async Promise.all (index 1)

Anything else?

This problem is not only synthetic and may happen (very rarely) during normal forum operation, perhaps also for other methods (sortedSet?). I'll explain why.

for (let i =0; i < 3; i++) {
    await db.setAdd(your_key, i);
}

This usage is right because no simultaneous creation of a set and setting of new data can occur at the same time. Promise.all is a different type of animal, it adds all asynchronous functions to the event loop node, when in the first call we encounter await, the context can jump to the second call, etc. This simulates very well the rare but real case of 2 or 3 requests from users in this same time.

Considering the above, using an API that allows you to write an array of data to a set in one call does not solve the core of this problem.

[barisusakli]

4a405ce