[SERVER-10710] No new connections accepted under heavy load Created: 08/Sep/13  Updated: 02/Mar/15  Resolved: 02/Mar/15

Status: Closed
Project: Core Server
Component/s: Networking
Affects Version/s: 1.8.2, 2.4.6
Fix Version/s: None

Type: Bug Priority: Critical - P2
Reporter: Steve Sperandeo Assignee: Ramon Fernandez Marina
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Ubuntu 10.04.2 LTS 64 bit running on Xen(linode) - Linux 2.6.39.1 x86_64 - 1GB RAM - 8 Cores of Intel(R) Xeon(R) CPU E5-2670 0 @ 2.60GHz - 512MB Swap (also tried an 8GB RAM linode variant)


Issue Links:
Related
related to SERVER-17140 ReplExecNetThread, errno:99 Cannot as... Closed
Operating System: Linux
Steps To Reproduce:

The steps to reproduce (and the fix) are located at: http://stackoverflow.com/questions/18664166/why-is-mongodb-unresponsive-during-a-load-test

Participants:

 Description   

The steps to reproduce (and the fix) are located at: http://stackoverflow.com/questions/18664166/why-is-mongodb-unresponsive-during-a-load-test

However, I believe this fix is a kernel workaround and that the actual error is in the Mongo network stack. Can you please either confirm or deny this statement.

Thx



 Comments   
Comment by Ramon Fernandez Marina [ 02/Mar/15 ]

ssperandeo, we haven't heard back from you for a while so I'm resolving this ticket.

In addition to the information posted above, users writing load tests may be interested in connection pooling (see documentation for PyMongo, which was mentioned in this ticket.

Regards,
Ramón.

Comment by Ramon Fernandez Marina [ 23/Jan/15 ]

Apologies if I missed some information here, I'm trying to understand how mongod is involved in all this since typically it is clients that put sockets in TIMED_WAIT, not servers like mongod.

Is there a chance you may be able to upload full logs for an affected mongod from the production system you mention? I hope that will help us investigate the problem further.

Thanks,
Ramón.

Comment by Steve Sperandeo [ 23/Jan/15 ]

As I had mentioned previously, this was an issue that affected our production systems (ie. no local load test client). Also, I've reproduced it with a remote load test client (also previously mentioned).

Again, you didn't read the comments before trying to sweep this under the rug. Why is this such an issue? This could have been easily addressed in under a week. This thread is coming up to 1.5 years old.

The only "help" that I've received from your team has been defensiveness. I'm trying to better your software. Just close the ticket. It doesn't look like you want to fix it anyways.

Comment by Ramon Fernandez Marina [ 23/Jan/15 ]

ssperandeo, I don't think it's fair to claim mongod is not able to accept new connections when there's other processes hoarding machine resources that mongod needs, in this case available sockets.

Are you able to reproduce this problem when your load tester is not in the same machine as the one where mongod is running?

Comment by Steve Sperandeo [ 29/Oct/14 ]

Also, I had already stated, in the StackOverflow post, how to reproduce this. Did you read that post before trying to reproduce this?

Comment by Steve Sperandeo [ 29/Oct/14 ]

I must say, I'm pretty surprised that MongoDB is sweeping this under the rug. It's almost like you haven't done any robust load testing because this was pretty easy to reproduce. Also, this isn't an edge case. I actually encountered this in production and used load testing to identify it.

You don't need to set SO_LINGER to 0. You can set it to a middle ground, like 10-20s (or better yet, make it configurable). The default is 120s.

This is not a thread saturation error. It's an open files saturation error. So, by default, if you use more sockets within a two minute period than is available to mongo, it will fail to connect because it can't open a socket. Setting the SO_LINGER to 10s will allow 12X more connections while still allowing a generous margin of safety.

So, given the above threshold of 47000 available sockets, I'd have to hit 47000 connections within a 10s period compared to 47000 in a 120s period. 47000 connections within a 10s is a pretty high threshold, but 47000 connections within a 120s period is reachable at high load.

To illustrate, you can just set your local ip port range to something really low:

sysctl net.ipv4.ip_local_port_range="18000 18005"

The default for this range is 28k. So, at 28k/120s, that means that Mongo will fail to accept new connections at a sustained connection rate of 235 connections per second (or greater) for a period of 120s.

You can reproduce this, as I did, by calling the system remotely with loader.io. The connections to mongo are local, but the load comes from an external box.

Comment by Ramon Fernandez Marina [ 29/Oct/14 ]

ssperandeo, my reading of this ticket is that there are two separate issues:

  • The number of sockets in TIME_WAIT
  • The "couldn't connect to server" error message

If the load test above is launching too many short-lived connections, it may at some point exhaust the available numbers of TCP sockets. However, when this happens the error looks (in 2.6.5) as follows:

2014-10-29T15:11:50.187-0400 warning: Failed to connect to x.x.x.x:27017, reason: errno:99 Cannot assign requested address
2014-10-29T15:11:50.188-0400 Error: couldn't connect to server foo:27017 (x.x.x.x), connection attempt failed at src/mongo/shell/mongo.js:148

The way I'm able to trigger the "couldn't connect to server" error is when the running mongod can no longer create any threads:

2014-10-29T14:51:23.211-0400 [initandlisten] connection accepted from y.y.y.y:43516 #88614 (2031 connections now open)
2014-10-29T14:51:23.211-0400 [initandlisten] can't create new thread, closing connection

I therefore think using the SO_LINGER option is not the solution for this issue – having client sockets sit in TIME_WAIT is a "good thing", and setting SO_LINGER to 0 may cause unexpected behavior down the road.

As for the "couldn't connect to server" error message, if you're still seeing it you may need to increase the resources available to mongod if you really need all those simultaneous connections. If you want to re-try your load test I'd recommend you run it in a different machine than the mongod server, and then share server logs to see how many connections can mongod handle.

Since this analysis doesn't point to a bug in the server I'm going to close this ticket, as the SERVER project is for reporting bugs or feature suggestions in MongoDB. For MongoDB-related support discussion, including configuration and resource limits questions, please post on the mongodb-user group or Stack Overflow with the mongodb tag, where your question will reach a larger audience.

Regards,
Ramón.

Comment by Steve Sperandeo [ 09/Sep/13 ]

Perhaps I was wrong then. It must have been a coincidence.

Anyways, netstat indeed shows what you suspected, 28237 connections in TIME_WAIT at the moment of lock out (versus 2 connections in TIME_WAIT before/after the test).

netstat -an | grep TIME_WAIT | wc -l

Setting this option:
sysctl net.ipv4.ip_local_port_range="18000 65535"
only makes the server fail later, at 47000 connections in TIME_WAIT.

So I guess you could change the SO_LINGER to a lower TIME_WAIT timeout with setsockopt:
http://stackoverflow.com/a/13088864/278976

http://alas.matf.bg.ac.rs/manuals/lspe/snode=105.html

Comment by Eliot Horowitz (Inactive) [ 08/Sep/13 ]

One thing I just tried to repo:

100 instances of a script doing

while 1
mongo --eval "printjson( db.foo.findOne() )"
end

Has been running for 10 minutes, will let it keep going and then up to 1000 instances.

Comment by Eliot Horowitz (Inactive) [ 08/Sep/13 ]

Steve,

Sorry you feel that way.

Not sure why you think I'm downvoting you. There is no "voting" in jira, I'm just trying to understand what is happening.

Can you try looking at netstat after/during the test?
No matter where the issue is, it will help isolate.

Comment by Steve Sperandeo [ 08/Sep/13 ]

So let me see if I get this straight. I help you by documenting (and isolating) the cause of a major bug. You respond by downvoting my post and then wildly throwing out assumptions that, "This usually indicates the client side isn't fully closing the socket".

TCP doesn't work that way. After both FIN/ACK exchanges are concluded, the side which sent the first FIN before receiving one waits for a timeout before finally closing the connection, during which time the local port is unavailable for new connections; this prevents confusion due to delayed packets being delivered during subsequent connections.

And seeing as we're using PyMongo, it would have been your client that hadn't disconnected. Which, is probably not the case anyways. The python driver is probably working perfectly fine. This is just how TCP works normally.

The really sad part here is that you're trying to defend yourself against someone who was trying to help. No more. I'm not interested in cooperating with you.

Comment by Eliot Horowitz (Inactive) [ 08/Sep/13 ]

There aren't downvotes here, just trying to understand.

We do many similar load tests, so wouldn't really have anything to try to repro without more information.

Usually when that kernel flag helps its because of a lot of connections in time wait.

When you can't connect to mongo, try running "netstan -an | grep 27017"
My assumption is that you'll see lots of connections in TIME_WAIT.

This usually indicates the client side isn't fully closing the socket.

Comment by Steve Sperandeo [ 08/Sep/13 ]

The load test code is proprietary, closed source. Why the downvotes? I invested time documenting this issue so that you'd be able to reproduce the error and ultimately improve your product. Not impressed.

Comment by Eliot Horowitz (Inactive) [ 08/Sep/13 ]

I'm not sure about that. Can you send the code you are using to do the load test?

Generated at Thu Feb 08 03:23:51 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.