Multiplanner and 5.0.13 replicaset - primary planner sendind query plan candidate to secondary?

Ops and Admin Replication
,
1

Hello everyone,

I have a 5.0.13 replicaset (community edition) with one primary / 2 secondaries, all client are using pymongo 4.1.1 and connect to the replicaset with readPreference “primaryPreferred”

now I see quite a lot of log on the secondaries node log file looking like this (I scrubbed the find query for sensibility reason)

{"t":{"$date":"2022-11-07T09:15:54.907+01:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn43774","msg":"Slow query","attr":{"type":"command","ns":"XXXX","command":{"find":"XXXXX","filter":{XXXXX},"sort":{XXXXX},"limit":1,"batchSize":1,"singleBatch":true,"maxTimeMS":1000,"$readPreference":{"mode":"secondaryPreferred"},"readConcern":{"level":"local"},"$db":"sief"},"numYields":66,"queryHash":"16E6F9A1","planCacheKey":"DC1D7D78","ok":0,"errMsg":"error while multiplanner was selecting best plan :: caused by :: operation exceeded time limit","errName":"MaxTimeMSExpired","errCode":50,"locks":{"FeatureCompatibilityVersion":{"acquireCount":{"r":67}},"Global":{"acquireCount":{"r":67}},"Mutex":{"acquireCount":{"r":1}}},"readConcern":{"level":"local","provenance":"clientSupplied"},"remote":"IP_OF_PRIMARY:34400","protocol":"op_msg","durationMillis":1000}}

so it seems to me that the PRIMARY node (“remote” in logs above) is sending queries to the secondaries during the “query plan selection” phase, with “secondaryPreferred” readPReference. I am understanding this correctly ? I do not see anything in the documentation about it https://www.mongodb.com/docs/manual/core/query-plans/. If yes is there a configuration option to increase the “maxTimeMS” parameter (1000ms is too low) or to disable this feature and have all query plan candidates run on the primary ?

Thank you for you help !
Olivier

2

Hi @Olivier_Le_Rigoleur welcome to the community!

I think the query’s originator is something marked conn43774 from the log line above. To see what connection is named as conn43774, you might be able to search for that string.

For example, if I’m looking for conn10, I would see this log line:

{"t":{"$date":"2022-11-08T16:47:19.858+11:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn10","msg":"client metadata","attr":{"remote":"127.0.0.1:49995","client":"conn10","doc":{"driver":{"name":"nodejs|mongosh","version":"4.10.0"},"os":{"type":"Darwin","name":"darwin","architecture":"x64","version":"20.6.0"},"platform":"Node.js v16.18.0, LE (unified)","version":"4.10.0|1.6.0","application":{"name":"mongosh 1.6.0"}}}}

which shows what client and what IP it’s connecting from.

disable this feature and have all query plan candidates run on the primary ?

Do you mean to run all queries in the primary? Have you tried changing the readPreference of the application from primaryPreferred to primary instead (the default)? You might also want to double check that no application is accidentally using secondaryPreferred read preference.

Best regards
Kevin