[SERVER-9199] Initial replication sync failed Created: 01/Apr/13 Updated: 10/Dec/14 Resolved: 12/Apr/13 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | Replication |
| Affects Version/s: | 2.4.1 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Marat Shakirov | Assignee: | J Rassi |
| Resolution: | Done | Votes: | 0 |
| Labels: | azure, initialSync, replicaset | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Environment: |
Primary ubuntu 10.04/ mongo 2.4.1 id0 |
||
| Attachments: |
|
|||||||||||||||||||||||||||||||||
| Operating System: | Linux | |||||||||||||||||||||||||||||||||
| Steps To Reproduce: | Start new replica and after 5-6 hours replica going to Assertion Failure.
|
|||||||||||||||||||||||||||||||||
| Participants: |
| Description |
|
rs.conf={ , , { "_id" : 2, "host" : "repl-10:27017", "priority" : 0, "slaveDelay" : 1800 } ] id0 and id1 in the same hosting (hetzner). network between id0 and id1 1Gb link 0.2 ms id2 deployed on azure. network between hetzner<>azure ~100MB link 30ms ping |
| Comments |
| Comment by Marat Shakirov [ 13/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Thank you! | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by J Rassi [ 12/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
I believe that adjusting the keepalive values was what fixed your issue (I suggest you consult Azure support for recommendations on what values to finalize on); the evidence available is consistent with the theory that a device in Azure was severing your connections. As such, I will resolve this ticket. Here are some observations I made from the log you provided:
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Marat Shakirov [ 12/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
from repl-10 | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Marat Shakirov [ 12/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
My replica now in STATE SECONDARY. Replica just slow replicate all base. , , { "_id" : 2, "host" : "repl-10:27017" } ] , , , | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Noah Davis [ 11/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Thank you Jason, I've added the issue here - https://jira.mongodb.org/browse/SERVER-9330 | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by J Rassi [ 11/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Noah, you are not encountering the same issue. Could you create a new SERVER ticket with title "Error 10092 during initial sync" and attach to the ticket the full mongod log file from the node that failed? | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Noah Davis [ 11/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Our replica also crashed last night 5-6 hours into its initial sync. We're on mongo 2.4.1. Here's the stacktrace from the replica: https://gist.github.com/noahd1/64fded6a77a5334a3351 Could you tell me if this is likely the same issue? If so, can I provide any additional information to help with the debugging? Thank you. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by J Rassi [ 10/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
That's not expected – if it's in STARTUP, it likely hasn't even started performing the initial sync. For prod-media-s02 and repl-10, could you:
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Marat Shakirov [ 10/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Yes, I decrease values already and start replication. But my replica in STARTUP state 2+ days. very slow. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by J Rassi [ 10/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Just checking in – were you able to decrease repl-10's keepalive values and reattempt the initial sync? | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by J Rassi [ 08/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
17 minutes is fine. The packet capture did show all of the keepalive probes getting a response for the experiment. However, for the initial sync, I'm still suspicious that the connection was dropped between keepalive probes while it was idle. I just came across a few reports from Microsoft/MongoLab employees of, supposedly, stateful routing infrastructure within Azure that (during peak load) drops connections that have been idle for only 1-4 minutes:
Based on this, I have further steps for diagnosis:
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Marat Shakirov [ 07/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
I waited slightly more long - 17 minutes, it is important?
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Marat Shakirov [ 07/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
tcpdump on 27017 | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by J Rassi [ 06/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
In the repl-10 log provided, I see ~30 attempts to perform an initial sync. Almost all of them fail at the exact same spot: the initial sync thread performs a 10-12 index build for the "songs.api_log" {_id: 1} index, and then the next socket write to the initial sync connection fails with ECONNRESET. The second-longest index builds seen performed by this thread are less than 3 minutes, and all socket writes immediately after those builds succeed. Note that no data is sent over the initial sync connection during the {_id: 1} index builds (however there should still be TCP traffic exchanged, since MongoDB enables SO_KEEPALIVE on both sides of the connection and lowers the idle and missed probe intervals to 5 minutes – and note this is currently Linux-only). There may be an issue with a stateful device on the Hetzner<=>Azure link, possibly a NAT device aggressively dropping idle connections from its translation table. Would you be able to take mongod on repl-10 offline (if it's not still offline) for long enough to perform the following experiment?
If it turns out there aren't responses to the keepalive probes, then I'd conclude it's a Hetzner or Azure issue; if there are, we'll diagnose further. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Marat Shakirov [ 06/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
on repl-10
sysct.conf:
on prod-media-s02
sysctl.conf:
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by J Rassi [ 05/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Can you paste the output of the following commands, on both prod-media-s02 and repl-10?
|