[SERVER-51835] Mongos readPreferenceTags are not working as expected Created: 26/Oct/20  Updated: 29/Oct/23  Resolved: 28/Feb/23

Status: Closed
Project: Core Server
Component/s: Internal Client, Internal Code
Affects Version/s: 4.4.0
Fix Version/s: 7.0.0-rc0, 4.4.20, 5.0.16, 6.0.6, 6.3.0-rc2

Type: Bug Priority: Major - P3
Reporter: Andres P Assignee: Max Hirschhorn
Resolution: Fixed Votes: 2
Labels: sa-groomed
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: PNG File mongo.png     File read_pref_with_tag_order.js    
Issue Links:
Backports
Related
related to DRIVERS-2563 Add spec test which checks that the o... Backlog
is related to SERVER-41910 Make RSM::getMatchingHosts return mul... Closed
Assigned Teams:
Sharding NYC
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Requested:
v6.3, v6.0, v5.0, v4.4
Steps To Reproduce:

Reproduce from mongo shell:

1. db.getMongo().setReadPref('nearest', [ { "something": "x", "region": "a" } ])
2. db.getMongo().setReadPref('nearest', [ { "something": "x", "region": "a" }, {"something": "x"} ])

db.getCollection('mytest').find({ _id: ObjectId("my-object-id") });

Get expected results with 1. option. While using 2. setting, I can see that query is executed in random node matching second tag.
Works as expected (as documentation says) with MongoDB version 4.2 but not starting with 4.4

Sprint: Sharding NYC 2023-03-06
Participants:
Case:

 Description   

From documentation:

Order matters when using multiple readPreferenceTags. The readPreferenceTags are tried in order until a match is found. Once found, that specification is used to find all eligible matching members and any remaining readPreferenceTags are ignored.

This isn't true in 4.4 anymore when using multiple readPreferenceTags as a fallback. 

Seems part of code location has shifted and that is the reason that readPreferenceTags behavior has changed. Or there could be other major changes with the code how matching is done regard with tags.

In 4.4 >

https://github.com/mongodb/mongo/blob/v4.4/src/mongo/client/scanning_replica_set_monitor.cpp#L1236-L1250 
In 4.2 >
https://github.com/mongodb/mongo/blob/v4.2/src/mongo/client/replica_set_monitor.cpp#L1149 



 Comments   
Comment by Githook User [ 16/Mar/23 ]

Author:

{'name': 'Max Hirschhorn', 'email': 'max.hirschhorn@mongodb.com', 'username': 'visemet'}

Message: SERVER-51835 Respect preference order in read preference tag set list.

Fixes the streamable and sdam replica set monitors to obey the
documented preference order for matching against multiple tag sets.
In particular, once a match is found, that tag set is used to find all
eligible matching server members, and the remaining tag sets are
ignored.

(cherry picked from commit 7b5b262e93af9fd3773cc842816a3517ced81e09)
Branch: v6.3
https://github.com/mongodb/mongo/commit/46bb04d7fdba4e4213534809973027d44029f05d

Comment by Githook User [ 15/Mar/23 ]

Author:

{'name': 'Max Hirschhorn', 'email': 'max.hirschhorn@mongodb.com', 'username': 'visemet'}

Message: SERVER-51835 Respect preference order in read preference tag set list.

Fixes the streamable and sdam replica set monitors to obey the
documented preference order for matching against multiple tag sets.
In particular, once a match is found, that tag set is used to find all
eligible matching server members, and the remaining tag sets are
ignored.

(cherry picked from commit 7b5b262e93af9fd3773cc842816a3517ced81e09)
Branch: v6.0
https://github.com/mongodb/mongo/commit/4899b659d44c1cf7c7d672ad2b6496f082b3631c

Comment by Githook User [ 01/Mar/23 ]

Author:

{'name': 'Max Hirschhorn', 'email': 'max.hirschhorn@mongodb.com', 'username': 'visemet'}

Message: SERVER-51835 Respect preference order in read preference tag set list.

Fixes the streamable and sdam replica set monitors to obey the
documented preference order for matching against multiple tag sets.
In particular, once a match is found, that tag set is used to find all
eligible matching server members, and the remaining tag sets are
ignored.

(cherry picked from commit 7b5b262e93af9fd3773cc842816a3517ced81e09)
Branch: v5.0
https://github.com/mongodb/mongo/commit/99847ed785e558074ccce242b65068f393e6e3b8

Comment by Githook User [ 01/Mar/23 ]

Author:

{'name': 'Max Hirschhorn', 'email': 'max.hirschhorn@mongodb.com', 'username': 'visemet'}

Message: SERVER-51835 Respect preference order in read preference tag set list.

Fixes the streamable and sdam replica set monitors to obey the
documented preference order for matching against multiple tag sets.
In particular, once a match is found, that tag set is used to find all
eligible matching server members, and the remaining tag sets are
ignored.

(cherry picked from commit 7b5b262e93af9fd3773cc842816a3517ced81e09)
Branch: v4.4
https://github.com/mongodb/mongo/commit/f15b19b907fee13fcd6f1a8b75bebf0ac1e7ae3f

Comment by Max Hirschhorn [ 28/Feb/23 ]

Many thanks for the patience regarding this ticket. It definitely sat for longer on the backlog than it ought to have. I wanted to take a moment to summarize the state across all release branches and what my plan for backporting the changes to older branches is.

  • In MongoDB 4.4, the replica set monitor was entirely rewritten to achieve two things (i) make use of the new streamable hello which minimizes the time to detect topology changes and (ii) ensure adherence to the MongoDB driver specifications for Server Discovery and Monitoring. Note that the C++ implementation of the replica set monitor is shared by both mongos and the legacy mongo shell. The new version of the replica set monitor—also known as the streamable RSM (--setParameter replicaSetMonitorProtocol=streamable)—was effectively treating any host which matched any of the read preference tag sets as being an eligible, contrary to the documented preference order.
  • The old version of the replica set monitor—also known as the scanning RSM (--setParameter replicaSetMonitorProtocol=scanning)—remained in the MongoDB 4.4 and 5.0 codebases. It was removed in MongoDB 6.0 (SERVER-62079).
  • By coincidence, also in MongoDB 4.4, the scanning RSM regressed in exactly the same way around multiple read preference tags as a result of SERVER-41910. This led to a situation where in MongoDB 4.4+ neither the on-by-default streamable RSM nor the old scanning RSM followed the documented preference order for multiple read preference tag sets.

We haven't found the scanning RSM to be needed as a workaround and have been satisfied by the relative stability of the streamable RSM. This is why the scanning RSM (--setParameter replicaSetMonitorProtocol=scanning) option has since been removed. And so after discussing with the Product team the plan is to -

  1. Fix the new streamble RSM on the MongoDB 4.4, 5.0, 6.0, and 6.3 branches. The changes will land in an upcoming patch release for these versions.
  2. Leave the old scanning RSM as-is on the MongoDB 4.4 and 5.0 branches expecting the regression introduced by SERVER-41910 won't impact applications because --setParameter replicaSetMonitorProtocol=scanning isn't being used. If we learn of cases where --setParameter replicaSetMonitorProtocol=scanning is being used then we'll reassess and also prioritize other improvements to the streamable RSM to fully supplant the scanning RSM.
Comment by Githook User [ 27/Feb/23 ]

Author:

{'name': 'Max Hirschhorn', 'email': 'max.hirschhorn@mongodb.com', 'username': 'visemet'}

Message: SERVER-51835 Respect preference order in read preference tag set list.

Fixes the streamable and sdam replica set monitors to obey the
documented preference order for matching against multiple tag sets.
In particular, once a match is found, that tag set is used to find all
eligible matching server members, and the remaining tag sets are
ignored.
Branch: master
https://github.com/mongodb/mongo/commit/7b5b262e93af9fd3773cc842816a3517ced81e09

Comment by Edwin Zhou [ 27/Oct/20 ]

Hi andres.pihlak@heathmont.net,

Thank you for your detailed description of your problem and your reproduction steps. I was able to reproduce your issue on a 2 node replica set. I'll These steps were taken in the mongo shell.

Reproduction

  1. Insert documents to be queried for later

    db = db.getSiblingDB("test")
    db.col.insertMany({ a: 1 }, { a: 2 })
    

  2. Add tags to each node in the replica set

    conf = rs.conf()
    conf.members[0].tags = { tag1: "a", tag2: "b" }
    conf.members[1].tags = { tag1: "a", tag2: "c" }
    rs.reconfig(conf)
    

  3. Set COMMAND log verbosity to 1

    > mongo --port 27017
    db.setLogLevel(1, "command")
    > mongo --port 27018
    db.setLogLevel(1, "command")
    

  4. Tail the logs for both nodes in the replica set filtering for "nearest" using tail -f <your log directory> | grep nearest

Connecting to the replica set, I tested your issue on both 4.4 and 4.2.

This command correctly executes a query on node_01 for both 4.4.0 and 4.2.0:

db.col.find({a:1}).readPref("nearest", [{ tag1: "a", tag2: "b" }])

 

This command correctly executes a query on node_02 for both 4.4.0 and 4.2.0

db.col.find({a:1}).readPref("nearest", [{ tag1: "a", tag2: "c" }])

 

This command incorrectly executes a query on node_02 for 4.4.0 but correctly executes a query on node_01 for 4.2.0

db.col.find({a:1}).readPref("nearest", [{ tag1: "a", tag2: "b" }, { tag1: "a", tag2: "c" }]) 

 

This command correctly executes a query on node_02 for both 4.4.0 and 4.2.0

db.col.find({a:1}).readPref("nearest", [{ tag1: "a", tag2: "c" }, { tag1: "a", tag2: "b" }]) 


The queries are seen executed in these logs, note the $readPreference:

4.4.0
node_01

{"t":{"$date":"2020-10-27T17:26:30.909-04:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn19","msg":"Slow query","attr":{"type":"command","ns":"test.col","appName":"MongoDB Shell","command":{"find":"col","filter":{"a":1.0},"lsid":{"id":{"$uuid":"27e6a932-3847-4823-a14a-783e751afa93"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1603833981,"i":1}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$readPreference":{"mode":"nearest","tags":[{"tag1":"a","tag2":"b"}]},"$db":"test"},"planSummary":"COLLSCAN","keysExamined":0,"docsExamined":2,"cursorExhausted":true,"numYields":0,"nreturned":1,"queryHash":"4B53BE76","planCacheKey":"4B53BE76","reslen":258,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{"data":{"bytesRead":112,"timeReadingMicros":17}},"protocol":"op_msg","durationMillis":0}}

node_02

{"t":{"$date":"2020-10-27T17:26:38.718-04:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn20","msg":"Slow query","attr":{"type":"command","ns":"test.col","appName":"MongoDB Shell","command":{"find":"col","filter":{"a":1.0},"lsid":{"id":{"$uuid":"27e6a932-3847-4823-a14a-783e751afa93"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1603833981,"i":1}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$readPreference":{"mode":"nearest","tags":[{"tag1":"a","tag2":"c"}]},"$db":"test"},"planSummary":"COLLSCAN","keysExamined":0,"docsExamined":2,"cursorExhausted":true,"numYields":0,"nreturned":1,"queryHash":"4B53BE76","planCacheKey":"4B53BE76","reslen":258,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{"data":{"bytesRead":112,"timeReadingMicros":17}},"protocol":"op_msg","durationMillis":0}}
{"t":{"$date":"2020-10-27T17:26:45.603-04:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn21","msg":"Slow query","attr":{"type":"command","ns":"test.col","appName":"MongoDB Shell","command":{"find":"col","filter":{"a":1.0},"lsid":{"id":{"$uuid":"27e6a932-3847-4823-a14a-783e751afa93"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1603833991,"i":1}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$readPreference":{"mode":"nearest","tags":[{"tag1":"a","tag2":"b"},{"tag1":"a","tag2":"c"}]},"$db":"test"},"planSummary":"COLLSCAN","keysExamined":0,"docsExamined":2,"cursorExhausted":true,"numYields":0,"nreturned":1,"queryHash":"4B53BE76","planCacheKey":"4B53BE76","reslen":258,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_msg","durationMillis":0}}
{"t":{"$date":"2020-10-27T17:26:53.510-04:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn22","msg":"Slow query","attr":{"type":"command","ns":"test.col","appName":"MongoDB Shell","command":{"find":"col","filter":{"a":1.0},"lsid":{"id":{"$uuid":"27e6a932-3847-4823-a14a-783e751afa93"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1603834001,"i":1}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$readPreference":{"mode":"nearest","tags":[{"tag1":"a","tag2":"c"},{"tag1":"a","tag2":"b"}]},"$db":"test"},"planSummary":"COLLSCAN","keysExamined":0,"docsExamined":2,"cursorExhausted":true,"numYields":0,"nreturned":1,"queryHash":"4B53BE76","planCacheKey":"4B53BE76","reslen":258,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_msg","durationMillis":0}}

4.2.0
node_01

2020-10-27T17:20:42.189-0400 I  COMMAND  [conn20] command test.col appName: "MongoDB Shell" command: find { find: "col", filter: { a: 1.0 }, lsid: { id: UUID("c61a5889-700c-4a9d-aa4e-ddf3242565b4") }, $clusterTime: { clusterTime: Timestamp(1603833632, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $readPreference: { mode: "nearest", tags: [ { tag1: "a", tag2: "b" } ] }, $db: "test" } planSummary: COLLSCAN keysExamined:0 docsExamined:2 cursorExhausted:1 numYields:0 nreturned:1 queryHash:4B53BE76 planCacheKey:4B53BE76 reslen:258 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 0ms
2020-10-27T17:23:18.082-0400 I  COMMAND  [conn20] command test.col appName: "MongoDB Shell" command: find { find: "col", filter: { a: 1.0 }, lsid: { id: UUID("c61a5889-700c-4a9d-aa4e-ddf3242565b4") }, $clusterTime: { clusterTime: Timestamp(1603833767, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $readPreference: { mode: "nearest", tags: [ { tag1: "a", tag2: "b" }, { tag1: "a", tag2: "c" } ] }, $db: "test" } planSummary: COLLSCAN keysExamined:0 docsExamined:2 cursorExhausted:1 numYields:0 nreturned:1 queryHash:4B53BE76 planCacheKey:4B53BE76 reslen:258 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 0ms

node_02

2020-10-27T17:22:52.994-0400 I  COMMAND  [conn28] command test.col command: find { find: "col", filter: { a: 1.0 }, lsid: { id: UUID("c61a5889-700c-4a9d-aa4e-ddf3242565b4") }, $clusterTime: { clusterTime: Timestamp(1603833632, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $readPreference: { mode: "nearest", tags: [ { tag1: "a", tag2: "c" } ] }, $db: "test" } planSummary: COLLSCAN keysExamined:0 docsExamined:2 cursorExhausted:1 numYields:0 nreturned:1 queryHash:4B53BE76 planCacheKey:4B53BE76 reslen:258 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 0ms
2020-10-27T17:23:44.229-0400 I  COMMAND  [conn29] command test.col command: find { find: "col", filter: { a: 1.0 }, lsid: { id: UUID("c61a5889-700c-4a9d-aa4e-ddf3242565b4") }, $clusterTime: { clusterTime: Timestamp(1603833807, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $readPreference: { mode: "nearest", tags: [ { tag1: "a", tag2: "c" }, { tag1: "a", tag2: "b" } ] }, $db: "test" } planSummary: COLLSCAN keysExamined:0 docsExamined:2 cursorExhausted:1 numYields:0 nreturned:1 queryHash:4B53BE76 planCacheKey:4B53BE76 reslen:258 locks:{ ReplicationStateTransition: { acquireCount: { w: 1 } }, Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 0ms

 
Best,

Edwin

Comment by Andres P [ 27/Oct/20 ]

Clarify this problem occurred with Mongo Router.  To illustrate the sample infrastructure:

Generated at Thu Feb 08 05:26:34 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.