[SERVER-14057] Changing TTL expiration time with collMod does not correctly update index definition Created: 27/May/14  Updated: 11/Jul/16  Resolved: 01/Dec/14

Status: Closed
Project: Core Server
Component/s: Storage
Affects Version/s: None
Fix Version/s: 2.6.6, 2.8.0-rc2

Type: Bug Priority: Major - P3
Reporter: Steve Briskin (Inactive) Assignee: J Rassi
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
Tested
Operating System: ALL
Backport Completed:
Participants:

 Description   

Using collmod to adjust the TTL window prints an incorrect expireAfterSeconds_old value.

I've had this happen several times on 2.6.0 and 2.6.1 but have not been able to reproduce it.

The command was run around 2014-05-27T15:14:28.086+0000.

index specs shows TTL to be 518400s.

oplog1:PRIMARY> db.oplog_i2.getIndexSpecs()
[
	{
		"v" : 1,
		"key" : {
			"_id" : 1
		},
		"ns" : "4fb2a07b87d1d86fa8ba6f07.oplog_i2",
		"name" : "_id_"
	},
	{
		"v" : 1,
		"key" : {
			"groupId" : 1,
			"rsId" : 1,
			"valid" : 1,
			"end" : 1,
			"_id" : 1
		},
		"ns" : "4fb2a07b87d1d86fa8ba6f07.oplog_i2",
		"name" : "groupId_1_rsId_1_valid_1_end_1__id_1"
	},
	{
		"v" : 1,
		"key" : {
			"end_date" : 1
		},
		"ns" : "4fb2a07b87d1d86fa8ba6f07.oplog_i2",
		"name" : "end_date_1",
		"expireAfterSeconds" : 518400,
		"background" : true
	}
]

Running collmod reports the old window to be 176400:

oplog1:PRIMARY> db.runCommand({collMod: "oplog_i2",
...               index: {keyPattern: {end_date : 1},
...               expireAfterSeconds: 900000}})
{
	"expireAfterSeconds_old" : 176400,
	"expireAfterSeconds_new" : 900000,
	"ok" : 1
}

Oldest record in the collection:

oplog1:PRIMARY> db.oplog_i2.find({}, {end_date:1}).sort({end_date : 1}).limit(1)
{ "_id" : ObjectId("537cc26ee4b04494b5ce2d26"), "end_date" : ISODate("2014-05-21T15:12:46.758Z") }



 Comments   
Comment by Githook User [ 01/Dec/14 ]

Author:

{u'username': u'jrassi', u'name': u'Jason Rassi', u'email': u'rassi@10gen.com'}

Message: SERVER-14057 Changing TTL should invalidate catalog's cached spec obj
Branch: master
https://github.com/mongodb/mongo/commit/c1c8778a5b7a1fa9f5cd5625fb3fd9dc7d667d37

Comment by Githook User [ 01/Dec/14 ]

Author:

{u'username': u'jrassi', u'name': u'Jason Rassi', u'email': u'rassi@10gen.com'}

Message: SERVER-14057 Changing TTL should invalidate catalog's cached spec obj
Branch: v2.6
https://github.com/mongodb/mongo/commit/d331763a98ba86dcbfceb155c77fb3cb65deac5d

Comment by J Rassi [ 24/Nov/14 ]

I have diagnosed this issue as a regression introduced in 2.6.0 by the introduction of the index catalog abstraction. In v2.4, all accesses of the index "info object" occur through the IndexDetails class, which reads directly from the on-disk index definition. In v2.6 and master, some accesses of the index "info object" occur through the index catalog, which reads from a cached copy of the index definition (owned by the IndexDescriptor). The bug is that the collMod command was not updated to invalidate this cached index definition. As a result, after running a collMod, some subsequent operations will read from an outdated index definition (including renameCollection, further calls to collMod, and more) until the collection or database is closed.

See repro below (reproduces on 2.6.5 and 2.8.0-rc0).

> db.foo.drop()
true
> db.foo.ensureIndex({a:1},{expireAfterSeconds:1})
{
	"createdCollectionAutomatically" : true,
	"numIndexesBefore" : 1,
	"numIndexesAfter" : 2,
	"ok" : 1
}
> db.foo.runCommand({collMod:"foo",index:{keyPattern:{a:1},expireAfterSeconds:2}})
{ "expireAfterSeconds_old" : 1, "expireAfterSeconds_new" : 2, "ok" : 1 }
> db.foo.getIndexes()
[
	{
		"v" : 1,
		"key" : {
			"_id" : 1
		},
		"name" : "_id_",
		"ns" : "test.foo"
	},
	{
		"v" : 1,
		"key" : {
			"a" : 1
		},
		"name" : "a_1",
		"ns" : "test.foo",
		"expireAfterSeconds" : 2 // Seems like index definition was successfully updated...
	}
]
> db.foo.runCommand({collMod:"foo",index:{keyPattern:{a:1},expireAfterSeconds:3}})
{ "expireAfterSeconds_old" : 1, "expireAfterSeconds_new" : 3, "ok" : 1 } // INCORRECT: expireAfterSeconds_old expected to be 2.
> db.adminCommand({renameCollection:"test.foo",to:"test2.foo"})
{ "ok" : 1 }
> db.getSiblingDB("test2").foo.getIndexes()
[
	{
		"v" : 1,
		"key" : {
			"_id" : 1
		},
		"name" : "_id_",
		"ns" : "test2.foo"
	},
	{
		"v" : 1,
		"key" : {
			"a" : 1
		},
		"name" : "a_1",
		"ns" : "test2.foo",
		"expireAfterSeconds" : 1 // INCORRECT: expireAfterSeconds expected to be 3.
	}
]

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