Error inserting read receipts per user

Description:

We are getting tons of errors about read receipts in server logs.

Steps to reproduce:

Expected behavior:

No errors for read receipts

Actual behavior:

See logs below

Server Setup Information:

• Version of Rocket.Chat Server: 5.4.1
• Operating System: Debian 11
• Deployment Method: tar
• Number of Running Instances: 4
• DB Replicaset Oplog: Yes
• NodeJS Version: v14.19.3
• MongoDB Version: 5.0.13 / wiredTiger (oplog Enabled)

Relevant logs:

Jan 02 16:32:15 chat-fwdc rocketchat[276738]: {"level":50,"time":"2023-01-02T16:32:15.909Z","pid":276738,"hostname":"chat-fwdc","name":"System","msg":"Error inserting read receipts per user","err":{"type":"MongoBulkWriteError","message":"E11000 duplicate key error collection: rocketchat.rocketchat_read_receipts index: roomId_1_userId_1_messageId_1 dup key: { roomId: \"PvfZfNaCpsoXizySaeYBktetYeYwSSg2bd\", userId: \"eYBktetYeYwSSg2bd\", messageId: \"j8R8Qj2gTiRhHBQKR\" }","stack":"MongoBulkWriteError: E11000 duplicate key error collection: rocketchat.rocketchat_read_receipts index: roomId_1_userId_1_messageId_1 dup key: { roomId: \"PvfZfNaCpsoXizySaeYBktetYeYwSSg2bd\", userId: \"eYBktetYeYwSSg2bd\", messageId: \"j8R8Qj2gTiRhHBQKR\" }\n    at OrderedBulkOperation.handleWriteError (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/bulk/common.js:883:22)\n    at resultHandler (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/bulk/common.js:402:27)\n    at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/utils.js:510:9\n    at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/operations/execute_operation.js:50:17\n    at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection_pool.js:273:25\n    at handleOperationResult (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/sdam/server.js:363:9)\n    at MessageStream.messageHandler (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection.js:474:9)\n    at MessageStream.emit (events.js:400:28)\n    at MessageStream.emit (domain.js:475:12)\n    at processIncomingData (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:108:16)\n    at MessageStream._write (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:28:9)\n    at writeOrBuffer (internal/streams/writable.js:358:12)\n    at MessageStream.Writable.write (internal/streams/writable.js:303:10)\n    at Socket.ondata (internal/streams/readable.js:731:22)\n    at Socket.emit (events.js:400:28)\n    at Socket.emit (domain.js:475:12)\n    at addChunk (internal/streams/readable.js:293:12)\n    at readableAddChunk (internal/streams/readable.js:267:9)\n    at Socket.Readable.push (internal/streams/readable.js:206:10)\n    at TCP.onStreamRead (internal/stream_base_commons.js:188:23)\n    at TCP.callbackTrampoline (internal/async_hooks.js:130:17)\n => awaited here:\n    at Function.Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)\n    at imports/message-read-receipt/server/lib/ReadReceipt.js:91:5\n    at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40","code":11000,"writeErrors":[{"code":11000,"index":0,"errmsg":"E11000 duplicate key error collection: rocketchat.rocketchat_read_receipts index: roomId_1_userId_1_messageId_1 dup key: { roomId: \"PvfZfNaCpsoXizySaeYBktetYeYwSSg2bd\", userId: \"eYBktetYeYwSSg2bd\", messageId: \"j8R8Qj2gTiRhHBQKR\" }","op":{"_id":"nwnv7sMB2NYtWaKYD","roomId":"PvfZfNaCpsoXizySaeYBktetYeYwSSg2bd","userId":"eYBktetYeYwSSg2bd","messageId":"j8R8Qj2gTiRhHBQKR","ts":"2023-01-02T16:32:15.495Z","_updatedAt":"2023-01-02T16:32:15.495Z"}}],"result":{"ok":1,"writeErrors":[{"code":11000,"index":0,"errmsg":"E11000 duplicate key error collection: rocketchat.rocketchat_read_receipts index: roomId_1_userId_1_messageId_1 dup key: { roomId: \"PvfZfNaCpsoXizySaeYBktetYeYwSSg2bd\", userId: \"eYBktetYeYwSSg2bd\", messageId: \"j8R8Qj2gTiRhHBQKR\" }","op":{"_id":"nwnv7sMB2NYtWaKYD","roomId":"PvfZfNaCpsoXizySaeYBktetYeYwSSg2bd","userId":"eYBktetYeYwSSg2bd","messageId":"j8R8Qj2gTiRhHBQKR","ts":"2023-01-02T16:32:15.495Z","_updatedAt":"2023-01-02T16:32:15.495Z"}}],"writeConcernErrors":[],"insertedIds":[{"index":0,"_id":"nwnv7sMB2NYtWaKYD"}],"nInserted":0,"nUpserted":0,"nMatched":0,"nModified":0,"nRemoved":0,"upserted":[],"opTime":{"ts":{"$timestamp":"7184093591591976963"},"t":16}}},"msg":"E11000 duplicate key error collection: rocketchat.rocketchat_read_receipts index: roomId_1_userId_1_messageId_1 dup key: { roomId: \"PvfZfNaCpsoXizySaeYBktetYeYwSSg2bd\", userId: \"eYBktetYeYwSSg2bd\", messageId: \"j8R8Qj2gTiRhHBQKR\" }"}

Start with imports/message-read-receipt/server/lib/ReadReceipt.js at the line 91 stack-trace entry and inspect how read receipts are inserted. Use the reported duplicate-key error and its roomId, userId, and messageId index to understand the failure; done means the reported read-receipt errors no longer appear in server logs.