Open chandraprakash opened 11 years ago
Case: node1 & node2 (zerostate nodes) node3 (new node bootstrapping off node2)
When node3 bootstraps off node2, GetAvailableEndpoint at node2 doesn't pick up the existing connection and returns a new transport's endpoint. This is resulting in some mismatch & resulting in the assertion on OnConnectionLostSlot().
Routing tests FUNC_ProcessSendDirectEndpoint & FUNC_ProcessSendRecursiveSendOn are intermittently failing due to this issue.
Repeating all tests (iteration 17) . . .
Note: Google Test filter = *FUNC_ProcessSendDirectEndpoint*
[==========] Running 1 test from 1 test case.
[----------] Global test environment set-up.
[==========] 1 test from NetworkUtilsTest
[ RUN ] NetworkUtilsTest.FUNC_ProcessSendDirectEndpoint
V 132 19:41:28.491801 rudp/connection_manager.cc:219] c064b9..ee3d1a This is a handshake packet from 192.168.0.44:23186 which is replying to a join request, or starting a new network
V 132 19:41:28.492169 rudp/core/session.cc:192] Can't establish external endpoint, peer on same network as this node.
S 132 19:41:28.492339 rudp/transport.cc:420] Successfully made Bootstrapping connection from [c064b9. - 0.0.0.0:0 / 192.168.0.44:60924] to [a20bae. - 192.168.0.44:23186]
V 132 19:41:28.492448 rudp/transport.cc:449]
++++++++++++++++++++++++
Added Bootstrapping connection from [c064b9. - 0.0.0.0:0 / 192.168.0.44:60924] to [a20bae. - 192.168.0.44:23186]
This node's peer connections:
a20bae.
This node's own transports and their peer connections:
[c064b9. - 0.0.0.0:0 / 192.168.0.44:60924] unknown NAT
Peer [a20bae. - 192.168.0.44:23186] Bootstrapping Expires in 00:09:59.866719
This node's idle transports:
This node's pending connections:
V 130 19:41:28.492465 rudp/transport.cc:113] Started new transport on 192.168.0.44:60924 connected to 000000. - 192.168.0.44:23186
V 130 19:41:28.492560 rudp/managed_connections.cc:223] Started a new transport on 0.0.0.0:0 / 192.168.0.44:60924 behind unknown NAT
V 133 19:41:28.492812 rudp/core/session.cc:192] Can't establish external endpoint, peer on same network as this node.
S 133 19:41:28.492970 rudp/transport.cc:420] Successfully made Bootstrapping connection from [a20bae. - 0.0.0.0:0 / 192.168.0.44:23186] to [c064b9. - 192.168.0.44:60924]
V 133 19:41:28.493077 rudp/transport.cc:449]
++++++++++++++++++++++++
Added Bootstrapping connection from [a20bae. - 0.0.0.0:0 / 192.168.0.44:23186] to [c064b9. - 192.168.0.44:60924]
This node's peer connections:
c064b9.
This node's own transports and their peer connections:
[a20bae. - 0.0.0.0:0 / 192.168.0.44:23186] unknown NAT
Peer [c064b9. - 192.168.0.44:60924] Bootstrapping Expires in 00:09:59.997175
This node's idle transports:
This node's pending connections:
V 131 19:41:28.493169 rudp/transport.cc:113] Started new transport on 192.168.0.44:23186 connected to 000000. - 192.168.0.44:60924
V 131 19:41:28.493252 rudp/managed_connections.cc:223] Started a new transport on 0.0.0.0:0 / 192.168.0.44:23186 behind unknown NAT
V 5 19:41:28.495743 routing/tests/network_utils_test.cc:202] ------------------------ Zero state setup done -----------------------
V 5 19:41:28.554999 routing/bootstrap_file_handler.cc:180] Appending 192.168.0.109:5483 to bootstrap endpoints
V 134 19:41:28.569714 rudp/connection_manager.cc:245] a20bae..d4cae2 This is a handshake packet from 192.168.0.44:40483 which is trying to ping this node or join the network
V 135 19:41:28.570890 rudp/connection_manager.cc:219] 5b0e9b..0a30e5 This is a handshake packet from 192.168.0.44:23186 which is replying to a join request, or starting a new network
V 136 19:41:28.572629 rudp/core/session.cc:192] Can't establish external endpoint, peer on same network as this node.
S 136 19:41:28.572832 rudp/transport.cc:420] Successfully made Bootstrapping connection from [5b0e9b. - 0.0.0.0:0 / 192.168.0.44:40483] to [a20bae. - 192.168.0.44:23186]
V 134 19:41:28.572856 rudp/core/session.cc:192] Can't establish external endpoint, peer on same network as this node.
V 5 19:41:28.572963 rudp/transport.cc:113] Started new transport on 192.168.0.44:40483 connected to 000000. - 192.168.0.44:23186
V 5 19:41:28.573126 rudp/managed_connections.cc:223] Started a new transport on 0.0.0.0:0 / 192.168.0.44:40483 behind unknown NAT
V 136 19:41:28.573065 rudp/transport.cc:449]
++++++++++++++++++++++++
Added Bootstrapping connection from [5b0e9b. - 0.0.0.0:0 / 192.168.0.44:40483] to [a20bae. - 192.168.0.44:23186]
This node's peer connections:
a20bae.
This node's own transports and their peer connections:
[5b0e9b. - 0.0.0.0:0 / 192.168.0.44:40483] unknown NAT
Peer [a20bae. - 192.168.0.44:23186] Bootstrapping Expires in 00:09:59.996505
This node's idle transports:
This node's pending connections:
I 5 19:41:28.573313 routing/network_utils.cc:112] Bootstrap successful, bootstrap connection id - a20bae..d4cae2
V 132 19:41:28.573714 rudp/connection_manager.cc:245] c064b9..ee3d1a This is a handshake packet from 192.168.0.44:57832 which is trying to ping this node or join the network
S 134 19:41:28.573033 rudp/transport.cc:420] Successfully made Bootstrapping connection from [a20bae. - 0.0.0.0:0 / 192.168.0.44:23186] to [5b0e9b. - 192.168.0.44:40483]
V 133 19:41:28.575778 rudp/connection_manager.cc:219] a20bae..d4cae2 This is a handshake packet from 192.168.0.44:60924 which is replying to a join request, or starting a new network
V 134 19:41:28.575822 rudp/transport.cc:449]
++++++++++++++++++++++++
Added Bootstrapping connection from [a20bae. - 0.0.0.0:0 / 192.168.0.44:23186] to [5b0e9b. - 192.168.0.44:40483]
This node's peer connections:
5b0e9b.
c064b9.
This node's own transports and their peer connections:
[a20bae. - 0.0.0.0:0 / 192.168.0.44:23186] unknown NAT
Peer [c064b9. - 192.168.0.44:60924] Permanent Expires in +infinity
Peer [5b0e9b. - 192.168.0.44:40483] Bootstrapping Expires in 00:09:59.994047
This node's idle transports:
This node's pending connections:
V 133 19:41:28.576040 rudp/core/session.cc:192] Can't establish external endpoint, peer on same network as this node.
V 137 19:41:28.576197 rudp/transport.cc:492]
************************
Removed Temporary connection from [c064b9. - 0.0.0.0:0 / 192.168.0.44:60924] to [a20bae. - 192.168.0.44:57832]
This node's peer connections:
a20bae.
This node's own transports and their peer connections:
[c064b9. - 0.0.0.0:0 / 192.168.0.44:60924] unknown NAT
Peer [a20bae. - 192.168.0.44:23186] Permanent Expires in +infinity
This node's idle transports:
This node's pending connections:
V 133 19:41:28.576305 rudp/connection_manager.cc:236] a20bae..d4cae2 Received a packet "0x80" for unknown connection 1296252123 from 192.168.0.44:60924
V 133 19:41:28.576430 rudp/transport.cc:492]
************************
Removed Temporary connection from [a20bae. - 0.0.0.0:0 / 192.168.0.44:57832] to [c064b9. - 192.168.0.44:60924]
This node's peer connections:
5b0e9b.
c064b9.
This node's own transports and their peer connections:
[a20bae. - 0.0.0.0:0 / 192.168.0.44:23186] unknown NAT
Peer [c064b9. - 192.168.0.44:60924] Permanent Expires in +infinity
Peer [5b0e9b. - 192.168.0.44:40483] Bootstrapping Expires in 00:09:59.993445
This node's idle transports:
[a20bae. - 0.0.0.0:0 / 192.168.0.44:57832] unknown NAT
This node's pending connections:
V 5 19:41:28.576517 rudp/transport.cc:113] Started new transport on 192.168.0.44:57832 connected to c064b9. - 192.168.0.44:60924
V 5 19:41:28.576567 rudp/managed_connections.cc:223] Started a new transport on 0.0.0.0:0 / 192.168.0.44:57832 behind unknown NAT
/home/prakash/repo/MaidSafe/src/routing/src/maidsafe/routing/tests/network_utils_test.cc:219: Failure
Value of: rudp2.GetAvailableEndpoint(node_id3, endpoint_pair_3, endpoint_pair_2, this_nat_type)
Actual: 0
Expected: rudp::kBootstrapConnectionAlreadyExists
Which is: -350008
I 5 19:41:28.576875 rudp/connection_manager.cc:126] a20bae..d4cae2 Not currently connected to 5b0e9b..0a30e5
V 136 19:41:28.577178 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:28.577238 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 134 19:41:28.579884 rudp/managed_connections.cc:626]
^^^^^^^^^^^^ OnMessageSlot ^^^^^^^^^^^^
This node's peer connections:
5b0e9b.
c064b9.
This node's own transports and their peer connections:
[a20bae. - 0.0.0.0:0 / 192.168.0.44:23186] unknown NAT
Peer [c064b9. - 192.168.0.44:60924] Permanent Expires in +infinity
Peer [5b0e9b. - 192.168.0.44:40483] Bootstrapping Expires in 00:09:59.990005
This node's idle transports:
[a20bae. - 0.0.0.0:0 / 192.168.0.44:57832] unknown NAT
This node's pending connections:
Pending to peer 5b0e9b. on this node's transport 0.0.0.0:0 / 192.168.0.44:57832
V 134 19:41:28.581821 routing/tests/network_utils_test.cc:123] Node -2- Received: validation_3->2, total count = 1
V 136 19:41:28.827186 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:28.827281 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 136 19:41:29.079904 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:29.079991 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 135 19:41:29.329971 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 135 19:41:29.330066 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 136 19:41:29.580205 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:29.580294 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 135 19:41:29.830279 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 135 19:41:29.830373 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 136 19:41:30.080348 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:30.080441 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 135 19:41:30.330428 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 135 19:41:30.330560 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 136 19:41:30.580511 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:30.580645 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 135 19:41:30.830577 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 135 19:41:30.830668 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 136 19:41:31.080653 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:31.080777 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 135 19:41:31.330734 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 135 19:41:31.330819 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 135 19:41:31.580811 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 135 19:41:31.580964 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 136 19:41:31.830907 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:31.830999 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 135 19:41:32.080971 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 135 19:41:32.081126 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 136 19:41:32.331074 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:32.331185 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 135 19:41:32.581327 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 135 19:41:32.581417 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 135 19:41:32.831215 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 135 19:41:32.831308 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 136 19:41:33.081301 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:33.081392 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
V 136 19:41:33.331389 rudp/connection_manager.cc:175] 5b0e9b..0a30e5 This is a handshake packet on a newly-added socket from 192.168.0.44:57832
V 136 19:41:33.331494 rudp/connection_manager.cc:236] 5b0e9b..0a30e5 Received a packet "0x80" for unknown connection 0 from 192.168.0.44:57832
W 133 19:41:33.577101 rudp/connection.cc:256] Failed to connect from 0.0.0.0:0 / 192.168.0.44:57832 to 192.168.0.44:40483 - timed out.
E 133 19:41:33.577228 rudp/managed_connections.cc:718] peer_id: 5b0e9b..0a30e5 is connected via 192.168.0.44:23186 not 192.168.0.44:57832
TESTrouting: /home/prakash/repo/MaidSafe/src/rudp/src/maidsafe/rudp/managed_connections.cc:720: void maidsafe::rudp::ManagedConnections::OnConnectionLostSlot(const maidsafe::NodeId&, maidsafe::rudp::ManagedConnections::TransportPtr, bool): Assertion `false' failed.
V 136 19:41:33.577280 rudp/connection_manager.cc:169] 5b0e9b..0a30e5 Failed to decode handshake packet from 192.168.0.44:57832
Aborted (core dumped)
prakash@di-work-64:~/repo/MaidSafe/build$
W 139706536806144 10:44:12.633625 rudp/connection.cc:229] Failed to connect from 176.58.120.133:57162 / 176.58.120.133:57162 to 192.168.0.26:43752 - timed out. pd-vault: /home/maidsafe/super/MaidSafe/src/rudp/src/maidsafe/rudp/managed_connections.cc:671: void maidsafe::rudp::ManagedConnections::OnConnectionLostSlot(const maidsafe::NodeId&, maidsafe::rudp::{anonymous}::TransportPtr, bool): Assertion `false' failed.
Stack trace for this issue: