For some unknown reason, mongoose
is querying my secondary MongoDB server, and I can't figure out how to change that.
I've set db.setProfilingLevel(2)
on my secondary server, and I see a lot of queries there for no reason.
When I view the records, I see:
"command" : {
"$readPreference" : {
"mode" : "secondaryPreferred"
}
}
Which is odd because according to the documentation, the default read preference should be primary
.
When I run db.getMongo().getReadPref()
I see that indeed that's the case:
ReadPreference {
mode: 'primary',
tags: undefined,
hedge: undefined,
maxStalenessSeconds: undefined,
minWireVersion: undefined
}
I also tried adding {readPreference: 'primary'}
to my mongoose
connection, but the issue remains the same.
Any suggestions where the secondaryPreferred
setting might be coming from?
(I am not sure if my issue is with mongoose
or MongoDB, so I've tagged them both)
Update
A full entry from the profiler on the SECONDARY server:
{
"op" : "query",
"ns" : "***",
"command" : {
"find" : "***",
"batchSize" : 1,
"singleBatch" : true,
"maxTimeMS" : 1000,
"$readPreference" : {
"mode" : "secondaryPreferred"
},
"readConcern" : {
"level" : "local"
},
"$db" : "***"
},
"keysExamined" : 0,
"docsExamined" : 1,
"cursorExhausted" : true,
"numYield" : 0,
"nreturned" : 1,
"queryHash" : "17830885",
"queryExecutionEngine" : "classic",
"locks" : {
"FeatureCompatibilityVersion" : {
"acquireCount" : {
"r" : NumberLong(1)
}
},
"Global" : {
"acquireCount" : {
"r" : NumberLong(1)
}
},
"Mutex" : {
"acquireCount" : {
"r" : NumberLong(1)
}
}
},
"flowControl" : {},
"readConcern" : {
"level" : "local",
"provenance" : "clientSupplied"
},
"responseLength" : 0,
"protocol" : "op_msg",
"millis" : 0,
"planSummary" : "COLLSCAN",
"execStats" : {
"stage" : "COLLSCAN",
"nReturned" : 1,
"executionTimeMillisEstimate" : 0,
"works" : 2,
"advanced" : 1,
"needTime" : 1,
"needYield" : 0,
"saveState" : 0,
"restoreState" : 0,
"isEOF" : 0,
"direction" : "forward",
"docsExamined" : 1
},
"ts" : ISODate("2022-10-01T19:00:03.842 07:00"),
"client" : "***", //IP address of the PRIMARY server
"allUsers" : [],
"user" : ""
}
Update 2
I can't replicate the issue on dev environment, so I'm guessing it's not a mongoose issue but something related to the servers setup.
Update 3
When looking at the profiler log again, I noticed that the client is the PRIMARY server IP, and not the app server.
CodePudding user response:
Update 3 When looking at the profiler log again, I noticed that the client is the PRIMARY server IP, and not the app server.
This is super helpful information and what I was attempting to ask about in my comment.
Based on this, I suspect what is happening here is that this profiler entry is associated with a Mirrored Read. Borrowing some from the documentation:
Mirrored reads reduce the impact of primary elections following an outage or planned maintenance. After a failover in a replica set, the secondary that takes over as the new primary updates its cache as new queries come in. While the cache is warming up performance can be impacted.
Starting in version 4.4, mirrored reads pre-warm the caches of electable secondary replica set members. To pre-warm the caches of electable secondaries, the primary mirrors a sample of the supported operations it receives to electable secondaries.
One way to quickly prove or disprove this hypothesis would be to disable mirrored reads in the production environment. Instructions for doing so can be found here and it involves setting the samplingRate
to 0.0
.
Overall what you are observing is probably expected behavior. It has only become visible because you are inspecting the profiler that includes all operations and therefore is not something to be concerned about. It sounds like the application itself is configured appropriately and using the primary
read preference as designed.