[SERVER-37624] Sessions never expire when you change value of localLogicalSessionTimeoutMinutes Created: 15/Oct/18  Updated: 29/Oct/23  Resolved: 02/Nov/18

Status: Closed
Project: Core Server
Component/s: Sharding
Affects Version/s: 4.0.3
Fix Version/s: 3.6.11, 4.0.5, 4.1.5

Type: Bug Priority: Major - P3
Reporter: Remi Jolin Assignee: Blake Oler
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Depends
is depended on by SERVER-46982 localLogicalSessionTimeoutMinutes do... Closed
Related
related to SERVER-43218 lsidTTLIndex is incorrect after modif... Backlog
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Requested:
v4.0, v3.6
Steps To Reproduce:

Short repro:

$ ./mongod --replSet replSet --dbpath ~/Temp/Data/replSet/ --logpath ~/Temp/Data/replSet/mongod.log --setParameter logicalSessionRefreshMillis=10 --setParameter localLogicalSessionTimeoutMinutes=0 --fork
$ ./mongo
replSet:SECONDARY> rs.initiate();
...
replSet:PRIMARY> db.shutdownServer({force:true});
...
$ ./mongod --replSet replSet --dbpath ~/Temp/Data/replSet/ --logpath ~/Temp/Data/replSet/mongod.log --setParameter logicalSessionRefreshMillis=10 --setParameter localLogicalSessionTimeoutMinutes=3 --fork
 
This produces the said message in the log:
2018-10-11T15:53:35.906+0000 I COMMAND  [LogicalSessionCacheRefresh] command config.$cmd command: createIndexes { createIndexes: "system.sessions", indexes: [ { key: { lastUse: 1 }, name: "lsidTTLIndex", expireAfterSeconds: 7800 } ], $db: "config" } numYields:0 ok:0 errMsg:"Index with name: lsidTTLIndex already exists with different options" errName:IndexOptionsConflict errCode:85 reslen:163 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_msg 0ms
2018-10-11T15:53:35.906+0000 I CONTROL  [LogicalSessionCacheRefresh] Sessions collection is not set up; waiting until next sessions refresh interval: Index with name: lsidTTLIndex already exists with different options

From reporter:

2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten] MongoDB starting : pid=15496 port=27017 dbpath=/data/test-standalone 64-bit host=mmovh6.milanamos.net
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten] db version v4.0.3
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten] git version: 7ea530946fa7880364d88c8d8b6026bbc9ffa48c
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.1.0g  2 Nov 2017
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten] modules: none
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten] build environment:
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten]     distmod: ubuntu1804
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten]     distarch: x86_64
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2018-10-11T13:33:34.566+0000 I CONTROL  [initandlisten] options: { config: "/data/test-standalone/automation-mongod.conf", net: { bindIp: "0.0.0.0", bindIpAll: true, port: 27017 }, op
erationProfiling: { mode: "slowOp", slowOpThresholdMs: 100 }, processManagement: { fork: true }, security: { authorization: "enabled", keyFile: "/var/lib/mongodb-mms-automation/keyfil
e" }, setParameter: { authenticationMechanisms: "SCRAM-SHA-1,SCRAM-SHA-256", cursorTimeoutMillis: "7200000", localLogicalSessionTimeoutMinutes: "130" }, storage: { dbPath: "/data/test
-standalone", engine: "wiredTiger" }, systemLog: { destination: "file", path: "/data/test-standalone/mongodb.log" } }
 
[...]
 
2018-10-11T15:53:35.906+0000 D COMMAND  [LogicalSessionCacheRefresh] run command config.$cmd { createIndexes: "system.sessions", indexes: [ { key: { lastUse: 1 }, name: "lsidTTLIndex", expireAfterSeconds: 7800 } ], $db: "config" }
2018-10-11T15:53:35.906+0000 D STORAGE  [LogicalSessionCacheRefresh] NamespaceUUIDCache: registered namespace config.system.sessions with UUID 8536711e-8cae-4309-9de1-e73aa77c7ae0
2018-10-11T15:53:35.906+0000 D -        [LogicalSessionCacheRefresh] User Assertion: IndexOptionsConflict: Index with name: lsidTTLIndex already exists with different options src/mongo/db/commands/create_indexes.cpp 230
2018-10-11T15:53:35.906+0000 D REPL     [LogicalSessionCacheRefresh] Waiting for write concern. OpTime: { ts: Timestamp(0, 0), t: -1 }, write concern: { w: 1, wtimeout: 0 }
2018-10-11T15:53:35.906+0000 D COMMAND  [LogicalSessionCacheRefresh] assertion while executing command 'createIndexes' on database 'config' with arguments '{ createIndexes: "system.sessions", indexes: [ { key: { lastUse: 1 }, name: "lsidTTLIndex", expireAfterSeconds: 7800 } ], $db: "config" }': IndexOptionsConflict: Index with name: lsidTTLIndex already exists with different options
2018-10-11T15:53:35.906+0000 I COMMAND  [LogicalSessionCacheRefresh] command config.$cmd command: createIndexes { createIndexes: "system.sessions", indexes: [ { key: { lastUse: 1 }, name: "lsidTTLIndex", expireAfterSeconds: 7800 } ], $db: "config" } numYields:0 ok:0 errMsg:"Index with name: lsidTTLIndex already exists with different options" errName:IndexOptionsConflict errCode:85 reslen:163 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_msg 0ms
2018-10-11T15:53:35.906+0000 I CONTROL  [LogicalSessionCacheRefresh] Sessions collection is not set up; waiting until next sessions refresh interval: Index with name: lsidTTLIndex already exists with different options

and in mongo today:

> new Date()
ISODate("2018-10-15T08:21:27.022Z")
> db.aggregate([{$listLocalSessions: {allUsers: true}}])
{ "_id" : { "id" : UUID("3a86b514-a453-478f-810d-8f2dd4c057ca"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-12T13:17:38.818Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("489ea100-fb41-4e4e-bd0b-623c86c46102"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:22:49.169Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("ede7ecab-9ea2-4106-ba8f-27de7add92e6"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:34:44.824Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("0de2fde6-253c-4ccc-b6c9-b5ca65ec494e"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:23:50.855Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("dd73b620-2b82-4d64-b296-4c2fbe8b2495"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-12T13:17:16.084Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("f680077a-824a-4cf3-b970-e05f6aa5b2f6"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:10:38.579Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("35cbc73b-5796-491f-8d80-415e25a2d552"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-12T13:17:40.570Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("ed918f82-383c-4162-97f2-a90bde93374c"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-12T13:17:14.419Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("cb3b4bff-3462-4d8a-a228-bd8de31d4503"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:36:39.143Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("8a3f879a-22b7-4c4e-96dc-c4a630b50ac0"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:35:50.095Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("c39c5f57-ad0d-480b-bac4-540d9ae75fd2"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:34:43.173Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("592f7a6a-c643-4781-a657-8e597a02ee95"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:33:50.600Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("b375b3a8-8fd3-48b0-b43c-c61341759c03"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:32:03.184Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("0192ff36-9430-4262-ad7e-62fe0bd35d69"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:33:48.904Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("89625c86-64e0-4409-a6e6-c82136aed279"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:26:09.546Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("a7c81832-940f-4c8d-ac47-8b66a66b043f"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:16:37.304Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("78c2256b-7e1d-4a3a-97bf-5b87dfd472e5"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:15:35.193Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("4d7ad3f5-e8c8-4631-bca7-9180fc1eb5ec"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-12T14:00:32.620Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("bdb7f93d-7966-4ba9-8223-f85592e89e34"), "uid" : BinData(0,"gvI6E3rwpLEMfFQo/pac02FLjxJ9+Zfrt+aIKnzCZeE=") }, "lastUse" : ISODate("2018-10-11T15:25:07.802Z"), "user" : "adminMongo@admin" }
{ "_id" : { "id" : UUID("0361c9da-f881-4eaa-be95-4015178cfba2"), "uid" : BinData(0,"7D7UuwqwK21uSTtaadvqpdytlQ+wwVZnZdE3WGwp8Uk=") }, "lastUse" : ISODate("2018-10-11T15:04:00.289Z"), "user" : "optimodeWrite@optimode" }
Type "it" for more
>

Sprint: Sharding 2018-11-05, Sharding 2018-12-31
Participants:

 Description   

For an existing 4.0 DB, if you change the value of localLogicalSessionTimeoutMinutes, the new sessions never expire because the system tries to recreate the index lsidTTLIndex of config.system.session and get an error "Index with name: lsidTTLIndex already exists with different options src/mongo/db/commands/create_indexes.cpp 230"

This bug prevents us to move to mongodb 4.0



 Comments   
Comment by Githook User [ 02/Feb/19 ]

Author:

{'name': 'Blake Oler', 'email': 'blake.oler@mongodb.com', 'username': 'BlakeIsBlake'}

Message: SERVER-37624 Allow sessions collection TTL index expiration value to change upon node restart

(cherry picked from commit f13d685ade22d662070bde942eb094790d4e7b8d)
Branch: v3.6
https://github.com/mongodb/mongo/commit/2b23402c019e05b98347dbb5760f51a4bb43d7d7

Comment by Githook User [ 09/Nov/18 ]

Author:

{'name': 'Blake Oler', 'email': 'blake.oler@mongodb.com', 'username': 'BlakeIsBlake'}

Message: SERVER-37624 Allow sessions collection TTL index expiration value to change upon node restart

(cherry picked from commit f13d685ade22d662070bde942eb094790d4e7b8d)
Branch: v4.0
https://github.com/mongodb/mongo/commit/bde5e3ad2316b450d467394c3b98fb26ff895193

Comment by Githook User [ 02/Nov/18 ]

Author:

{'name': 'Blake Oler', 'email': 'blake.oler@mongodb.com', 'username': 'BlakeIsBlake'}

Message: SERVER-37624 Allow sessions collection TTL index expiration value to change upon node restart
Branch: master
https://github.com/mongodb/mongo/commit/f13d685ade22d662070bde942eb094790d4e7b8d

Comment by Kaloian Manassiev [ 25/Oct/18 ]

Hi rj-10gen@arsynet.com,

Thanks for the update and I am glad that your issue got worked around.

Again, apologies for the inconvenience and please keep monitoring this ticket for when we schedule the work on it.

Best regards,
-Kal.

Comment by Remi Jolin [ 24/Oct/18 ]

ok, I've deleted the index. 

 

I'm now going further with my tests.

I hope it will run the same on a sharded/replicated DB

Comment by Kaloian Manassiev [ 24/Oct/18 ]

Hello rj-10gen@arsynet.com,

Apologies for the delayed response. By default the readWrite role doesn't give access to the system collections, so you will have to invoke the following grant command before attempting to drop the index:

db.grantRolesToUser("<user>", [{role: "readWrite", db: "config", collection: "system.sessions" }]);

Make sure after you are done to revoke that role using:

db. revokeRolesFromUser("<user>", [{role: "readWrite", db: "config", collection: "system.sessions" }]);

Let me know if this works.

Best regards,
-Kal.

Comment by Remi Jolin [ 18/Oct/18 ]

> db.system.sessions.dropIndex("lsidTTLIndex")
{
        "ok" : 0,
        "errmsg" : "not authorized on config to execute command { deleteIndexes: \"system.sessions\", index: \"lsidTTLIndex\", lsid: { id: UUID(\"eb00e0b9-5d74-443e-a5bc-f4331dd13657\") }, $db: \"config\" }",
        "code" : 13,
        "codeName" : "Unauthorized"
}

Comment by Kaloian Manassiev [ 18/Oct/18 ]

Hi rj-10gen@arsynet.com,

Thank you very much for your report and for the detailed explanation. This is indeed a legitimate bug which prevents the logicalSessionRefreshMinutes parameter to change between releases and I have put it for scheduling. Please keep watching this ticket for more information on when it will get fixed.

As a work-around in order to unblock your upgrade, after upgrade can you please run the following command in order to get the index to be recreated:

replSet:PRIMARY> use config;
replSet:PRIMARY> db.system.sessions.dropIndex("lsidTTLIndex");

If you are running a sharded cluster, you should be able to just connect to mongos and run that, otherwise to the replica set primary.

Best regards,
-Kal.

Generated at Thu Feb 08 04:46:32 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.