The following has been tested on mongoDB v2.2.0rc0 & mongoDB v2.2.0:

1. 1. 1. The test:

First initialize the database:

> use test
> db.dropDatabase()
> db.createCollection('testdocuments')
> db.testdocuments.insert(

{ _id : ObjectId("000000000000000000000001") }

)

Then populate a document's inner collection with objects:

> for ( var i = 1; i < 10000; i++) { db.testdocuments.update(

{ _id : ObjectId("000000000000000000000001") }

, { $push : { 'a' :

{ uid1 : i, uid2: i }

} }) }

Then add a new outer field:

> db.testdocuments.update(

{ _id : ObjectId("000000000000000000000001") }

, { $set :

{ 'aNewOuterField' : 1 }

})

All is well and the update takes normal time. But, if those inner documents are indexed:

> db.testdocuments.ensureIndex(

{ 'a.uid1' : 1 }

)

mongodb-console-> Thu Aug 30 14:17:31 [conn4] build index test.testdocuments

{ a.uid1: 1.0 }

mongodb-console-> Thu Aug 30 14:17:34 [conn4] build index done. scanned 1 total records. 2.244 secs
mongodb-console-> Thu Aug 30 14:17:34 [conn4] insert test.system.indexes keyUpdates:0 locks(micros) w:2244536 2244ms

and we add another outer field :

> db.testdocuments.update(

{ _id : ObjectId("000000000000000000000001") }

, { $set :

{ 'anotherOuterField' : 1 }

})

Then we get the MongoDB console reporting the action as slow:

mongodb-console-> Thu Aug 30 14:20:01 [conn4] update test.testdocuments query:

{ _id: ObjectId('000000000000000000000001') }

update: { $set:

{ anotherOuterField: 1.0 }

} idhack:1 nupdated:1 keyUpdates:0 locks(micros) w:4191036 4191ms

Indeed, the last operation has been reported to have taken more than 4 seconds even though there was no index modification at all.

This might be due to the document being moved but setting the profiler 'on',

> db.setProfilingLevel(1)

and adding another outer field:

> db.testdocuments.update(

{ _id : ObjectId("000000000000000000000001") }

, { $set :

{ 'oneLastOuterField' : 1 }

})

gives us the following:

> db.system.profile.find().pretty()

{
"ts" : ISODate("2012-08-30T18:23:03.053Z"),
"op" : "update",
"ns" : "test.testdocuments",
"query" :

{ "_id" : ObjectId("000000000000000000000001") }

,
"updateobj" : {
"$set" :

{ "oneLastOuterField" : 1 }

},
"idhack" : true,
"nupdated" : 1,
"keyUpdates" : 0,
"numYield" : 0,
"lockStats" : {
"timeLockedMicros" :

{ "r" : NumberLong(0), "w" : NumberLong(4064791) }

,
"timeAcquiringMicros" :

{ "r" : NumberLong(0), "w" : NumberLong(47) }

},
"millis" : 4064,
"client" : "127.0.0.1",
"user" : ""
}

which definitely shows that the delay isn't due to the document being 'moved'.

Adding to the inner collection is not faster either as

> db.testdocuments.update(

{ _id : ObjectId("000000000000000000000001") }

, { $push : { 'a' :

{ uid1 : -1, uid2: -1 }

} })

gives us the following profile

> db.system.profile.find().pretty()

{
"ts" : ISODate("2012-08-30T18:32:34.080Z"),
"op" : "update",
"ns" : "test.testdocuments",
"query" :

{ "_id" : ObjectId("000000000000000000000001") }

,
"updateobj" : {
"$push" : {
"a" :

{ "uid1" : -1, "uid2" : -1 }

}
},
"nscanned" : 1,
"nupdated" : 1,
"keyUpdates" : 1,
"numYield" : 0,
"lockStats" : {
"timeLockedMicros" :

{ "r" : NumberLong(0), "w" : NumberLong(4057496) }

,
"timeAcquiringMicros" :

{ "r" : NumberLong(0), "w" : NumberLong(213) }

},
"millis" : 4057,
"client" : "127.0.0.1",
"user" : ""
}