[SERVER-423] db.<dname>.ensureIndex( { uid: 1 }, {unique: true} ) eats up all ram and swap Created: 13/Nov/09  Updated: 12/Jul/16  Resolved: 06/Apr/10

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

Type: Bug Priority: Major - P3
Reporter: Alexey Zilber Assignee: Eliot Horowitz (Inactive)
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

AWS Linux m1.large instance. x64
Linux ip-10-244-51-31 2.6.21.7-2.fc8xen #1 SMP Fri Feb 15 12:34:28 EST 2008 x86_64 x86_64 x86_64 GNU/Linux
Thu Nov 12 17:50:50 Mongo DB : starting : pid = 2413 port = 27017 dbpath = /mnt/mdb master = 1 slave = 0 64-bit
Thu Nov 12 17:50:50 db version v1.1.3, pdfile version 4.5
Thu Nov 12 17:50:50 git version: aa8b12e13fbbdfb293d94786dcc0df589cabef99
Thu Nov 12 17:50:50 sys info: Linux ofc-n1.10gen.com 2.6.23.17-88.fc7 #1 SMP Thu May 15 00:02:29 EDT 2008 x86_64


Participants:

 Description   

When creating a NON-Unique index, index is created normally. On a collection with 3.5M documents:
I did a db.<dname>.ensureIndex(

{ uid: 1 }

):

Fri Nov 13 13:44:24 cpu: 4000 0 0%
Fri Nov 13 13:44:25 building new index on

{ uid: 1.0 }

for <dbname>.Farm...
Fri Nov 13 13:44:25 Buildindex <dbname>,Farm idxNo:1 { ns: "<dbname>.Farm", key:

{ uid: 1.0 }

, name: "uid_1" }
Fri Nov 13 13:48:22 done for 3517687 records 237.078secs
Fri Nov 13 13:44:25 insert <dnbame>.system.indexes 237259ms
Fri Nov 13 13:48:22 cpu: 238225 237265 99%

I did a db.<dbname>.dropIndexes();
{
"nIndexesWas" : 2,
"msg" : "all indexes deleted for collection",
"ok" : 1
}

Then db.<dname>.ensureIndex(

{ uid: 1 }

,

{unique: true}

)

Fri Nov 13 13:51:10 cpu: 4000 0 0%
Fri Nov 13 13:51:10 building new index on

{ uid: 1.0 }

for <dname>.Farm...
Fri Nov 13 13:51:11 Buildindex <dbname>.Farm idxNo:1 { ns: "<dname>.Farm", key:

{ uid: 1.0 }

, name: "uid_1", unique: true }
Fri Nov 13 14:05:28 User Exception E11000 duplicate key errorindex: <dname>.Farm.$uid_1 dup key: { : 501272713 }
Fri Nov 13 14:05:38 <dbname>.system.indexes Caught Assertion insert, continuing
Fri Nov 13 13:51:10 insert <dbname>.system.indexes exception userassert:E11000 duplicate key errorindex: <dbname>.Farm.$uid_1 dup key: { : 501272713 } 867252ms
Fri Nov 13 14:05:38 cpu: 867851 867252 99%

During this second run, mongo went almost 2GB into swap and as you can see, took almost 4 times as long before even detecting a conflict. I had to restart mongodb to clear up the ram usage.. it was using all system ram (RES 7.2G). The whole collection size is around 16G.

> db.<dbname>.dropIndexes();
{
"nIndexesWas" : 1,
"msg" : "all indexes deleted for collection",
"ok" : 1
}

Now, even adding a regular index causes massive swap use:
db.<dbname>.ensureIndex(

{ uid: 1 }

)

top - 14:16:50 up 20:28, 4 users, load average: 1.50, 0.89, 0.93
Tasks: 66 total, 2 running, 64 sleeping, 0 stopped, 0 zombie
Cpu(s): 42.7%us, 0.3%sy, 0.0%ni, 49.3%id, 0.7%wa, 0.0%hi, 0.0%si, 6.9%st
Mem: 7872040k total, 7855940k used, 16100k free, 104k buffers
Swap: 8388600k total, 1092068k used, 7296532k free, 5337924k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
5480 mongo 19 0 22.1g 7.3g 5.1g S 82 96.6 0:13.91 mongod

It completes, but ram is not freed:

Fri Nov 13 14:13:34 cpu: 4000 0 0%
Fri Nov 13 14:13:34 building new index on

{ uid: 1.0 }

for <dbname>.Farm...
Fri Nov 13 14:13:34 Buildindex <dbname>.Farm idxNo:1 { ns: "<dbname>.Farm", key:

{ uid: 1.0 }

, name: "uid_1" }
Fri Nov 13 14:16:58 done for 3517687 records 203.592secs
Fri Nov 13 14:13:34 insert <dbname>.system.indexes 203648ms
Fri Nov 13 14:16:58 cpu: 204073 203655 99%



 Comments   
Comment by Eliot Horowitz (Inactive) [ 06/Apr/10 ]

this should be fixed in 1.4

Comment by Eliot Horowitz (Inactive) [ 17/Feb/10 ]

some changes in 1.3.2
anyway you could try that?

Comment by Alexey Zilber [ 17/Nov/09 ]

I can give you access to the instance where I have the csv file, you're welcome to see for yourself.

-Alex

Comment by auto [ 13/Nov/09 ]

Author:

{'name': 'Eliot Horowitz', 'email': 'eliot@10gen.com'}

Message: BDONObjBuilder::apendAsNumber
better fix for SERVER-423
http://github.com/mongodb/mongo/commit/ca785a040086939005a88b06fa77f9133751450e

Comment by Eliot Horowitz (Inactive) [ 13/Nov/09 ]

I cannot reproduce this.
I'm seeing a consistent 10% slowdown for unique, which is about what you should expect.
Can you make a reproducible test that we can try?

Comment by auto [ 13/Nov/09 ]

Author:

{'name': 'Eliot Horowitz', 'email': 'eliot@10gen.com'}

Message: some index building code cleaning looking at SERVER-423, but can't see anything yet
http://github.com/mongodb/mongo/commit/7db9f7ee87339b703d309f97fa20c17e243c5bad

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