[SERVER-53853] Large buildup of mongos to mongod connections and low performance with secondaryPreferred reads Created: 16/Jan/21  Updated: 08/Jan/24  Resolved: 30/Oct/23

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: 4.2.0, 4.2.11
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Bruce Lucas (Inactive) Assignee: Amirsaman Memaripour
Resolution: Gone away Votes: 2
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: PNG File connection-pool.png     PNG File connections.png     PNG File conns.png     PNG File default-scheduling.png     PNG File mongos-targeting.png     PNG File odd.png     PNG File reactor-scheduling.png     PNG File single-target-command.png     File x-conns.tgz    
Issue Links:
Duplicate
is duplicated by SERVER-53899 TaskExecutor CPU fills up instantly Closed
Related
related to SERVER-54278 Add feature flag to disable Opportuni... Closed
Operating System: ALL
Steps To Reproduce:

Run this workload against a single-shard cluster

function repro() {
 
    nthreads = 500
    db.c.insert({_id: 0})
 
    threads = []
    for (var t=0; t<nthreads; t++) {
        thread = new Thread(function(t) {
            while (true)
                db.c.find({_id: 0}).readPref("secondaryPreferred").itcount()
        }, t)
        threads.push(thread)
        thread.start()
    }
    for (var t = 0; t < nthreads; t++)
        threads[t].join()
 
}

Sprint: Service Arch 2021-02-08, Service Arch 2021-02-22, Service Arch 2021-03-08, Service Arch 2021-03-22, Service Arch 2021-04-05, Service Arch 2021-04-19, Service Arch 2021-05-03
Participants:
Case:

 Description   

Test consists of 500 threads doing secondaryPreferred reads as fast as possible against a single shard cluster. In the chart below the queries before A are from the primary for reference, after A are secondaryPreferred.

  • As expected, there are 500 connections to mongos, so there are as many as 500 outstanding operations.
  • Before A when reading from the primary (node 0) connections from mongos to mongod build to about 300, and the pool totalInUse and mongod active connections metrics are at times in the hundreds, justifying the need for 300 connections.
  • But after A when doing secondary reads connections from mongos to mongod build steadily up to about 10 k connections, far more than the 500 possible outstanding operations. Most of those are considered "in use" by mongos, but very few are "active" in mongod.
  • After reaching about 10 k connections the mongos seems to reset and begin building connections again, either to the same or a different secondary.
  • Slow query logs from mongos record a large number of operations taking tens of milliseconds, but almost non on mongod. The latency metrics from mongod confirm that there is no performance bottleneck on mongod.
  • Query throughput after A when doing secondary reads is much less than the primary reads before A. This seems to get worse as the number of connections build, but the latency on mongod remains low, so this is probably not due to an issue on mongod with the number of connections, but rather some issue in mongos.


 Comments   
Comment by Matthew Tretin (Inactive) [ 23/Apr/21 ]

We believe this issue was addressed with https://jira.mongodb.org/browse/SERVER-54278. Thanks everyone! 

Comment by Bruce Lucas (Inactive) [ 20/Jan/21 ]

There's another report in SERVER-53899 that may be impacted by this issue.

Comment by Bruce Lucas (Inactive) [ 19/Jan/21 ]

This issue affects 4.2.0 and 4.2.11, but does not seem to affect 4.0.22 nor 4.4.3.

Comment by Bruce Lucas (Inactive) [ 17/Jan/21 ]

While doing some more experiments I found that this issue does not always occur - sometimes the secondary reads are evenly distributed between the secondaries and no buildup of connections occurs. I guess this is the expected behavior? However it seemed to reproduce reliably when running the above (both mongo client and single-shard cluster) all on a single desktop machine with 24 cpus.

Also noticed the following:

During the period A-B for example

  • As noted previously all queries are routed to secondary member 1, and a buildup of connections occurs on that node (although as mentioned above these connections were marked in-use on mongos but were not active on mongod, and there's no reason for 10 k connections to service at most 500 concurrent requests).
  • No connections are created to secondary member 2 nor are queries routed there, but nevertheless there is a high volume of ismaster commands on member 2, about one per query, which seems unusual to me.
Generated at Thu Feb 08 05:32:02 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.