[SERVER-14999] db.system.indexes.dropIndexes() crashes mongod Created: 22/Aug/14  Updated: 16/Nov/21  Resolved: 03/Feb/16

Status: Closed
Project: Core Server
Component/s: Index Maintenance
Affects Version/s: 2.6.1, 2.6.4
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Steffen Assignee: Charlie Swanson
Resolution: Won't Fix Votes: 2
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
related to SERVER-10231 Creating an index on system.indexes b... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Participants:

 Description   

Somehow we created by accident an index in "system.indexes"
Due to this our replica slave fails to sync, when it trys to create this index.

2014-08-22T06:59:08.788+0200 [rsSync] ERROR: error creating index when cloning spec: { key: { target: 1, relation: 1, source: 1 }, unique: true, ns: "database1.system.indexes", background: 1, name: "target_1_relation_1_sou
rce_1" } error: CannotCreateIndex cannot create indexes on the system.indexes collection

db.system.indexes.getIndexSpecs()
[
    {
        "v" : 1,
        "key" : {
            "target" : NumberLong(1),
            "relation" : NumberLong(1),
            "source" : NumberLong(1)
        },
        "unique" : true,
        "ns" : "database1.system.indexes",
        "background" : NumberLong(1),
        "name" : "target_1_relation_1_source_1"
    }
]

To get rid of this index we try to drop it via dropIndex or remove. Both don't work. So we used db.system.indexes.dropIndexes() to get rid of it. This crashes mongod.

2014-08-22T10:59:48.388+0200 [conn156] CMD: dropIndexes database1.system.indexes
2014-08-22T10:59:48.394+0200 [conn156] ERROR: About to fassert -  numIndexesTotal(): 0 numSystemIndexesEntries: 1 _entries.size(): 0 indexNamesToDrop: 0 haveIdIndex: 0
2014-08-22T10:59:48.394+0200 [conn156] database1 Fatal Assertion 17328
2014-08-22T10:59:48.401+0200 [conn156] database1 0x11c0e91 0x1163109 0x114576d 0x8d714d 0x93c027 0xa1e85a 0xa20171 0xa21086 0xd4dae7 0xb97322 0xb99902 0x76b6af 0x117720b 0x7f6f85cb59ca 0x7f6f8505c1cd
 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0x11c0e91]
 /usr/bin/mongod(_ZN5mongo10logContextEPKc+0x159) [0x1163109]
 /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xcd) [0x114576d]
 /usr/bin/mongod(_ZN5mongo12IndexCatalog14dropAllIndexesEb+0xffd) [0x8d714d]
 /usr/bin/mongod(_ZN5mongo14CmdDropIndexes3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x837) [0x93c027]
 /usr/bin/mongod(_ZN5mongo12_execCommandEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x3a) [0xa1e85a]
 /usr/bin/mongod(_ZN5mongo7Command11execCommandEPS0_RNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x1601) [0xa20171]
 /usr/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x6c6) [0xa21086]
 /usr/bin/mongod(_ZN5mongo11newRunQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_+0x2307) [0xd4dae7]
 /usr/bin/mongod() [0xb97322]
 /usr/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x442) [0xb99902]
 /usr/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x9f) [0x76b6af]
 /usr/bin/mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x4fb) [0x117720b]
 /lib/libpthread.so.0(+0x69ca) [0x7f6f85cb59ca]
 /lib/libc.so.6(clone+0x6d) [0x7f6f8505c1cd]
2014-08-22T10:59:48.401+0200 [conn156]
 
***aborting after fassert() failure
 
 
2014-08-22T10:59:48.407+0200 [conn156] SEVERE: Got signal: 6 (Aborted).
Backtrace:0x11c0e91 0x11c026e 0x7f6f84fa5be0 0x7f6f84fa5b65 0x7f6f84fa96b0 0x11457da 0x8d714d 0x93c027 0xa1e85a 0xa20171 0xa21086 0xd4dae7 0xb97322 0xb99902 0x76b6af 0x117720b 0x7f6f85cb59ca 0x7f6f8505c1cd
 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0x11c0e91]
 /usr/bin/mongod() [0x11c026e]
 /lib/libc.so.6(+0x33be0) [0x7f6f84fa5be0]
 /lib/libc.so.6(gsignal+0x35) [0x7f6f84fa5b65]
 /lib/libc.so.6(abort+0x180) [0x7f6f84fa96b0]
 /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0x13a) [0x11457da]
 /usr/bin/mongod(_ZN5mongo12IndexCatalog14dropAllIndexesEb+0xffd) [0x8d714d]
 /usr/bin/mongod(_ZN5mongo14CmdDropIndexes3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x837) [0x93c027]
 /usr/bin/mongod(_ZN5mongo12_execCommandEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x3a) [0xa1e85a]
 /usr/bin/mongod(_ZN5mongo7Command11execCommandEPS0_RNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x1601) [0xa20171]
 /usr/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x6c6) [0xa21086]
 /usr/bin/mongod(_ZN5mongo11newRunQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_+0x2307) [0xd4dae7]
 /usr/bin/mongod() [0xb97322]
 /usr/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x442) [0xb99902]
 /usr/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x9f) [0x76b6af]
 /usr/bin/mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x4fb) [0x117720b]
 /lib/libpthread.so.0(+0x69ca) [0x7f6f85cb59ca]
 /lib/libc.so.6(clone+0x6d) [0x7f6f8505c1cd]



 Comments   
Comment by Charlie Swanson [ 03/Feb/16 ]

It turns out this issue can still affect 2.4 mongods. If you created an index on the system.indexes collection in 2.4, you should follow the steps described in this comment to drop it. Do not try to drop it after upgrading.

We do not plan to take any action to fix this issue on versions newer than 2.4, as they already prevent you from creating indexes on the system.indexes collection.

Comment by Charlie Swanson [ 02/Feb/16 ]

I'm closing this ticket as "Gone away", since I cannot reproduce it on any recent versions (including 2.6.11, 3.0.7, and 3.2.1). Please re-open if you believe it is still an issue.

Comment by Ramon Fernandez Marina [ 29/Oct/14 ]

reidmorrison, the downgrade to 2.4.10 is only temporary – after running

db.system.indexes.dropIndexes()

on 2.4.10 to get rid of the offending index you can go back to 2.6.5.

Comment by Reid Morrison [ 29/Oct/14 ]

Is downgrading to V2.4.10 the only solution at this time?

Running the following command causes MongoDB server to crash:

> db.last_seen_by_group.drop()

Below is our stack trace running a stand-alone MongoDB server ( no replica set or shard ) :

2014-10-29T16:06:27.420+0000 [conn5] CMD: drop cache_release.last_seen_by_group
2014-10-29T16:06:27.421+0000 [conn5] ERROR: About to fassert -  numIndexesTotal(): 0 numSystemIndexesEntries: 1 _entries.size(): 0 indexNamesToDrop: 1 haveIdIndex: 0
2014-10-29T16:06:27.421+0000 [conn5] cache_release Fatal Assertion 17328
2014-10-29T16:06:27.432+0000 [conn5] cache_release 0x11e9b11 0x118b849 0x116e37d 0x8e3373 0x8c748b 0xa3206e 0xa2939a 0xa2b151 0xa2c9a6 0xd5f83a 0xba1052 0xba2630 0x770d5f 0x119f93e 0x3978a079d1 0x39786e8b6d 
 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0x11e9b11]
 /usr/bin/mongod(_ZN5mongo10logContextEPKc+0x159) [0x118b849]
 /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xcd) [0x116e37d]
 /usr/bin/mongod(_ZN5mongo12IndexCatalog14dropAllIndexesEb+0xd93) [0x8e3373]
 /usr/bin/mongod(_ZN5mongo8Database14dropCollectionERKNS_10StringDataE+0x37b) [0x8c748b]
 /usr/bin/mongod(_ZN5mongo7CmdDrop3runERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x3ae) [0xa3206e]
 /usr/bin/mongod(_ZN5mongo12_execCommandEPNS_7CommandERKSsRNS_7BSONObjEiRSsRNS_14BSONObjBuilderEb+0x3a) [0xa2939a]
 /usr/bin/mongod(_ZN5mongo7Command11execCommandEPS0_RNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x19b1) [0xa2b151]
 /usr/bin/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_11_BufBuilderINS_16TrivialAllocatorEEERNS_14BSONObjBuilderEbi+0x6c6) [0xa2c9a6]
 /usr/bin/mongod(_ZN5mongo11newRunQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1_+0x230a) [0xd5f83a]
 /usr/bin/mongod() [0xba1052]
 /usr/bin/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_11HostAndPortE+0x580) [0xba2630]
 /usr/bin/mongod(_ZN5mongo16MyMessageHandler7processERNS_7MessageEPNS_21AbstractMessagingPortEPNS_9LastErrorE+0x9f) [0x770d5f]
 /usr/bin/mongod(_ZN5mongo17PortMessageServer17handleIncomingMsgEPv+0x4ee) [0x119f93e]
 /lib64/libpthread.so.0() [0x3978a079d1]
 /lib64/libc.so.6(clone+0x6d) [0x39786e8b6d]
2014-10-29T16:06:27.432+0000 [conn5] 

With the following Index information:

> db.last_seen_by_group.getIndexes()
[
	{
		"v" : 1,
		"name" : "_id_",
		"key" : {
			"_id" : 1
		},
		"ns" : "cache_release.last_seen_by_group"
	},
	{
		"v" : 1,
		"name" : "identity_id_1_group_id_1",
		"key" : {
			"identity_id" : 1,
			"group_id" : 1
		},
		"unique" : true,
		"ns" : "cache_release.last_seen_by_group"
	}
]

Extract from log files after restarting showing version info etc.

2014-10-29T16:07:03.652+0000 ***** SERVER RESTARTED *****
2014-10-29T16:07:03.662+0000 [initandlisten] MongoDB starting : pid=22616 port=27017 dbpath=/mongodata/mongod 64-bit host=tparelmca1.clarity.net
2014-10-29T16:07:03.662+0000 [initandlisten] db version v2.6.5
2014-10-29T16:07:03.662+0000 [initandlisten] git version: e99d4fcb4279c0279796f237aa92fe3b64560bf6
2014-10-29T16:07:03.662+0000 [initandlisten] build info: Linux build8.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
2014-10-29T16:07:03.662+0000 [initandlisten] allocator: tcmalloc
2014-10-29T16:07:03.662+0000 [initandlisten] options: { config: "/etc/mongod.conf", net: { http: { enabled: false }, port: 27017 }, operationProfiling: { mode: "slowOp", slowOpThresholdMs: 100 }, processManagement: { fork: true, pidFilePath: "/var/run/mongo/mongod.pid" }, storage: { dbPath: "/mongodata/mongod", directoryPerDB: true, journal: { enabled: true } }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongo/mongod.log" } }
2014-10-29T16:07:03.664+0000 [initandlisten] journal dir=/mongodata/mongod/journal

Comment by Ramon Fernandez Marina [ 12/Sep/14 ]

Thanks for letting us know the workaround solved your issue steffen.

Comment by Steffen [ 10/Sep/14 ]

Hello Ramon,

we solved this issue with the downgrade like you described.
Thanks
Steffen

Comment by Ramon Fernandez Marina [ 25/Aug/14 ]

steffen, the workaround I posted above is no good – my apologies. Also I'm told that renaming system.indexes is not safe (see SERVER-5955), as the server may exhibit undefined behavior when the collection is missing, so I'd recommend renaming it back.

As for the actual issue, I was able to work around it by going back to 2.4.10 to get rid of the unwanted index. Here's how my sample index looks:

> db.system.indexes.getIndexSpecs()
[
        {
                "v" : 1,
                "key" : {
                        "x" : NumberLong(1),
                        "y" : NumberLong(1)
                },
                "unique" : true,
                "ns" : "test.system.indexes",
                "name" : "x_1_y_1"
        }
]

When I try dropIndexes() on 2.6.4 then I observe the behavior you reported:

MongoDB shell version: 2.6.4
> db.system.indexes.dropIndexes()
2014-08-25T14:43:08.266-0400 DBClientCursor::init call() failed
2014-08-25T14:43:08.267-0400 Error: error doing query: failed at src/mongo/shell/query.js:81
2014-08-25T14:43:08.268-0400 trying reconnect to 127.0.0.1:27017 (127.0.0.1) failed
2014-08-25T14:43:08.268-0400 warning: Failed to connect to 127.0.0.1:27017, reason: errno:61 Connection refused
2014-08-25T14:43:08.268-0400 reconnect 127.0.0.1:27017 (127.0.0.1) failed failed couldn't connect to server 127.0.0.1:27017 (127.0.0.1), connection attempt failed

But when I rolled back to 2.4.10 I was able to get rid of the offending index, despite a confusing error message:

MongoDB shell version: 2.4.10
connecting to: test
> db.system.indexes.dropIndexes()
{
    "nIndexesWas" : 0,
    "msg" : "non-_id indexes dropped for collection",
    "ok" : 1
}
> db.system.indexes.getIndexSpecs()
[ ]

Right after I did that my sample replica set recovered to a healthy state.

Comment by Steffen [ 22/Aug/14 ]

renaming worked.

> db.system.indexes.renameCollection('test')

Bug deleting all Indexes doesn't have any effect, since system.indexes is empty / not there anymore

shard3:PRIMARY> db.test.dropIndexes()
{
	"nIndexesWas" : 0,
	"msg" : "non-_id indexes dropped for collection",
	"ok" : 1
}

I tried to delete the document but this fails if there is no system.indexes collection.

> db.test.find({"ns" : "database1.system.indexes"})
{ "v" : 1, "key" : { "target" : NumberLong(1), "relation" : NumberLong(1), "source" : NumberLong(1) }, "unique" : true, "ns" : "database1.system.indexes", "background" : NumberLong(1), "name" : "target_1_relation_1_source_1" }
> db.test.remove({"ns" : "database1.system.indexes"})
WriteResult({
    "nRemoved" : 0,
    "writeError" : {
        "code" : 2,
        "errmsg" : "error processing query: ns=database1.test limit=0 skip=0\nTree: ns == \"database1.system.indexes\"\nSort: {}\nProj: {}\n No query solutions"
    }
})

Comment by Ramon Fernandez Marina [ 22/Aug/14 ]

steffen, I'm able to reproduce the behavior you describe, so we'll investigate. I think I've found a workaround by renaming the system.indexes collection:

> use test
> db.system.indexes.getIndexSpecs()
[
        {
                "v" : 1,
                "key" : {
                        "_id" : 1
                },
                "ns" : "test.system.indexes",
                "name" : "_id_"
        }
]
> db.system.indexes.renameCollection("foo")
{ "ok" : 1 }
> db.system.indexes.getIndexSpecs()
[ ]
> db.foo.dropIndexes()
{
        "nIndexesWas" : 0,
        "msg" : "non-_id indexes dropped for collection",
        "ok" : 1
}

Can you give this workaround a try and see if it solves the replication problem?

Thanks,
Ramón.

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