[root@birbank-mongodb02 ~]# mongostat
insert query update delete getmore command dirty used flushes vsize res qrw arw net_in net_out conn set repl time
*22 149 *228 *0 0 261|0 0.7% 81.2% 0 35.3G 21.4G 0|0 11|0 179k 1.44m 665 birbankrs SEC Sep 12 21:02:51.274
*43 106 *166 *0 0 214|0 0.7% 84.7% 0 35.3G 21.4G 0|0 8|0 139k 1.68m 665 birbankrs SEC Sep 12 21:02:52.277
*130 253 *327 *0 0 242|0 0.7% 81.8% 0 35.3G 21.4G 0|0 12|0 194k 10.1m 666 birbankrs SEC Sep 12 21:02:53.275
*38 156 *264 *0 0 217|0 0.8% 80.8% 0 35.3G 21.4G 0|0 11|0 161k 1.69m 668 birbankrs SEC Sep 12 21:02:54.276
*7 125 *240 *0 0 204|0 0.8% 80.5% 0 35.3G 21.4G 0|0 11|0 147k 581k 670 birbankrs SEC Sep 12 21:02:55.275
*2 123 *183 *0 0 190|0 0.8% 81.4% 0 35.3G 21.4G 0|0 12|0 137k 481k 671 birbankrs SEC Sep 12 21:02:56.276
Queries or Explains? You mention slow queries in logs but dont show any.
{
type: 'op',
host: 'mongoserver.com:27017',
desc: 'conn207308',
connectionId: 207308,
client: 'client_ip:49188',
clientMetadata: {
driver: {
name: 'mongo-java-driver|sync|spring-boot',
version: '4.8.2'
},
os: {
type: 'Linux',
name: 'Linux',
architecture: 'amd64',
version: '4.18.0-305.el8.x86_64'
},
platform: 'Java/Eclipse Adoptium/17.0.5+8'
},
active: true,
currentOpTime: '2023-09-12T21:42:59.983+04:00',
threaded: true,
opid: -1623456351,
secs_running: Long("9"),
microsecs_running: Long("9807260"),
op: 'command',
ns: 'admin.$cmd',
command: {
hello: 1,
helloOk: true,
topologyVersion: {
processId: ObjectId("64de9980542caf5a1f6d18be"),
counter: Long("3")
},
maxAwaitTimeMS: Long("10000"),
'$db': 'admin'
},
numYields: 0,
waitingForLatch: {
timestamp: ISODate("2023-09-12T17:42:50.276Z"),
captureName: 'AnonymousLockable'
},
locks: {},
waitingForLock: false,
lockStats: {},
waitingForFlowControl: false,
flowControlStats: {}
},
{
"t": {
"$date": "2023-09-12T21:45:53.358+04:00"
},
"s": "I",
"c": "COMMAND",
"id": 51803,
"ctx": "conn526866",
"msg": "Slow query",
"attr": {
"type": "command",
"ns": "mb_front_prod.notifications",
"command": {
"count": "notifications",
"query": {
"subscribers": "34EC52260C77403B992C62E8C3725E05",
"state": 2,
"action.read": {
"$nin": [
"34EC52260C77403B992C62E8C3725E05"
]
},
"action.delete": {
"$nin": [
"34EC52260C77403B992C62E8C3725E05"
]
},
"type": {
"$nin": [
"TRANSACTION"
]
}
},
"lsid": {
"id": {
"$uuid": "2f2b831f-8867-4530-8e07-3df1ea0693e3"
}
},
"$clusterTime": {
"clusterTime": {
"$timestamp": {
"t": 1694540751,
"i": 38
}
},
"signature": {
"hash": {
"$binary": {
"base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=",
"subType": "0"
}
},
"keyId": 0
}
},
"$db": "mb_front_prod",
"$readPreference": {
"mode": "secondaryPreferred"
}
},
"planSummary": "IXSCAN { subscribers: 1, state: 1 }",
"keysExamined": 3280,
"docsExamined": 3280,
"fromMultiPlanner": true,
"replanned": true,
"replanReason": "cached plan was less efficient than expected: expected trial execution to take 156 works but it took at least 1560 works",
"numYields": 115,
"queryHash": "8798D071",
"planCacheKey": "B688F8B7",
"reslen": 170,
"locks": {
"FeatureCompatibilityVersion": {
"acquireCount": {
"r": 116
}
},
"Global": {
"acquireCount": {
"r": 116
}
},
"Mutex": {
"acquireCount": {
"r": 1
}
}
},
"readConcern": {
"level": "local",
"provenance": "implicitDefault"
},
"storage": {
"data": {
"bytesRead": 205471880,
"timeReadingMicros": 1039721
}
},
"remote": "remote_ip:2772",
"protocol": "op_msg",
"durationMillis": 1334
}
}
You are using the $nin operator, which is known not to be very selective. You can see the IXSCAN is matching a large number of documents, possibly because of this. Is there another way you can write the query to be more selective? See https://www.mongodb.com/docs/manual/core/query-optimization/#query-selectivity
This problem was solved. We got queries which worked slowly. The developer indexed them.
This topic was automatically closed 5 days after the last reply. New replies are no longer allowed.