[SERVER-26215] Initial sync fails due to false time out if index creation takes longer than X hours Created: 21/Sep/16 Updated: 08/Jan/24 Resolved: 05/May/17 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | Index Maintenance, Networking, Replication |
| Affects Version/s: | 3.2.9 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Matthieu Rigal | Assignee: | Mira Carey |
| Resolution: | Duplicate | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Issue Links: |
|
||||||||
| Backwards Compatibility: | Fully Compatible | ||||||||
| Operating System: | ALL | ||||||||
| Steps To Reproduce: | Create a collection big enough (several hundred millions of entries), enough indexes to keep the system busy for more than 3-4 hours and just run an initial sync, it will fail. |
||||||||
| Participants: | |||||||||
| Description |
|
Hi guys, We recently had to redo some sync of our replica sets. We could reproducibly find a way to make the initial sync fail. We have several collections to be synced. For our largest, the sync permanently failed after the index build of the largest collection. When it tries to get the indexes for the next collection, it fails permanently. We had to use rsync. Between normal size collections, it was working, but not for this big one. Also a later retry gave the same effect. As you will see from the very narrow timestamps, the error must lay in the network component. The previous call was probably older than the threshold set for this operation, and then instead of resetting the timeout when the process is really making the request, it takes the previous now very old timestamp and thus times out. Here is a part of the log
|
| Comments |
| Comment by Matthieu Rigal [ 05/May/17 ] | ||||
|
Hi @jason.carey Thanks for having pursued your investigations! We were a bit astonished that the issue was not tackled at all before, but better late than never. Regards, | ||||
| Comment by Mira Carey [ 04/May/17 ] | ||||
|
I believe that the behavior you saw was fixed in It is slated for release with 3.2.14. Or, if an upgrade is an option, Regards, | ||||
| Comment by Mira Carey [ 23/Mar/17 ] | ||||
|
After some staring, I think this may actually be a bug in the networking code (specific at this point to 3.2 and earlier). While I haven't dug into the actual repl side of this, the log lines in question don't make a lot of sense. All of our actual log lines for time outs should say:
instead of
And those functions should throw SocketException::SEND_TIMEOUT, instead of SEND_ERROR. From what I can tell, the cause is likely the sendmsg path in our Socket type. It's error handling for timeouts is different in the vectorized case than the non-vectorized case. Specifically:
instead of
Note that the second case specifically checks for EWOULDBLOCK, which is a valid return from a timeout generated by the SO_SNDTIMEO socket option. This doesn't matter in 3.4 and later, as that code path is no longer exercised (messages always use the single buffer version). So in this case, it's possible that most users see EAGAIN during initial sync timeouts for vectorized messages. Or that most users aren't generating vectorized messages during initial syncs (I haven't dug into which is more likely). But in either case, we have confirmation that there is a reasonable code path that involves returning timeouts as socket errors up into the initial sync code. Which I assume fails incorrectly, where a different exception would have been retried. | ||||
| Comment by Kelsey Schubert [ 23/Sep/16 ] | ||||
|
Hi MRigal, Thank you for reporting this issue. We're investigating and will update this ticket when we know more. Kind regards, | ||||
| Comment by Matthieu Rigal [ 21/Sep/16 ] | ||||
|
Additional comment, we retried it also with modifying the TCP keepalive parameters, in both directions, without more success... https://docs.mongodb.com/manual/faq/diagnostics/#does-tcp-keepalive-time-affect-mongodb-deployments | ||||
| Comment by Matthieu Rigal [ 21/Sep/16 ] | ||||
|
This could (should ?) be done prior to https://jira.mongodb.org/browse/SERVER-8076 |