Rocket.chat: MongoError: E11000 duplicate key error collection: rocketchat.rocketchat_cron_history index: intendedAt_1_name_1

[abate]

version : 0.70.4 (from dockerhub) / mongodb 4.0.3

After a docker-compose pull , I got a MongoError: E11000 duplicate key error collection: rocketchat.rocketchat_cron_history index: intendedAt_1_name_1 .

Somehow, I think, ricketchat wants to create a duplicated record, or a duplicated record ended up in the db.

how can I recover from this problem ?

This is the mongodb log at restart, and below the rocketchat log :

mongo_1       | 2018-10-21T11:09:00.470+0000 I NETWORK  [conn1] received client metadata from 172.20.0.7:38830 conn1: { driver: { name: "nodejs", version: "2.2.34" }, os: { type: "Linux", name: "linux", architecture: "x64", version: "4.9.132-xxxx-std-ipv6-64" }, platform: "Node.js v8.11.3, LE, mongodb-core: 2.1.18" }
mongo_1       | 2018-10-21T11:09:03.081+0000 I NETWORK  [listener] connection accepted from 172.20.0.7:38838 #2 (2 connections now open)
mongo_1       | 2018-10-21T11:09:04.015+0000 I NETWORK  [listener] connection accepted from 172.20.0.7:38840 #3 (3 connections now open)
mongo_1       | 2018-10-21T11:09:05.523+0000 I NETWORK  [listener] connection accepted from 172.20.0.7:38860 #4 (4 connections now open)
mongo_1       | 2018-10-21T11:09:05.827+0000 I STORAGE  [conn2] createCollection: rocketchat.rocketchat_raw_imports with generated UUID: 8ef79eea-40a1-46ae-81e7-80ae058db5b3
mongo_1       | 2018-10-21T11:09:05.836+0000 I INDEX    [conn2] build index on: rocketchat.rocketchat_raw_imports properties: { v: 2, key: { _updatedAt: 1 }, name: "_updatedAt_1", ns: "rocketchat.rocketchat_raw_imports" }
mongo_1       | 2018-10-21T11:09:05.836+0000 I INDEX    [conn2]      building index using bulk method; build may temporarily use up to 500 megabytes of RAM
mongo_1       | 2018-10-21T11:09:05.836+0000 I INDEX    [conn2] build index done.  scanned 0 total records. 0 secs
mongo_1       | 2018-10-21T11:09:09.927+0000 I COMMAND  [conn3] CMD: drop rocketchat.rocketchat_raw_imports
mongo_1       | 2018-10-21T11:09:09.927+0000 I STORAGE  [conn3] Finishing collection drop for rocketchat.rocketchat_raw_imports (8ef79eea-40a1-46ae-81e7-80ae058db5b3).
mongo_1       | 2018-10-21T11:09:10.527+0000 I INDEX    [conn4] build index on: rocketchat.rocketchat_cron_history properties: { v: 2, unique: true, key: { intendedAt: 1, name: 1 }, name: "intendedAt_1_name_1", ns: "rocketchat.rocketchat_cron_history" }
mongo_1       | 2018-10-21T11:09:10.527+0000 I INDEX    [conn4]      building index using bulk method; build may temporarily use up to 500 megabytes of RAM

rocketchat_1  | Updating process.env.MAIL_URL
rocketchat_1  | Starting Email Intercepter...
rocketchat_1  | Warning: connect.session() MemoryStore is not
rocketchat_1  | designed for a production environment, as it will leak
rocketchat_1  | memory, and will not scale past a single process.
rocketchat_1  | LocalStore: store created at 
rocketchat_1  | LocalStore: store created at 
rocketchat_1  | LocalStore: store created at 
rocketchat_1  | Setting default file store to GridFS
rocketchat_1  | Sun, 21 Oct 2018 11:18:24 GMT connect deprecated multipart: use parser (multiparty, busboy, formidable) npm module instead at npm/node_modules/connect/lib/middleware/bodyParser.js:56:20
rocketchat_1  | Sun, 21 Oct 2018 11:18:24 GMT connect deprecated limit: Restrict request size at location of read at npm/node_modules/connect/lib/middleware/multipart.js:86:15
rocketchat_1  | {"line":"159","file":"rocketchat_migrations.js","message":"Migrations: Not migrating, already at version 135","time":{"$date":1540120705238},"level":"info"}
rocketchat_1  | Using GridFS for custom sounds storage
rocketchat_1  | Using GridFS for custom emoji storage
rocketchat_1  | Updating process.env.MAIL_URL
rocketchat_1  | Loaded the Apps Framework and loaded a total of 0 Apps!
rocketchat_1  | Exception in callback of async function: MongoError: E11000 duplicate key error collection: rocketchat.rocketchat_cron_history index: intendedAt_1_name_1 dup key: { : new Date(1540025100000), : "Generate download files for user data" }
rocketchat_1  |     at Function.MongoError.create (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/error.js:31:11)
rocketchat_1  |     at /app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:497:72
rocketchat_1  |     at authenticateStragglers (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:443:16)
rocketchat_1  |     at Connection.messageHandler (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:477:5)
rocketchat_1  |     at Socket.<anonymous> (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/connection.js:333:22)
rocketchat_1  |     at emitOne (events.js:116:13)
rocketchat_1  |     at Socket.emit (events.js:211:7)
rocketchat_1  |     at addChunk (_stream_readable.js:263:12)
rocketchat_1  |     at readableAddChunk (_stream_readable.js:250:11)
rocketchat_1  |     at Socket.Readable.push (_stream_readable.js:208:10)
rocketchat_1  |     at TCP.onread (net.js:597:20)
rocketchat_1  | 

[almaro90]

+1

[abate]

One more piece of information. I use blacklabelops/volumerize to backup the mongodb volume... I'm wondering if this information might be relevant. The mongodb volume is shared with the volumerize container readonly.

[lopezmuzas]

+1

[sawo]

+1

[abate]

does anybody have a temporary solution ?

[reetp]

There are lots of issue on the error:

E11000 duplicate key error collection

https://github.com/RocketChat/Rocket.Chat/issues?utf8=%E2%9C%93&q=is%3Aissue+E11000+duplicate+key+error+collection

Please have a read through them and see if any are applicable or resolve your situation.

[sawo]

I have cleared the rocketchat_cron_history collection in mongo with the following commands in the mongo console:
use rocketchat
db.rocketchat_cron_history.remove({})
and it worked for me after restarted the rocketchat server.

[maxdwit]

@sawo is it save to delete the cron_history on a live environment?

[sawo]

@maxdwit to be frank with you, I do not know, what happens behind the scenes, when you truncate the rocketchat_cron_history table, but at least the app starts properly when the table is truncated before the app is started. I believe it is just for having some audit logs, or similar. I am not a developer of Rocket.Chat, so the workaround I mentioned above is not official, but I do it frequently in one of my servers, where I cannot upgrade the Rocket.Chat to newer version.

[reetp]

Any further information on this ? Currently on 0.74.2

[MarekPikula]

It started to show after I turned on replica set after upgrade to 1.0.3. Here's my log: https://gist.github.com/MarPiRK/60c43a9abc4fd6744cd79da64f9cf537