Adding a new database gets longer the more databases exist (listDatabase hits again)

MongoDB Percona Operator for MongoDB
1

Depending on the number of existing databases, it turns out that the creation time increases. It turns out listDatabases is called during the creation.

Question : is this call (listDatabase) originated from Percona or is it from MongoDB ?

{
“t”: {
“$date”: “2022-01-24T13:46:28.014+00:00”
},
“s”: “I”,
“c”: “COMMAND”,
“id”: 51803,
“ctx”: “conn277”,
“msg”: “Slow query”,
“attr”: {
“type”: “command”,
“ns”: “admin.$cmd”,
“command”: {
“listDatabases”: 1,
“maxTimeMS”: 600000,
“lsid”: {
“id”: {
“$uuid”: “e4858e8d-b4f3-4813-9db0-2b52643e6218”
},
“uid”: {
“$binary”: {
“base64”: “YGti/c5Tn4R/bgcsJkGhJh0d/qtIaBxXR/b+7uzn4M0=”,
“subType”: “0”
}
}
},
“$readPreference”: {
“mode”: “primaryPreferred”
},
“$clusterTime”: {
“clusterTime”: {
“$timestamp”: {
“t”: 1643031982,
“i”: 1
}
},
“signature”: {
“hash”: {
“$binary”: {
“base64”: “0zndY6QZhQTibmGSshvJT06DYos=”,
“subType”: “0”
}
},
“keyId”: 7056733904161472534
}
},
“$audit”: {
“$impersonatedUsers”: [
{
“user”: “db_9307”,
“db”: “db_9307”
}
],
“$impersonatedRoles”: [
{
“role”: “dbOwner”,
“db”: “db_9307”
}
]
},
“$client”: {
“driver”: {
“name”: “mongo-java-driver|legacy”,
“version”: “3.12.8”
},
“os”: {
“type”: “Windows”,
“name”: “Windows 10”,
“architecture”: “amd64”,
“version”: “10.0”
},
“platform”: “Java/Oracle Corporation/1.8.0_191-b12”,
“mongos”: {
“host”: “xxx-mongodb01-cluster-mongos-547975446f-4st85:27017”,
“client”: “127.0.0.1:41310”,
“version”: “4.4.10-11”
}
},
“$configServerState”: {
“opTime”: {
“ts”: {
“$timestamp”: {
“t”: 1643031982,
“i”: 1
}
},
“t”: 6
}
},
“$db”: “admin”
},
“numYields”: 0,
“reslen”: 595375,
“locks”: {
“ParallelBatchWriterMode”: {
“acquireCount”: {
“r”: 10300
}
},
“ReplicationStateTransition”: {
“acquireCount”: {
“w”: 10300
}
},
“Global”: {
“acquireCount”: {
“r”: 10300
}
},
“Database”: {
“acquireCount”: {
“r”: 10299
}
},
“Collection”: {
“acquireCount”: {
“r”: 51504
}
},
“Mutex”: {
“acquireCount”: {
“r”: 10299
}
},
“oplog”: {
“acquireCount”: {
“r”: 1
}
}
},
“storage”: {},
“protocol”: “op_msg”,
“durationMillis”: 5849
}
}

1 Like
2

Pls close - it’s MongoDB related

1 Like
3

Hello @jamoser! Are you tracking it on MongoDB side somehow?
Which version of MongoDB is it?

1 Like
4

As I said, you can close the ticket because it’s MongoDB related

1 Like
5

@jamoser I understand that it is MongoDB related, but I’m thinking we can fix it in Percona Server for MongoDB itself.

1 Like
6

I’ve already placed a ticket → https://jira.mongodb.org/browse/SERVER-62909

But seems this issue has already been fixed for 5.2 - but not for the 4.x version

1 Like
7

If it helps to analyse - some code snippets:

Creation of DB - approx xxx ms:

		    MongoDatabase db =  mongoClient.getDatabase(tenantId);
		    BasicDBObject command = new BasicDBObject("createUser", tenantId).append("pwd", myPwd).append("roles",
                    Collections.singletonList(new BasicDBObject("role", "dbOwner").append("db", tenantId)));
		    db.runCommand(command);

Add first collection - approx xx’xxx ms when having 50k databases, only here listDatabases() is called (?!), which takes xx’xxx ms:

		MongoDatabase database = mongoClient.getDatabase(tenantId);
		MongoCollection<Document> collection = database.getCollection("first_coll");
		collection.insertOne(first_coll_doc);

Add second collection - approx xx ms, no listDatabases() is called:

		MongoDatabase database = mongoClient.getDatabase(tenantId);
		MongoCollection<Document> collection = database.getCollection("second_coll");
		collection.insertOne(second_coll_doc);
1 Like
8

I have to revoke my request to close the ticket. After all I am not sure if this is related to Percona.

Could you please check if listDatabase is called by “Percona code” ? (Mainly because SHARDING is not part of the original MongoDB code).

image
image1852×273 142 KB

1 Like
9

Hello @jamoser
Percona code does not call listDatabase.
That SHARDING message with id = 21950 is part of original MongoDB code. Here is v4.4 source: https://github.com/mongodb/mongo/blob/v4.4/src/mongo/db/s/database_sharding_state.cpp#L123-L127
But that message was removed in v5.0 so I guess your log snippet is from v4.4 or probably v4.2.

2 Likes
10

but I’m thinking we can fix it in Percona Server for MongoDB itself.

Ok - the Mongodb guys are a little bit helpless

→ if you guys could pick up this issue, that would be great !

Thanks & Regards
John

1 Like
11

@jamoser do you see the same behavior in 5.0?

1 Like
12

@Sergey_Pronin yes - and according to MongoDB, they say the slow execution of listdatabases() is fixed in version 5.2

1 Like
13

Are you talking about https://jira.mongodb.org/browse/SERVER-57357 or something else?

1 Like
14

@Igor_Solodovnikov … well that is what they claim.

1 Like
15

I am little bit stuck here - the mongodb team wants me to send the data from the diagnostic.data folder

bash-4.4$
bash-4.4$ ls diagnostic.data/
metrics.2022-02-22T23-51-01Z-00000 metrics.2022-02-26T02-56-01Z-00000 metrics.2022-03-01T06-49-10Z-00000 …

is there something related to Percona ?

1 Like
16

And again could you check on your side, if you call listDatabases() during the creation of the first collection of a newly created database ?

(PS: if someone can show me where to look for in the git repo, I could dig through the code myself)

1 Like
17

Percona code has no additional calls to listDatabases(). So all listDatabases() calls are inherited from upstream.

2 Likes
18

I think diagnostic.data folder is equivalent in PSMDB and in upstream MongoDB.

2 Likes
19

I’ve installed Install MongoDB Community Kubernetes Operator | MongoDB with MongoDB Version 4.4.6 on the same GKE env and the issue is not existent.

So the issue of the topic is related to Percona. Could you pls fix this issue.

1 Like
20

@Igor_Solodovnikov I think this is wrong and I am happy to prove that to you.

1 Like