[SERVER-16965] Missing _id index message after dropping and re-creating _id index Created: 21/Jan/15  Updated: 23/Feb/15  Resolved: 23/Feb/15

Status: Closed
Project: Core Server
Component/s: Replication
Affects Version/s: 2.6.6
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Elad Moshe Assignee: Ramon Fernandez Marina
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Steps To Reproduce:

1. Create a collection with some data on a single instance deployment
2. remove _id index (maybe only possible in 2.4)
3. Create a replica with the data from that instance

Participants:

 Description   

I have some collection that is only used for archiving (no reads). I have removed the _id index at some point (I think it was still in ver 2.4).
Then, I started the process of upgrading to a replica set from single instance. When I connect to mongo I get the following message:

015-01-05T10:08:39.088+0000 [initandlisten] WARNING: the collection 'stats.invalid_events' lacks a unique index on _id. This index is needed for replication to function properly
2015-01-05T10:08:39.088+0000 [initandlisten] 	 To fix this, you need to create a unique index on _id. See http://dochub.mongodb.org/core/build-replica-set-indexes

I created an index, but the warning still appears:

rs1-test:PRIMARY> db.invalid_events.getIndexes()
[
	{
		"v" : 1,
		"unique" : true,
		"key" : {
			"_id" : 1
		},
		"name" : "_id_",
		"ns" : "stats.invalid_events",
		"background" : true
	}
]



 Comments   
Comment by Elad Moshe [ 22/Jan/15 ]

Thank you milkie, restarting the server indeed made the warning to disappear.

Comment by Eric Milkie [ 22/Jan/15 ]

Hi Elad.
The shell reports server startup warnings every time you connect. I believe if you restart the server, the startup warning will be cleared and you will no longer see it when connecting with the shell.

Comment by Elad Moshe [ 22/Jan/15 ]

I tried to create the collection again and got the same results. Attached is the log, although I don't see anything interesting here...

rs1-test:PRIMARY> use admin
switched to db admin
rs1-test:PRIMARY> db.runCommand( { logRotate : 1 } )
{ "ok" : 1 }
rs1-test:PRIMARY> use stats
switched to db stats
rs1-test:PRIMARY> db.createCollection('invalid_events2',{capped:true,size:100000000})
{ "ok" : 1 }
rs1-test:PRIMARY> db.invalid_events.find().forEach(function(i){ db.invalid_events2.insert(i)})
rs1-test:PRIMARY> db.invalid_events2.renameCollection('invalid_events',true);
{ "ok" : 1 }
rs1-test:PRIMARY> use admin
switched to db admin
rs1-test:PRIMARY>  db.runCommand( { logRotate : 1 } )
{ "ok" : 1 }
^C
 
emoshe@mongo:/var/log/mongodb$ mongo stats
MongoDB shell version: 2.6.6
connecting to: stats
Server has startup warnings:
2015-01-05T10:08:39.088+0000 [initandlisten] WARNING: the collection 'stats.invalid_events' lacks a unique index on _id. This index is needed for replication to function properly
2015-01-05T10:08:39.088+0000 [initandlisten] 	 To fix this, you need to create a unique index on _id. See http://dochub.mongodb.org/core/build-replica-set-indexes
 
 
emoshe@mongo:/var/log/mongodb$ cat mongod.log.2015-01-22T13-02-06
2015-01-22T13:00:45.110+0000 [conn334647] pid=27057 port=27017 64-bit host=mongo.test.capriza.com
2015-01-22T13:00:45.110+0000 [conn334647] db version v2.6.6
2015-01-22T13:00:45.110+0000 [conn334647] git version: 608e8bc319627693b04cc7da29ecc300a5f45a1f
2015-01-22T13:00:45.110+0000 [conn334647] build info: Linux build10.nj1.10gen.cc 2.6.32-431.3.1.el6.x86_64 #1 SMP Fri Jan 3 21:39:27 UTC 2014 x86_64 BOOST_LIB_VERSION=1_49
2015-01-22T13:00:45.110+0000 [conn334647] allocator: tcmalloc
2015-01-22T13:00:45.110+0000 [conn334647] options: { config: "/etc/mongod.conf", replication: { replSet: "rs1-test" }, storage: { dbPath: "/var/lib/mongodb/lib/mongodb" }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongod.log" } }
2015-01-22T13:00:55.399+0000 [initandlisten] connection accepted from 127.0.0.1:60406 #334658 (59 connections now open)
2015-01-22T13:00:55.404+0000 [conn334658] end connection 127.0.0.1:60406 (58 connections now open)
2015-01-22T13:00:57.652+0000 [conn334656] end connection 10.1.8.10:48875 (57 connections now open)
2015-01-22T13:00:57.653+0000 [initandlisten] connection accepted from 10.1.8.10:48891 #334659 (58 connections now open)
2015-01-22T13:00:58.344+0000 [conn334657] end connection 10.1.108.10:39432 (57 connections now open)
2015-01-22T13:00:58.345+0000 [initandlisten] connection accepted from 10.1.108.10:39463 #334660 (58 connections now open)
2015-01-22T13:01:01.359+0000 [conn334647] build index on: stats.invalid_events2 properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "stats.invalid_events2" }
2015-01-22T13:01:01.359+0000 [conn334647] 	 added index to empty collection
2015-01-22T13:01:18.645+0000 [initandlisten] connection accepted from 192.168.10.72:51468 #334661 (59 connections now open)
2015-01-22T13:01:25.390+0000 [initandlisten] connection accepted from 127.0.0.1:60445 #334662 (60 connections now open)
2015-01-22T13:01:25.396+0000 [conn334662] end connection 127.0.0.1:60445 (59 connections now open)
2015-01-22T13:01:27.662+0000 [conn334659] end connection 10.1.8.10:48891 (58 connections now open)
2015-01-22T13:01:27.663+0000 [initandlisten] connection accepted from 10.1.8.10:50613 #334663 (59 connections now open)
2015-01-22T13:01:28.364+0000 [conn334660] end connection 10.1.108.10:39463 (58 connections now open)
2015-01-22T13:01:28.365+0000 [initandlisten] connection accepted from 10.1.108.10:39912 #334664 (59 connections now open)
2015-01-22T13:01:55.643+0000 [initandlisten] connection accepted from 127.0.0.1:60485 #334665 (60 connections now open)
2015-01-22T13:01:55.650+0000 [conn334665] end connection 127.0.0.1:60485 (59 connections now open)
2015-01-22T13:01:57.672+0000 [conn334663] end connection 10.1.8.10:50613 (58 connections now open)
2015-01-22T13:01:57.673+0000 [initandlisten] connection accepted from 10.1.8.10:50628 #334666 (59 connections now open)
2015-01-22T13:01:58.384+0000 [conn334664] end connection 10.1.108.10:39912 (58 connections now open)
2015-01-22T13:01:58.385+0000 [initandlisten] connection accepted from 10.1.108.10:41201 #334667 (59 connections now open)

Comment by Ramon Fernandez Marina [ 21/Jan/15 ]

emoshe, I'm not able to reproduce the behavior you describe, so I think I'll need more details on how you arrived to this situation (and the logs of course).

This is what I tried:

  • started up a one-node replica set using 2.6.6
  • created a collection with autoIndexId set to false
  • inserted some data into the collection
  • fired up a new node and added it to the replica set
  • when the node becomes secondary I see the following in the logs:

    2015-01-21T10:57:18.713-0500 [rsSync] build index on: test.foo properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "test.foo" }

In other words, the secondary automatically creates the missing {_id: 1} index.

Comment by Ramon Fernandez Marina [ 21/Jan/15 ]

Can you please upload the logs of the primary and secondaries involved from the time you created a new collection until now?

Comment by Elad Moshe [ 21/Jan/15 ]

I tried creating a new collection and copy all the data to that collection, then rename the new collection with dropTarget:true, but the warning does not disappear:

rs1-test:PRIMARY> db.invalid_events.getIndexes()
[
	{
		"v" : 1,
		"key" : {
			"_id" : 1
		},
		"name" : "_id_",
		"ns" : "stats.invalid_events"
	}
]

Comment by Elad Moshe [ 21/Jan/15 ]

I think that while creating the collection I used the autoIndexId:false flag of db.createCollection(). Then, when moving to the replica set I created the _id index manually with background:true.

Comment by Elad Moshe [ 21/Jan/15 ]

I started using Mongo version 2.4.x. Since it was quite time ago, unfortunately I no longer have those logs. I don't recall anything special I did to remove that index (although I am unable to remove the _id index now).
I will move the data to a new collection and drop the old collection.

Comment by Ramon Fernandez Marina [ 21/Jan/15 ]

The _id index is not expected to be a background index, so I think that's the issue here. I tried removing the _id index with various 2.4 and 2.2 versions, unsuccessfully, so I think at this stage you may need to dump/export and restore/import your data.

Also, are you sure you're upgrading from 2.4? I'm asking because one can't upgrade from older versions directly into 2.6. For example, if you're running 2.0 you must go through 2.2 and 2.4 before getting to 2.6. Do you know what version you were running before? Can you please check the logs and find out?

Generated at Thu Feb 08 03:42:51 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.