Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-49390

TooManyLogicalSessions: Cannot add session into the cache (error code 261) on standalone MongoDB

XMLWordPrintableJSON

    • Type: Icon: Bug Bug
    • Resolution: Works as Designed
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 4.0.19
    • Component/s: Internal Code
    • Labels:
      None
    • ALL

      I am getting the same error in a mongodb setup (single replicaset; no sharding)

      MongoDB Enterprise node01:PRIMARY> show dbs
2020-07-08T12:56:07.934+0000 E QUERY    [js] Error: listDatabases failed:{
	"ok" : 0,
	"errmsg" : "cannot add session into the cache",
	"code" : 261,
	"codeName" : "TooManyLogicalSessions"
} :
_getErrorWithCode@src/mongo/shell/utils.js:25:13
Mongo.prototype.getDBs@src/mongo/shell/mongo.js:139:1
shellHelper.show@src/mongo/shell/utils.js:882:13
shellHelper@src/mongo/shell/utils.js:766:15
@(shellhelp2):1:1

      MongoDB version is 4.0.19

      MongoDB Enterprise node01:PRIMARY> version()
4.0.19

      Following are excerpts from mongod log

      2020-07-08T12:56:03.123+0000 I NETWORK  [listener] connection accepted from XX.YY.20.30:47572 #2050276 (5 connections now open)
2020-07-08T12:56:03.124+0000 I NETWORK  [conn2050276] received client metadata from XX.YY.20.30:47572 conn2050276: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.19" }, os: { type: "Linux", name: "CentOS Linux release 7.6.1810 (Core) ", architecture: "x86_64", version: "Kernel 3.10.0-957.el7.x86_64" } }
2020-07-08T12:56:03.138+0000 I ACCESS   [conn2050276] Successfully authenticated as principal rootuser on admin from client XX.YY.20.30:47572
2020-07-08T12:56:22.557+0000 I COMMAND  [PeriodicTaskRunner] task: UnusedLockCleaner took: 589ms
2020-07-08T12:57:23.176+0000 I COMMAND  [PeriodicTaskRunner] task: UnusedLockCleaner took: 618ms
2020-07-08T12:58:23.770+0000 I COMMAND  [PeriodicTaskRunner] task: UnusedLockCleaner took: 593ms
2020-07-08T12:59:24.472+0000 I COMMAND  [PeriodicTaskRunner] task: UnusedLockCleaner took: 701ms
2020-07-08T12:59:59.041+0000 I CONTROL  [LogicalSessionCacheReap] Sessions collection is not set up; waiting until next sessions reap interval: sharding state is not yet initialized
2020-07-08T12:59:59.041+0000 I CONTROL  [LogicalSessionCacheRefresh] Sessions collection is not set up; waiting until next sessions refresh interval: sharding state is not yet initialized
2020-07-08T13:00:25.044+0000 I COMMAND  [PeriodicTaskRunner] task: UnusedLockCleaner took: 572ms
2020-07-08T13:01:25.624+0000 I COMMAND  [PeriodicTaskRunner] task: UnusedLockCleaner took: 579ms
2020-07-08T13:02:26.222+0000 I COMMAND  [PeriodicTaskRunner] task: UnusedLockCleaner took: 597ms
2020-07-08T13:03:26.738+0000 I COMMAND  [PeriodicTaskRunner] task: UnusedLockCleaner took: 515ms
2020-07-08T13:04:27.236+0000 I COMMAND  [PeriodicTaskRunner] task: UnusedLockCleaner took: 498ms
2020-07-08T13:04:38.185+0000 I NETWORK  [conn2050276] end connection XX.YY.20.30:47572 (4 connections now open)
2020-07-08T13:04:59.041+0000 I CONTROL  [LogicalSessionCacheReap] Sessions collection is not set up; waiting until next sessions reap interval: sharding state is not yet initialized
2020-07-08T13:04:59.041+0000 I CONTROL  [LogicalSessionCacheRefresh] Sessions collection is not set up; waiting until next sessions refresh interval: sharding state is not yet initialized

      Any help would be useful. The cluster is down and this is affecting our workloads.

      Also, is there a way to reopen this JIRA or should I open a new one?

      When we monitor number of sessions on MongoDB we see it is always increasing.

      Command to monitor sessions.

      db.aggregate( [  { $listLocalSessions: { allUsers: true } },{$count: "count"} ] )

      This was observed in two separate single replicaset unsharded setup. Example RS status:

      MongoDB Enterprise node01:PRIMARY> rs.status()
{
	"set" : "node01",
	"date" : ISODate("2020-07-09T06:35:31.919Z"),
	"myState" : 1,
	"term" : NumberLong(32),
	"syncingTo" : "",
	"syncSourceHost" : "",
	"syncSourceId" : -1,
	"heartbeatIntervalMillis" : NumberLong(2000),
	"majorityVoteCount" : 2,
	"writeMajorityCount" : 2,
	"optimes" : {
		"lastCommittedOpTime" : {
			"ts" : Timestamp(1594276531, 1),
			"t" : NumberLong(32)
		},
		"lastCommittedWallTime" : ISODate("2020-07-09T06:35:31.494Z"),
		"readConcernMajorityOpTime" : {
			"ts" : Timestamp(1594276531, 1),
			"t" : NumberLong(32)
		},
		"readConcernMajorityWallTime" : ISODate("2020-07-09T06:35:31.494Z"),
		"appliedOpTime" : {
			"ts" : Timestamp(1594276531, 1),
			"t" : NumberLong(32)
		},
		"durableOpTime" : {
			"ts" : Timestamp(1594276531, 1),
			"t" : NumberLong(32)
		},
		"lastAppliedWallTime" : ISODate("2020-07-09T06:35:31.494Z"),
		"lastDurableWallTime" : ISODate("2020-07-09T06:35:31.494Z")
	},
	"lastStableRecoveryTimestamp" : Timestamp(1594276461, 1),
	"lastStableCheckpointTimestamp" : Timestamp(1594276461, 1),
	"electionCandidateMetrics" : {
		"lastElectionReason" : "electionTimeout",
		"lastElectionDate" : ISODate("2020-06-23T08:17:47.513Z"),
		"electionTerm" : NumberLong(32),
		"lastCommittedOpTimeAtElection" : {
			"ts" : Timestamp(0, 0),
			"t" : NumberLong(-1)
		},
		"lastSeenOpTimeAtElection" : {
			"ts" : Timestamp(1592900226, 1),
			"t" : NumberLong(31)
		},
		"numVotesNeeded" : 2,
		"priorityAtElection" : 1,
		"electionTimeoutMillis" : NumberLong(10000),
		"numCatchUpOps" : NumberLong(0),
		"newTermStartDate" : ISODate("2020-06-23T08:17:48.222Z"),
		"wMajorityWriteAvailabilityDate" : ISODate("2020-06-23T08:17:49.324Z")
	},
	"members" : [
		{
			"_id" : 0,
			"name" : "node01:27201",
			"health" : 1,
			"state" : 1,
			"stateStr" : "PRIMARY",
			"uptime" : 1376299,
			"optime" : {
				"ts" : Timestamp(1594276531, 1),
				"t" : NumberLong(32)
			},
			"optimeDate" : ISODate("2020-07-09T06:35:31Z"),
			"syncingTo" : "",
			"syncSourceHost" : "",
			"syncSourceId" : -1,
			"infoMessage" : "",
			"electionTime" : Timestamp(1592900267, 1),
			"electionDate" : ISODate("2020-06-23T08:17:47Z"),
			"configVersion" : 705572,
			"self" : true,
			"lastHeartbeatMessage" : ""
		},
		{
			"_id" : 1,
			"name" : "node01:27203",
			"health" : 1,
			"state" : 2,
			"stateStr" : "SECONDARY",
			"uptime" : 1376270,
			"optime" : {
				"ts" : Timestamp(1594276521, 1),
				"t" : NumberLong(32)
			},
			"optimeDurable" : {
				"ts" : Timestamp(1594276521, 1),
				"t" : NumberLong(32)
			},
			"optimeDate" : ISODate("2020-07-09T06:35:21Z"),
			"optimeDurableDate" : ISODate("2020-07-09T06:35:21Z"),
			"lastHeartbeat" : ISODate("2020-07-09T06:35:30.675Z"),
			"lastHeartbeatRecv" : ISODate("2020-07-09T06:35:31.791Z"),
			"pingMs" : NumberLong(0),
			"lastHeartbeatMessage" : "",
			"syncingTo" : "node01:27201",
			"syncSourceHost" : "node01:27201",
			"syncSourceId" : 0,
			"infoMessage" : "",
			"configVersion" : 705572
		}
	],
	"ok" : 1,
	"$clusterTime" : {
		"clusterTime" : Timestamp(1594276531, 1),
		"signature" : {
			"hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
			"keyId" : NumberLong(0)
		}
	},
	"operationTime" : Timestamp(1594276531, 1)
}

            Assignee:
            dmitry.agranat@mongodb.com Dmitry Agranat
            Reporter:
            jdatta@imanisdata.com Joydip Datta
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

              Created:
              Updated:
              Resolved: