internal void WriteToLog_p2p_lightPain(ConnectionToNeighbor connectionToNeighbor, string message, object req) { if (Configuration.VisionChannel?.GetAttentionTo(Configuration.VisionChannelSourceId, VisionChannelModuleName_p2p) <= AttentionLevel.lightPain) { Configuration.VisionChannel?.EmitPeerInRoutedPath(Configuration.VisionChannelSourceId, VisionChannelModuleName_p2p, AttentionLevel.lightPain, $"[{connectionToNeighbor}] {message}", req, connectionToNeighbor.LocalDrpPeer); } }
public void AddToConnectedNeighbors(ConnectionToNeighbor newConnectedNeighbor, RegisterRequestPacket req) { newConnectedNeighbor.OnP2pInitialized(); ConnectedNeighbors.Add(newConnectedNeighbor); Engine.WriteToLog_p2p_higherLevelDetail(newConnectedNeighbor, $"added new connection to list of neighbors: {newConnectedNeighbor} to {newConnectedNeighbor.RemoteEndpoint}", req); }
async Task WaitForRegistrationConfirmationRequestAsync(string requesterVisibleDescription, Logger logger, IPEndPoint requesterEndpoint, RegisterRequestPacket req, ConnectionToNeighbor newConnectionToNeighbor, ConnectionToNeighbor sourcePeerNullable) { try { var regCfmScanner = RegisterConfirmationPacket.GetScanner(logger, sourcePeerNullable, req); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"waiting for CFM"); } var regCfmUdpPayload = await OptionallySendUdpRequestAsync_Retransmit_WaitForResponse("cfm 123575", requesterVisibleDescription, null, requesterEndpoint, regCfmScanner, Configuration.CfmTimoutS); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received CFM"); } var registerCfmPacket = RegisterConfirmationPacket.DecodeAndOptionallyVerify(regCfmUdpPayload, req, newConnectionToNeighbor); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified CFM"); } SendNeighborPeerAckResponseToRegisterCfm(registerCfmPacket, requesterEndpoint, sourcePeerNullable); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sent NPACK to CFM"); } } catch (Exception exc) { logger.WriteToLog_lightPain($"disposing new connection because of CFM error: {exc}"); newConnectionToNeighbor.Dispose(); } }
/// <returns>null if no neighbors found for routing</returns> public ConnectionToNeighbor RouteInviteRequest(LocalDrpPeer localDrpPeer, RoutedRequest routedRequest) { var req = routedRequest.InviteReq; var logger = routedRequest.Logger; ConnectionToNeighbor r = null; RegistrationIdDistance minDistance = null; var connectedNeighborsForRouting = localDrpPeer.GetConnectedNeighborsForRouting(routedRequest).ToList(); foreach (var connectedPeer in connectedNeighborsForRouting) { var distanceToConnectedPeer = req.ResponderRegistrationId.GetDistanceTo(_cryptoLibrary, connectedPeer.RemoteRegistrationId, NumberOfDimensions); logger.WriteToLog_routing_detail($"distanceToConnectedPeer={distanceToConnectedPeer} from {req} to {connectedPeer}"); if (minDistance == null || minDistance.IsGreaterThan(distanceToConnectedPeer)) { minDistance = distanceToConnectedPeer; r = connectedPeer; } } if (r == null) { logger.WriteToLog_routing_detail($"no neighbors found for routing"); } return(r); }
internal void WriteToLog_p2p_detail(ConnectionToNeighbor connectionToNeighbor, string message, object req) { if (WriteToLog_p2p_detail_enabled) { Configuration.VisionChannel?.EmitPeerInRoutedPath(Configuration.VisionChannelSourceId, VisionChannelModuleName_p2p, AttentionLevel.detail, $"[{connectionToNeighbor}] {message}", req, connectionToNeighbor.LocalDrpPeer); } }
void DestroyWorstNeighbor(double?mutualValueLowLimit, DateTime timeNowUtc) { if (ConnectedNeighbors.Any(x => x.IsInTeardownState)) { return; } double?worstValue = mutualValueLowLimit; ConnectionToNeighbor worstNeighbor = null; foreach (var neighbor in ConnectedNeighborsCanBeUsedForNewRequests) { var p2pConnectionValue_withNeighbor = P2pConnectionValueCalculator.GetMutualP2pConnectionValue(CryptoLibrary, this.Configuration.LocalPeerRegistrationId, this.ConnectedNeighborsBusySectorIds, neighbor.RemoteRegistrationId, neighbor.RemoteNeighborsBusySectorIds ?? 0, Engine.NumberOfDimensions, true, this.AnotherNeighborToSameSectorExists(neighbor), neighbor.Remote_AnotherNeighborToSameSectorExists ?? false ); Engine.WriteToLog_p2p_higherLevelDetail(neighbor, $"@DestroyWorstNeighbor() p2pConnectionValue_withNeighbor={p2pConnectionValue_withNeighbor} from {this} to {neighbor}", null); if (worstValue == null || p2pConnectionValue_withNeighbor < worstValue) { worstValue = p2pConnectionValue_withNeighbor; worstNeighbor = neighbor; } } if (worstNeighbor != null) { _lastTimeDetroyedWorstNeighborUtc = timeNowUtc; Engine.WriteToLog_p2p_higherLevelDetail(worstNeighbor, $"destroying worst P2P connection with neighbor. neighbors count = {ConnectedNeighbors.Count}", null); var ping = worstNeighbor.CreatePing(false, true, 0, false); var pendingPingRequest = new PendingLowLevelUdpRequest("pendingPingRequest 351", worstNeighbor.RemoteEndpoint, PongPacket.GetScanner(worstNeighbor.LocalNeighborToken32, ping.PingRequestId32), Engine.DateTimeNowUtc, Engine.Configuration.UdpLowLevelRequests_ExpirationTimeoutS, ping.Encode(), Engine.Configuration.UdpLowLevelRequests_InitialRetransmissionTimeoutS, Engine.Configuration.UdpLowLevelRequests_RetransmissionTimeoutIncrement ); _ = Engine.SendUdpRequestAsync_Retransmit(pendingPingRequest); // retransmit until PONG worstNeighbor.IsInTeardownState = true; Engine.EngineThreadQueue.EnqueueDelayed(TimeSpan.FromSeconds(PingPacket.ConnectionTeardownStateDurationS), () => { if (!worstNeighbor.IsDisposed) { Engine.WriteToLog_p2p_higherLevelDetail(worstNeighbor, $"destroying worst P2P connection after teardown state timeout", null); worstNeighbor.Dispose(); } }, "estroying worst P2P connection 2146"); } }
public SentRequest(DrpPeerEngine engine, Logger logger, IPEndPoint destinationEndpoint, ConnectionToNeighbor destinationNeighborNullable, byte[] requestUdpData, RequestP2pSequenceNumber16 sentReqP2pSeq16, LowLevelUdpResponseScanner ack1Scanner) { _destinationEndpoint = destinationEndpoint; _logger = logger; _requestUdpData = requestUdpData; _sentReqP2pSeq16 = sentReqP2pSeq16; _ack1Scanner = ack1Scanner; _destinationNeighborNullable = destinationNeighborNullable; _engine = engine; }
public bool AnotherNeighborToSameSectorExists(ConnectionToNeighbor neighbor) { ushort r = 0; foreach (var n in ConnectedNeighborsCanBeUsedForNewRequests) { if (n != neighbor && n.SectorIndexFlagsMask == neighbor.SectorIndexFlagsMask) { return(true); } } return(false); }
void SendNeighborPeerAckResponseToCfm(InviteConfirmationPacket cfm, ConnectionToNeighbor neighbor) { var npAck = new NeighborPeerAckPacket { ReqP2pSeq16 = cfm.ReqP2pSeq16, ResponseCode = ResponseOrFailureCode.accepted }; npAck.NeighborToken32 = neighbor.RemoteNeighborToken32; npAck.NeighborHMAC = neighbor.GetNeighborHMAC(w => npAck.GetSignedFieldsForNeighborHMAC(w, cfm.GetSignedFieldsForNeighborHMAC)); var npAckUdpData = npAck.Encode(false); Engine.RespondToRequestAndRetransmissions(cfm.DecodedUdpPayloadData, npAckUdpData, neighbor.RemoteEndpoint); }
public RoutedRequest(Logger logger, ConnectionToNeighbor receivedFromNeighborNullable, IPEndPoint receivedFromEndpoint, Stopwatch reqReceivedSwNullable, InviteRequestPacket inviteReqNullable, RegisterRequestPacket registerReqNullable, RoutedRequest previousTrialRoutedRequestNullable = null) { InviteReq = inviteReqNullable; RegisterReq = registerReqNullable; if (InviteReq == null && RegisterReq == null) { throw new ArgumentException(); } if (InviteReq != null && RegisterReq != null) { throw new ArgumentException(); } ReceivedFromNeighborNullable = receivedFromNeighborNullable; ReceivedFromEndpoint = receivedFromEndpoint; Logger = logger; _engine = logger.Engine; ReqReceivedSwNullable = reqReceivedSwNullable; if (InviteReq != null) { ReqP2pSeq16 = InviteReq.ReqP2pSeq16; } else { ReqP2pSeq16 = RegisterReq.ReqP2pSeq16; } if (previousTrialRoutedRequestNullable != null) { _repliedWithNPA = previousTrialRoutedRequestNullable._repliedWithNPA; TriedNeighbors = previousTrialRoutedRequestNullable.TriedNeighbors; } }
/// <summary> /// main register responder proc for both A-EP and P2P modes /// in P2P mode Timestamp32S, NeighborToken32 and NeighborHMAC are verified at this time /// </summary> /// <param name="receivedFromInP2pMode"> /// is null in A-EP mode /// </param> internal async Task AcceptRegisterRequestAsync(LocalDrpPeer acceptAt, RoutedRequest routedRequest) // engine thread { var logger = routedRequest.Logger; logger.ModuleName = VisionChannelModuleName_reg_responderSide; var req = routedRequest.RegisterReq; if (req.RequesterRegistrationId.Equals(acceptAt.Configuration.LocalPeerRegistrationId)) { throw new InvalidOperationException(); } // check signature of requester (A) if (!req.RequesterSignature.Verify(_cryptoLibrary, w => req.GetSharedSignedFields(w, false), req.RequesterRegistrationId ) ) { throw new BadSignatureException("invalid REGISTER REQ RequesterSignature 2396"); } if (routedRequest.ReceivedFromNeighborNullable == null) { // A-EP mode if (req.EpEndpoint.Address.Equals(acceptAt.PublicIpApiProviderResponse) == false) { throw new PossibleAttackException(); } } if (PendingRegisterRequestExists(req.RequesterRegistrationId)) { // received duplicate REGISTER REQ packet logger.WriteToLog_needsAttention($"ignoring duplicate registration request {req.RequesterRegistrationId} from {routedRequest.ReceivedFromEndpoint}"); return; } if (!RecentUniqueAcceptedRegistrationRequests.Filter(req.GetUniqueRequestIdFields)) { logger.WriteToLog_needsAttention($"ignoring registration request {req.RequesterRegistrationId} ts={req.ReqTimestamp64} from {routedRequest.ReceivedFromEndpoint} with non-unique request ID fields"); return; } logger.WriteToLog_higherLevelDetail($"accepting registration from {routedRequest.ReceivedFromEndpoint}: ReqP2pSeq16={req.ReqP2pSeq16}, NumberOfHopsRemaining={req.NumberOfHopsRemaining}, epEndpoint={req.EpEndpoint}, sourcePeer={routedRequest.ReceivedFromNeighborNullable}, ts={req.ReqTimestamp64}"); if (!RecentUniquePublicEcdhKeys.Filter(req.RequesterEcdhePublicKey.Ecdh25519PublicKey)) { logger.WriteToLog_needsAttention($"ignoring registration request {req.RequesterRegistrationId} from {routedRequest.ReceivedFromEndpoint} with non-unique RequesterEcdhePublicKey"); return; } _pendingRegisterRequests.Add(req.RequesterRegistrationId); try { if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending NPACK to REQ to {routedRequest.ReceivedFromEndpoint} (delay={routedRequest.ReqReceivedSw_ms}ms)"); } routedRequest.SendNeighborPeerAck_accepted_IfNotAlreadyReplied(); var newConnectionToNeighbor = new ConnectionToNeighbor(this, acceptAt, ConnectedDrpPeerInitiatedBy.remotePeer, req.RequesterRegistrationId) { LocalEndpoint = routedRequest.ReceivedFromNeighborNullable?.LocalEndpoint ?? req.EpEndpoint, }; byte[] ack1UdpData; try { var ack1 = new RegisterAck1Packet { RequesterRegistrationId = req.RequesterRegistrationId, ReqTimestamp64 = req.ReqTimestamp64, ResponderEcdhePublicKey = new EcdhPublicKey(newConnectionToNeighbor.LocalEcdhe25519PublicKey), ResponderRegistrationId = acceptAt.Configuration.LocalPeerRegistrationId, ReqP2pSeq16 = GetNewNpaSeq16_AtoEP(), }; RecentUniquePublicEcdhKeys.AssertIsUnique(ack1.ResponderEcdhePublicKey.Ecdh25519PublicKey, $"ack1.ResponderEcdhePublicKey"); ack1.ToResponderTxParametersEncrypted = newConnectionToNeighbor.Encrypt_ack1_ToResponderTxParametersEncrypted_AtResponder_DeriveSharedDhSecret(logger, req, ack1, routedRequest.ReceivedFromNeighborNullable); ack1.ResponderSignature = RegistrationSignature.Sign(_cryptoLibrary, (w2) => { req.GetSharedSignedFields(w2, true); ack1.GetSharedSignedFields(w2, false, true); }, acceptAt.Configuration.LocalPeerRegistrationPrivateKey); if (routedRequest.ReceivedFromNeighborNullable == null) { ack1.RequesterEndpoint = routedRequest.ReceivedFromEndpoint; } ack1UdpData = ack1.Encode_OpionallySignNeighborHMAC(routedRequest.ReceivedFromNeighborNullable); var ack2Scanner = RegisterAck2Packet.GetScanner(logger, routedRequest.ReceivedFromNeighborNullable, req); var requesterVisibleDescription = routedRequest.ReceivedFromNeighborNullable?.ToString() ?? routedRequest.ReceivedFromEndpoint.ToString(); byte[] ack2UdpData; if (routedRequest.ReceivedFromNeighborNullable == null) { // wait for ACK2, retransmitting ACK1 if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending ACK1, waiting for ACK2"); } ack2UdpData = await OptionallySendUdpRequestAsync_Retransmit_WaitForResponse("ack2 33469", requesterVisibleDescription, ack1UdpData, routedRequest.ReceivedFromEndpoint, ack2Scanner); } else { // retransmit ACK1 until NPACK (via P2P); at same time wait for ACK if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending ACK1, awaiting for NPACK"); } _ = OptionallySendUdpRequestAsync_Retransmit_WaitForNeighborPeerAck("ack1 423087", ack1UdpData, routedRequest.ReceivedFromEndpoint, ack1.ReqP2pSeq16, routedRequest.ReceivedFromNeighborNullable, ack1.GetSignedFieldsForNeighborHMAC); // not waiting for NPACK, wait for ACK if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"waiting for ACK2"); } ack2UdpData = await OptionallySendUdpRequestAsync_Retransmit_WaitForResponse("ack2 46051", requesterVisibleDescription, null, routedRequest.ReceivedFromEndpoint, ack2Scanner); } if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received ACK2"); } var ack2 = RegisterAck2Packet.Decode_OptionallyVerify_InitializeP2pStreamAtResponder(logger, ack2UdpData, req, ack1, newConnectionToNeighbor); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified ACK2"); } acceptAt.AddToConnectedNeighbors(newConnectionToNeighbor, req); // added to list here in order to respond to ping requests from A SendNeighborPeerAckResponseToRegisterAck2(ack2, routedRequest.ReceivedFromEndpoint, routedRequest.ReceivedFromNeighborNullable); // send NPACK to ACK _ = WaitForRegistrationConfirmationRequestAsync(requesterVisibleDescription, logger, routedRequest.ReceivedFromEndpoint, req, newConnectionToNeighbor, routedRequest.ReceivedFromNeighborNullable); #region send ping, verify pong var ping = newConnectionToNeighbor.CreatePing(true, false, acceptAt.ConnectedNeighborsBusySectorIds, acceptAt.AnotherNeighborToSameSectorExists(newConnectionToNeighbor)); var pendingPingRequest = new PendingLowLevelUdpRequest("pendingPingRequest 693", newConnectionToNeighbor.RemoteEndpoint, PongPacket.GetScanner(newConnectionToNeighbor.LocalNeighborToken32, ping.PingRequestId32), DateTimeNowUtc, Configuration.InitialPingRequests_ExpirationTimeoutS, ping.Encode(), Configuration.InitialPingRequests_InitialRetransmissionTimeoutS, Configuration.InitialPingRequests_RetransmissionTimeoutIncrement ); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sent PING"); } var pongPacketData = await SendUdpRequestAsync_Retransmit(pendingPingRequest); // wait for pong from A if (pongPacketData == null) { throw new DrpTimeoutException($"reg. responder initial PING request to {newConnectionToNeighbor} (timeout={Configuration.InitialPingRequests_ExpirationTimeoutS}s)"); } var pong = PongPacket.DecodeAndVerify(_cryptoLibrary, pongPacketData, ping, newConnectionToNeighbor, true); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified PONG"); } newConnectionToNeighbor.OnReceivedVerifiedPong(pong, pendingPingRequest.ResponseReceivedAtUtc.Value, pendingPingRequest.ResponseReceivedAtUtc.Value - pendingPingRequest.InitialTxTimeUTC.Value); #endregion } catch (Exception exc) { newConnectionToNeighbor.Dispose(); throw exc; } } catch (DrpTimeoutException exc) { logger.WriteToLog_needsAttention($"could not accept REGISTER request: {exc}"); } catch (Exception exc) { logger.WriteToLog_mediumPain($"could not accept REGISTER request: {exc}"); } finally { _pendingRegisterRequests.Remove(req.RequesterRegistrationId); } }
void SendNeighborPeerAckResponseToRegisterCfm(RegisterConfirmationPacket cfm, IPEndPoint remoteEndpoint, ConnectionToNeighbor neighbor) { var npAck = new NeighborPeerAckPacket { ReqP2pSeq16 = cfm.ReqP2pSeq16, ResponseCode = ResponseOrFailureCode.accepted }; if (cfm.AtoEP == false) { npAck.NeighborToken32 = neighbor.RemoteNeighborToken32; npAck.NeighborHMAC = neighbor.GetNeighborHMAC(w => npAck.GetSignedFieldsForNeighborHMAC(w, cfm.GetSignedFieldsForNeighborHMAC)); } var npAckUdpData = npAck.Encode(cfm.AtoEP); RespondToRequestAndRetransmissions(cfm.DecodedUdpPayloadData, npAckUdpData, remoteEndpoint); }
//internal void SendErrorResponseToRegisterReq(RegisterRequestPacket req, IPEndPoint requesterEndpoint, // ConnectionToNeighbor neighbor, bool alreadyRepliedWithNPA, DrpResponderStatusCode errorCode) //{ // WriteToLog_routing_higherLevelDetail($"routing failed, executing SendErrorResponseToRegisterReq()", req, neighbor?.LocalDrpPeer); // if (alreadyRepliedWithNPA) // { // // send ack1 // _ = RespondToSourcePeerWithAck1_Error(requesterEndpoint, req, neighbor, errorCode); // } // else // { // // send NPACK // SendNeighborPeerAckResponseToRegisterReq(req, requesterEndpoint, NextHopResponseOrFailureCode.failure_routeIsUnavailable, neighbor); // } //} internal void SendNeighborPeerAckResponseToRegisterAck1(RegisterAck1Packet ack1, ConnectionToNeighbor neighbor) { var npAck = new NeighborPeerAckPacket { ReqP2pSeq16 = ack1.ReqP2pSeq16, ResponseCode = ResponseOrFailureCode.accepted }; npAck.NeighborToken32 = neighbor.RemoteNeighborToken32; npAck.NeighborHMAC = neighbor.GetNeighborHMAC(w => npAck.GetSignedFieldsForNeighborHMAC(w, ack1.GetSignedFieldsForNeighborHMAC)); var npAckUdpData = npAck.Encode(false); RespondToRequestAndRetransmissions(ack1.DecodedUdpPayloadData, npAckUdpData, neighbor.RemoteEndpoint); }
/// <returns>null if registration failed with timeout or some error code</returns> public async Task <ConnectionToNeighbor> RegisterAsync(LocalDrpPeer localDrpPeer, IPEndPoint epEndpoint, uint minimalDistanceToNeighbor, byte numberofHops, double[] directionVectorNullable, bool allowConnectionsToRequesterRegistrationId) // engine thread { var regSW = Stopwatch.StartNew(); WriteToLog_reg_requesterSide_higherLevelDetail($"connecting via EntryPeer {epEndpoint}", null, null); localDrpPeer.CurrentRegistrationOperationsCount++; try { #region PoW1 RegisterPow1ResponsePacket pow1ResponsePacket = null; if (!Configuration.SandboxModeOnly_DisablePoW) { WriteToLog_reg_requesterSide_detail($"generating PoW1 request", null, null); var pow1SW = Stopwatch.StartNew(); await PowThreadQueue.EnqueueAsync("pow1 6318"); WriteToLog_reg_requesterSide_detail($"generating PoW1 request @pow thread", null, null); var registerPow1RequestPacket = GenerateRegisterPow1RequestPacket(localDrpPeer.PublicIpApiProviderResponse.GetAddressBytes(), Timestamp32S); await EngineThreadQueue.EnqueueAsync("pow1 234709"); WriteToLog_reg_requesterSide_detail($"generated PoW1 request @engine thread", null, null); // send register pow1 request if (pow1SW.Elapsed.TotalMilliseconds > 3000) { WriteToLog_reg_requesterSide_lightPain($"PoW1 took {(int)pow1SW.Elapsed.TotalMilliseconds}ms", null, null); } WriteToLog_reg_requesterSide_detail($"PoW1 took {(int)pow1SW.Elapsed.TotalMilliseconds}ms. sending PoW1 request", null, null); var rpPow1ResponsePacketData = await SendUdpRequestAsync_Retransmit( new PendingLowLevelUdpRequest("rpPow1 469", epEndpoint, RegisterPow1ResponsePacket.GetScanner(registerPow1RequestPacket.Pow1RequestId), DateTimeNowUtc, Configuration.UdpLowLevelRequests_ExpirationTimeoutS, registerPow1RequestPacket.Encode(), Configuration.UdpLowLevelRequests_InitialRetransmissionTimeoutS, Configuration.UdpLowLevelRequests_RetransmissionTimeoutIncrement )); // wait for response, retransmit if (rpPow1ResponsePacketData == null) { throw new DrpTimeoutException($"pow1 request to EP '{epEndpoint}' (timeout={Configuration.UdpLowLevelRequests_ExpirationTimeoutS}s)"); } ; pow1ResponsePacket = new RegisterPow1ResponsePacket(rpPow1ResponsePacketData); WriteToLog_reg_requesterSide_detail($"got PoW1 response with status={pow1ResponsePacket.StatusCode}", null, null); if (pow1ResponsePacket.StatusCode != RegisterPow1ResponseStatusCode.succeeded_Pow2Challenge) { throw new Pow1RejectedException(pow1ResponsePacket.StatusCode); } } #endregion var newConnectionToNeighbor = new ConnectionToNeighbor(this, localDrpPeer, ConnectedDrpPeerInitiatedBy.localPeer, null); PongPacket pong; var req = new RegisterRequestPacket { RequesterRegistrationId = localDrpPeer.Configuration.LocalPeerRegistrationId, ReqTimestamp64 = Timestamp64, MinimalDistanceToNeighbor = minimalDistanceToNeighbor, RequesterNatBehaviour = LocalNatBehaviour, AllowConnectionsToRequesterRegistrationId = allowConnectionsToRequesterRegistrationId, NumberOfHopsRemaining = numberofHops, RequesterEcdhePublicKey = new EcdhPublicKey(newConnectionToNeighbor.LocalEcdhe25519PublicKey), ReqP2pSeq16 = GetNewNpaSeq16_AtoEP(), EpEndpoint = epEndpoint, DirectionVectorNullableD = directionVectorNullable }; var logger = new Logger(this, localDrpPeer, req, VisionChannelModuleName_reg_requesterSide); try { #region register REQ PoW2 RecentUniquePublicEcdhKeys.AssertIsUnique(req.RequesterEcdhePublicKey.Ecdh25519PublicKey, $"req.RequesterEcdhePublicKey {req}"); // this is used in non-standard way when routing registration requests to same (local) reg. ID, too var pow2SW = Stopwatch.StartNew(); if (!Configuration.SandboxModeOnly_DisablePoW) { await PowThreadQueue.EnqueueAsync("pow2 23465"); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"calculating PoW2 @pow thread"); } GenerateRegisterReqPow2(req, pow1ResponsePacket.ProofOfWork2Request); await EngineThreadQueue.EnqueueAsync("pow2 2496"); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"calculated PoW2 @engine thread"); } } else { req.ProofOfWork2 = new byte[64]; } pow2SW.Stop(); if (pow2SW.Elapsed.TotalMilliseconds > 3000) { logger.WriteToLog_lightPain($"PoW2 took {(int)pow2SW.Elapsed.TotalMilliseconds}ms"); } req.RequesterSignature = RegistrationSignature.Sign(_cryptoLibrary, w => req.GetSharedSignedFields(w, false), localDrpPeer.Configuration.LocalPeerRegistrationPrivateKey ); var reqToAck1Stopwatch = Stopwatch.StartNew(); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"PoW2 took {(int)pow2SW.Elapsed.TotalMilliseconds}ms. sending REQ, waiting for NPACK. ReqP2pSeq16={req.ReqP2pSeq16}"); } #endregion // var reqSW = Stopwatch.StartNew(); #region wait for ACK1 var sentRequest = new SentRequest(this, logger, epEndpoint, null, req.Encode_OptionallySignNeighborHMAC(null), req.ReqP2pSeq16, RegisterAck1Packet.GetScanner(logger, req)); var ack1UdpData = await sentRequest.SendRequestAsync("reg req ack1 367097"); var ack1 = RegisterAck1Packet.DecodeAndOptionallyVerify(logger, ack1UdpData, req, newConnectionToNeighbor); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified ACK1. RequesterEndpoint={ack1.RequesterEndpoint}"); } #endregion // check if it matches to previously known local public IP if (ack1.RequesterEndpoint.Address.Equals(localDrpPeer.PublicIpApiProviderResponse) == false) { // MITM attack / EP sent local (requester) endpoint IP some bad IP address throw new PossibleAttackException(); } RecentUniquePublicEcdhKeys.AssertIsUnique(ack1.ResponderEcdhePublicKey.Ecdh25519PublicKey, $"ack1.ResponderEcdhePublicKey from {epEndpoint}"); newConnectionToNeighbor.LocalEndpoint = ack1.RequesterEndpoint; newConnectionToNeighbor.RemoteRegistrationId = ack1.ResponderRegistrationId; reqToAck1Stopwatch.Stop(); var reqToAck1TimeMs = reqToAck1Stopwatch.Elapsed.TotalMilliseconds; if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"measured REQ-ACK1_RTT={(int)reqToAck1TimeMs}ms"); } #region send ACK2, encode local IP var ack2 = new RegisterAck2Packet { ReqTimestamp64 = req.ReqTimestamp64, RequesterRegistrationId = localDrpPeer.Configuration.LocalPeerRegistrationId, ReqP2pSeq16 = GetNewNpaSeq16_AtoEP() }; ack2.ToRequesterTxParametersEncrypted = newConnectionToNeighbor.Encrypt_ack2_ToRequesterTxParametersEncrypted_AtRequester(logger, req, ack1, ack2); newConnectionToNeighbor.InitializeP2pStream(req, ack1, ack2); ack2.RequesterSignature = RegistrationSignature.Sign(_cryptoLibrary, w => { req.GetSharedSignedFields(w, true); ack1.GetSharedSignedFields(w, true, true); ack2.GetSharedSignedFields(w, false, true); }, localDrpPeer.Configuration.LocalPeerRegistrationPrivateKey ); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending ACK2 (in response to ACK1), waiting for NPACK"); } RespondToRequestAndRetransmissions(ack1UdpData, ack2.Encode_OptionallySignNeighborHMAC(null), epEndpoint); await OptionallySendUdpRequestAsync_Retransmit_WaitForNeighborPeerAck("ack2 46873", null, epEndpoint, ack2.ReqP2pSeq16); #endregion var neighborWaitTimeMs = reqToAck1TimeMs * 0.5 - 250; if (neighborWaitTimeMs < 0) { neighborWaitTimeMs = 0; } if (neighborWaitTimeMs > 20) { if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"awaiting {(int)neighborWaitTimeMs}ms before PING..."); } await EngineThreadQueue.WaitAsync(TimeSpan.FromMilliseconds(neighborWaitTimeMs), "before PING 34589"); // wait until the ACK2 reaches neighbor N via peers if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"... awaiting is complete"); } } localDrpPeer.AddToConnectedNeighbors(newConnectionToNeighbor, req); #region send ping request directly to neighbor N, retransmit var pingRequest = newConnectionToNeighbor.CreatePing(true, false, localDrpPeer.ConnectedNeighborsBusySectorIds, localDrpPeer.AnotherNeighborToSameSectorExists(newConnectionToNeighbor)); newConnectionToNeighbor.InitialPendingPingRequest = new PendingLowLevelUdpRequest("pingRequest 3850", newConnectionToNeighbor.RemoteEndpoint, PongPacket.GetScanner(newConnectionToNeighbor.LocalNeighborToken32, pingRequest.PingRequestId32), DateTimeNowUtc, Configuration.InitialPingRequests_ExpirationTimeoutS, pingRequest.Encode(), Configuration.InitialPingRequests_InitialRetransmissionTimeoutS, Configuration.InitialPingRequests_RetransmissionTimeoutIncrement ); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending PING neighborToken32={pingRequest.NeighborToken32}, waiting for PONG"); } var pongPacketData = await SendUdpRequestAsync_Retransmit(newConnectionToNeighbor.InitialPendingPingRequest); if (pongPacketData == null) { throw new DrpTimeoutException($"initial reg. requester PING to {newConnectionToNeighbor} (timeout={Configuration.InitialPingRequests_ExpirationTimeoutS}s)"); } if (newConnectionToNeighbor.IsDisposed) { throw new ObjectDisposedException($"initial reg. requester PING to {newConnectionToNeighbor} (special case: connection is disposed)", (Exception)null); // ping timeout already destroyed the connection, so PONG response here is too late } pong = PongPacket.DecodeAndVerify(_cryptoLibrary, pongPacketData, pingRequest, newConnectionToNeighbor, true); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified PONG"); } newConnectionToNeighbor.OnReceivedVerifiedPong(pong, newConnectionToNeighbor.InitialPendingPingRequest.ResponseReceivedAtUtc.Value, newConnectionToNeighbor.InitialPendingPingRequest.ResponseReceivedAtUtc.Value - newConnectionToNeighbor.InitialPendingPingRequest.InitialTxTimeUTC.Value); #endregion } catch { // todo update QoS newConnectionToNeighbor.Dispose(); // remove from token32 table throw; } #region send registration confirmation packet to EP->X->N try { var cfm = new RegisterConfirmationPacket { ReqTimestamp64 = req.ReqTimestamp64, RequesterRegistrationId = localDrpPeer.Configuration.LocalPeerRegistrationId, ResponderRegistrationConfirmationSignature = pong.ResponderRegistrationConfirmationSignature, ReqP2pSeq16 = GetNewNpaSeq16_AtoEP() }; cfm.RequesterRegistrationConfirmationSignature = RegistrationSignature.Sign(_cryptoLibrary, w => newConnectionToNeighbor.GetRequesterRegistrationConfirmationSignatureFields(w, cfm.ResponderRegistrationConfirmationSignature), localDrpPeer.Configuration.LocalPeerRegistrationPrivateKey); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending CFM, waiting for NPACK"); } await OptionallySendUdpRequestAsync_Retransmit_WaitForNeighborPeerAck("cfm 32107", cfm.Encode_OptionallySignNeighborHMAC(null), epEndpoint, cfm.ReqP2pSeq16); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received NPACK to CFM"); } } catch (DrpTimeoutException exc) { // we ingnore exceptions here, just wite warning to log. the connection is alive already, as direct ping channel to neighbor is set up logger.WriteToLog_needsAttention($"... registration confirmation request failed: {exc}"); } catch (Exception exc) { // we ingnore exceptions here, just wite warning to log. the connection is alive already, as direct ping channel to neighbor is set up logger.WriteToLog_mediumPain($"... registration confirmation request failed: {exc}"); } #endregion regSW.Stop(); if (regSW.Elapsed.TotalMilliseconds > 5000) { logger.WriteToLog_lightPain($"registration is completed in {(int)regSW.Elapsed.TotalMilliseconds}ms"); } else { logger.WriteToLog_higherLevelDetail($"registration is completed in {(int)regSW.Elapsed.TotalMilliseconds}ms"); }; return(newConnectionToNeighbor); } finally { localDrpPeer.CurrentRegistrationOperationsCount--; } }
/// <summary> /// Timestamp32S, NeighborToken32 and NeighborHMAC are verified at this time /// </summary> /// <returns> /// true to retry the request with another neighbor (if the request needs to be "rerouted") /// </returns> internal async Task <bool> ProxyInviteRequestAsync(RoutedRequest routedRequest, ConnectionToNeighbor destinationPeer) { var req = routedRequest.InviteReq; var logger = routedRequest.Logger; logger.ModuleName = DrpPeerEngine.VisionChannelModuleName_inv_proxySide; if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"proxying {req} to {destinationPeer}"); } if (!routedRequest.CheckedRecentUniqueProxiedRequests) { if (!Engine.RecentUniqueInviteRequests.Filter(req.GetUniqueRequestIdFields)) { logger.WriteToLog_higherLevelDetail($"rejecting non-unique {req}: requesterEndpoint={routedRequest.ReceivedFromEndpoint}"); await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_routeIsUnavailable); return(false); } routedRequest.CheckedRecentUniqueProxiedRequests = true; } if (req.NumberOfHopsRemaining > InviteRequestPacket.MaxNumberOfHopsRemaining) { await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_routeIsUnavailable); return(false); } if (req.NumberOfHopsRemaining <= 1) { await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_numberOfHopsRemainingReachedZero); return(false); } _pendingInviteRequests.Add(req.RequesterRegistrationId); try { // send NPACK to REQ if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending NPACK to REQ source peer"); } routedRequest.SendNeighborPeerAck_accepted_IfNotAlreadyReplied(); req.NumberOfHopsRemaining--; if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"decremented number of hops in {req}: NumberOfHopsRemaining={req.NumberOfHopsRemaining}"); } // send (proxy) REQ to responder. wait for NPACK, verify NPACK.senderHMAC, retransmit REQ var reqUdpData = req.Encode_SetP2pFields(destinationPeer); #region wait for ACK1 from responder verify NeighborHMAC byte[] ack1UdpData; try { var sentRequest = new SentRequest(Engine, logger, destinationPeer.RemoteEndpoint, destinationPeer, reqUdpData, req.ReqP2pSeq16, InviteAck1Packet.GetScanner(logger, req, destinationPeer)); ack1UdpData = await sentRequest.SendRequestAsync("inv proxy ack1 3457"); } catch (RequestRejectedException reqExc) { logger.WriteToLog_higherLevelDetail($"got response={reqExc.ResponseCode} from destination {destinationPeer}. will try another neighbor.."); if (reqExc.ResponseCode == ResponseOrFailureCode.failure_numberOfHopsRemainingReachedZero) { await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_numberOfHopsRemainingReachedZero); return(false); } if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 75675"); return(false); } if (reqExc.ResponseCode == ResponseOrFailureCode.failure_routeIsUnavailable) { req.NumberOfHopsRemaining++; // roll back previous decrement for a new trial } return(true); // will retry } catch (DrpTimeoutException exc) { logger.WriteToLog_higherLevelDetail($"got timeout error when requesting {destinationPeer}: {exc.Message}"); req.NumberOfHopsRemaining++; // roll back previous decrement for a new trial return(true); // will retry } catch (Exception reqExc) { logger.WriteToLog_mediumPain($"could not proxy INVITE request: {reqExc}"); if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 76897805"); return(false); } return(true); // will retry } var ack1 = InviteAck1Packet.Decode(ack1UdpData); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified ACK1 from responder"); } // respond with NPACK to ACk1 SendNeighborPeerAckResponseToAck1(ack1, destinationPeer); #endregion #region send ACK1 to requester, wait for NPACK and ACK2 var ack1UdpDataTx = ack1.Encode_SetP2pFields(routedRequest.ReceivedFromNeighborNullable); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending ACK1, awaiting for NPACK"); } _ = Engine.OptionallySendUdpRequestAsync_Retransmit_WaitForNeighborPeerAck("ack1 13536", ack1UdpDataTx, routedRequest.ReceivedFromEndpoint, ack1.ReqP2pSeq16, routedRequest.ReceivedFromNeighborNullable, ack1.GetSignedFieldsForNeighborHMAC); // not waiting for NPACK, wait for ACK1 if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"waiting for ACK2"); } var ack2UdpData = await Engine.OptionallySendUdpRequestAsync_Retransmit_WaitForResponse("ack2 2346892", routedRequest.ReceivedFromNeighborNullable?.ToString() ?? routedRequest.ReceivedFromEndpoint.ToString(), null, routedRequest.ReceivedFromEndpoint, InviteAck2Packet.GetScanner(logger, req, routedRequest.ReceivedFromNeighborNullable)); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received ACK2"); } var ack2 = InviteAck2Packet.Decode(ack2UdpData); #endregion // send NPACK to ACK2 if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending NPACK to ACK2 to source peer"); } SendNeighborPeerAckResponseToAck2(ack2, routedRequest.ReceivedFromNeighborNullable); // send ACK2 to responder // put ACK2.ReqP2pSeq16, sendertoken32, senderHMAC // wait for NPACK var ack2UdpDataTx = ack2.Encode_SetP2pFields(destinationPeer); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending ACK2 to responder"); } await destinationPeer.SendUdpRequestAsync_Retransmit_WaitForNPACK("ack2 5344530", ack2UdpDataTx, ack2.ReqP2pSeq16, ack2.GetSignedFieldsForNeighborHMAC); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received NPACK to ACK2 from destination peer"); } // wait for CFM from responder if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"waiting for CFM from responder"); } var cfmUdpData = await Engine.WaitForUdpResponseAsync(new PendingLowLevelUdpRequest("cfm 12358", destinationPeer.RemoteEndpoint, InviteConfirmationPacket.GetScanner(logger, req, destinationPeer), Engine.DateTimeNowUtc, Engine.Configuration.CfmTimoutS )); if (cfmUdpData == null) { throw new DrpTimeoutException($"inv. proxy CFM response from destination peer {destinationPeer} (timeout={Engine.Configuration.CfmTimoutS}s)"); } var cfm = InviteConfirmationPacket.Decode(cfmUdpData); // todo verify signature, update RDRs and QoS if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified CFM from responder"); } // respond NPACK to CFM to destination peer SendNeighborPeerAckResponseToCfm(cfm, destinationPeer); // send CFM to requester var cfmUdpDataTx = cfm.Encode_SetP2pFields(routedRequest.ReceivedFromNeighborNullable); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending CFM to requester, waiting for NPACK"); } await Engine.OptionallySendUdpRequestAsync_Retransmit_WaitForNeighborPeerAck("cfm 23468", cfmUdpDataTx, routedRequest.ReceivedFromEndpoint, cfm.ReqP2pSeq16, routedRequest.ReceivedFromNeighborNullable, cfm.GetSignedFieldsForNeighborHMAC); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received NPACK to CFM from source peer"); } } catch (DrpTimeoutException exc) { logger.WriteToLog_lightPain($"could not proxy INVITE: {exc.Message}"); } catch (Exception exc) { logger.WriteToLog_mediumPain($"could not proxy INVITE request: {exc}"); } finally { _pendingInviteRequests.Remove(req.RequesterRegistrationId); } return(false); }
/// <summary> /// main register responder proc for both A-EP and P2P modes /// in P2P mode NeighborToken32 and NeighborHMAC are verified at this time /// </summary> /// <param name="receivedFromInP2pMode"> /// is null in A-EP mode /// </param> /// <returns> /// true to retry the request with another neighbor (if the request needs to be "rerouted") /// </returns> internal async Task <bool> ProxyRegisterRequestAsync(RoutedRequest routedRequest, ConnectionToNeighbor destinationPeer) // engine thread { routedRequest.ReceivedFromNeighborNullable?.AssertIsNotDisposed(); var req = routedRequest.RegisterReq; var logger = routedRequest.Logger; logger.ModuleName = VisionChannelModuleName_reg_proxySide; if (!ValidateReceivedReqTimestamp64(req.ReqTimestamp64)) { logger.WriteToLog_needsAttention($"rejecting REGISTER request {req.RequesterRegistrationId}: invalid REGISTER REQ 457 ReqTimestamp64={MiscProcedures.Int64ticksToDateTime(req.ReqTimestamp64)}"); // await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_numberOfHopsRemainingReachedZero); return(false); } if (PendingRegisterRequestExists(req.RequesterRegistrationId)) { logger.WriteToLog_higherLevelDetail($"rejecting duplicate request {req}: requesterEndpoint={routedRequest.ReceivedFromEndpoint}"); await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_routeIsUnavailable); return(false); } if (req.NumberOfHopsRemaining > RegisterRequestPacket.MaxNumberOfHopsRemaining || req.NumberOfRandomHopsRemaining > RegisterRequestPacket.MaxNumberOfHopsRemaining) { logger.WriteToLog_needsAttention($"rejecting {req}: invalid number of hops remaining"); await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_routeIsUnavailable); return(false); } if (!routedRequest.CheckedRecentUniqueProxiedRequests) { var recentUniqueProxiedRegistrationRequests = req.RandomModeAtThisHop ? RecentUniqueProxiedRegistrationRequests_RandomHop : RecentUniqueProxiedRegistrationRequests_NonRandomHop; if (!recentUniqueProxiedRegistrationRequests.Filter(req.GetUniqueRequestIdFields)) { logger.WriteToLog_higherLevelDetail($"rejecting non-unique request {req}: requesterEndpoint={routedRequest.ReceivedFromEndpoint}"); await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_routeIsUnavailable); return(false); } routedRequest.CheckedRecentUniqueProxiedRequests = true; } logger.WriteToLog_higherLevelDetail($"proxying {req}: requesterEndpoint={routedRequest.ReceivedFromEndpoint}, NumberOfHopsRemaining={req.NumberOfHopsRemaining}, ReqP2pSeq16={req.ReqP2pSeq16}, destinationPeer={destinationPeer}, sourcePeer={routedRequest.ReceivedFromNeighborNullable}"); if (!ValidateReceivedReqTimestamp64(req.ReqTimestamp64)) { throw new BadSignatureException($"invalid REGISTER REQ ReqTimestamp64={MiscProcedures.Int64ticksToDateTime(req.ReqTimestamp64)} 3507"); } req.NumberOfHopsRemaining--; if (req.NumberOfHopsRemaining == 0) { logger.WriteToLog_needsAttention($"rejecting REGISTER request {req.RequesterRegistrationId}: max hops reached"); await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_numberOfHopsRemainingReachedZero); return(false); } _pendingRegisterRequests.Add(req.RequesterRegistrationId); try { // send NPACK to source peer if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending NPACK to REQ source peer (delay={routedRequest.ReqReceivedSw_ms}ms)"); } routedRequest.SendNeighborPeerAck_accepted_IfNotAlreadyReplied(); if (req.NumberOfRandomHopsRemaining >= 1) { req.NumberOfRandomHopsRemaining--; } if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"decremented number of hops in {req}: NumberOfHopsRemaining={req.NumberOfHopsRemaining}, NumberOfRandomHopsRemaining={req.NumberOfRandomHopsRemaining}"); } req.ReqP2pSeq16 = destinationPeer.GetNewRequestP2pSeq16_P2P(); byte[] ack1UdpData; try { var sentRequest = new SentRequest(this, logger, destinationPeer.RemoteEndpoint, destinationPeer, req.Encode_OptionallySignNeighborHMAC(destinationPeer), req.ReqP2pSeq16, RegisterAck1Packet.GetScanner(logger, req, destinationPeer)); // send (proxy) REQ to responder. wait for NPACK, verify NPACK.senderHMAC, retransmit REQ // wait for ACK1 from destination peer // verify NeighborHMAC // var ack1R = await sentRequest.SendRequestAsync_NoExc("ack1 34601"); ////////////////////////////////// new method ack1UdpData = await sentRequest.SendRequestAsync("ack1 34601"); // if (logger.WriteToLog_detail2_enabled) logger.WriteToLog_detail("got ACK1 result"); if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 52460"); return(false); } if (destinationPeer?.IsDisposed == true) { logger.WriteToLog_needsAttention($"destinationPeer={destinationPeer} is disposed during proxying 52460"); return(false); } //if (ack1R.ResponseCode != ResponseOrFailureCode.accepted) //{ // logger.WriteToLog_higherLevelDetail($"got response={ack1R.ResponseCode} from destination {destinationPeer}"); // if (ack1R.ResponseCode == ResponseOrFailureCode.failure_routeIsUnavailable) // req.NumberOfHopsRemaining++; // roll back previous decrement for a new trial // return true; // will retry //} //ack1UdpData = ack1R.UdpData; } catch (RequestRejectedException reqExc) { logger.WriteToLog_higherLevelDetail($"got exception: response={reqExc.ResponseCode} from destination {destinationPeer}"); if (reqExc.ResponseCode == ResponseOrFailureCode.failure_numberOfHopsRemainingReachedZero) { await routedRequest.SendErrorResponse(ResponseOrFailureCode.failure_numberOfHopsRemainingReachedZero); return(false); } if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 35346232"); return(false); } if (reqExc.ResponseCode == ResponseOrFailureCode.failure_routeIsUnavailable) { req.NumberOfHopsRemaining++; // roll back previous decrement for a new trial } return(true); // will retry } catch (DrpTimeoutException exc) { logger.WriteToLog_higherLevelDetail($"got timeout error when requesting {destinationPeer}: {exc.Message}"); req.NumberOfHopsRemaining++; // roll back previous decrement for a new trial return(true); // will retry } catch (Exception reqExc) { logger.WriteToLog_mediumPain($"could not proxy REGISTER request: {reqExc}"); if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 76897805"); return(false); } return(true); // will retry } var tr1 = CreateTracker("ack1 34601 2"); var ack1 = RegisterAck1Packet.DecodeAndOptionallyVerify(logger, ack1UdpData, req, null); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified ACK1 from destination"); } // respond with NPACK SendNeighborPeerAckResponseToRegisterAck1(ack1, destinationPeer); // send ACK1 to source peer // wait for ACK / NPACK if (routedRequest.ReceivedFromNeighborNullable != null) { // P2P mode routedRequest.ReceivedFromNeighborNullable.AssertIsNotDisposed(); ack1.ReqP2pSeq16 = routedRequest.ReceivedFromNeighborNullable.GetNewRequestP2pSeq16_P2P(); } else { // A-EP mode ack1.RequesterEndpoint = routedRequest.ReceivedFromEndpoint; } var ack1UdpDataTx = ack1.Encode_OpionallySignNeighborHMAC(routedRequest.ReceivedFromNeighborNullable); var sourcePeerVisibleDescription = routedRequest.ReceivedFromNeighborNullable?.ToString() ?? routedRequest.ReceivedFromEndpoint.ToString(); var ack2Scanner = RegisterAck2Packet.GetScanner(logger, routedRequest.ReceivedFromNeighborNullable, req); tr1.Dispose(); byte[] ack2UdpData; if (routedRequest.ReceivedFromNeighborNullable == null) { // A-EP mode: wait for ACK2, retransmitting ACK1 if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending ACK1, waiting for ACK2"); } ack2UdpData = await OptionallySendUdpRequestAsync_Retransmit_WaitForResponse("ack2 12368", sourcePeerVisibleDescription, ack1UdpDataTx, routedRequest.ReceivedFromEndpoint, ack2Scanner); } else { // P2P mode: retransmit ACK1 until NPACK (via P2P); at same time wait for ACK2 if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending ACK1, awaiting for NPACK"); } _ = OptionallySendUdpRequestAsync_Retransmit_WaitForNeighborPeerAck("ack1 3686", ack1UdpDataTx, routedRequest.ReceivedFromEndpoint, ack1.ReqP2pSeq16, routedRequest.ReceivedFromNeighborNullable, ack1.GetSignedFieldsForNeighborHMAC); // not waiting for NPACK, wait for ACK2 if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"waiting for ACK2"); } ack2UdpData = await OptionallySendUdpRequestAsync_Retransmit_WaitForResponse("ack2 345209", sourcePeerVisibleDescription, null, routedRequest.ReceivedFromEndpoint, ack2Scanner); } if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received ACK2"); } if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 2345135"); return(false); } if (destinationPeer?.IsDisposed == true) { logger.WriteToLog_needsAttention($"destinationPeer={destinationPeer} is disposed during proxying 2345135"); return(false); } var ack2 = RegisterAck2Packet.Decode_OptionallyVerify_InitializeP2pStreamAtResponder(logger, ack2UdpData, null, null, null); // send NPACK to source peer if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending NPACK to ACK2 to source peer"); } SendNeighborPeerAckResponseToRegisterAck2(ack2, routedRequest.ReceivedFromEndpoint, routedRequest.ReceivedFromNeighborNullable); // send ACK2 to destination peer // put ACK2.ReqP2pSeq16, sendertoken32, senderHMAC // wait for NPACK if (destinationPeer.IsDisposed == true) { logger.WriteToLog_needsAttention($"destinationPeer={destinationPeer} is disposed during proxying 345784567"); return(false); } if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 345784567"); return(false); } ack2.ReqP2pSeq16 = destinationPeer.GetNewRequestP2pSeq16_P2P(); await destinationPeer.SendUdpRequestAsync_Retransmit_WaitForNPACK("ack2 41937", ack2.Encode_OptionallySignNeighborHMAC(destinationPeer), ack2.ReqP2pSeq16, ack2.GetSignedFieldsForNeighborHMAC); if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 234646"); return(false); } if (destinationPeer?.IsDisposed == true) { logger.WriteToLog_needsAttention($"destinationPeer={destinationPeer} is disposed during proxying 234646"); return(false); } // wait for CFM from source peer var cfmUdpData = await OptionallySendUdpRequestAsync_Retransmit_WaitForResponse("cfm 234789", sourcePeerVisibleDescription, null, routedRequest.ReceivedFromEndpoint, RegisterConfirmationPacket.GetScanner(logger, routedRequest.ReceivedFromNeighborNullable, req) ); var cfm = RegisterConfirmationPacket.DecodeAndOptionallyVerify(cfmUdpData, null, null); if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 3452326"); return(false); } if (destinationPeer?.IsDisposed == true) { logger.WriteToLog_needsAttention($"destinationPeer={destinationPeer} is disposed during proxying 3452326"); return(false); } // TODO verify signatures and update QoS // send NPACK to source peer SendNeighborPeerAckResponseToRegisterCfm(cfm, routedRequest.ReceivedFromEndpoint, routedRequest.ReceivedFromNeighborNullable); // send CFM to responder // wait for NPACK from destination peer, retransmit if (destinationPeer.IsDisposed == true) { logger.WriteToLog_needsAttention($"destinationPeer={destinationPeer} is disposed during proxying 123678"); return(false); } if (routedRequest.ReceivedFromNeighborNullable?.IsDisposed == true) { logger.WriteToLog_needsAttention($"sourcePeer={routedRequest.ReceivedFromNeighborNullable} is disposed during proxying 123678"); return(false); } cfm.ReqP2pSeq16 = destinationPeer.GetNewRequestP2pSeq16_P2P(); await destinationPeer.SendUdpRequestAsync_Retransmit_WaitForNPACK("cfm 1357", cfm.Encode_OptionallySignNeighborHMAC(destinationPeer), cfm.ReqP2pSeq16, cfm.GetSignedFieldsForNeighborHMAC); logger.WriteToLog_higherLevelDetail($"proxying {req} is successfully complete"); } catch (DrpTimeoutException exc) { logger.WriteToLog_lightPain($"could not proxy REGISTER: request timeout: {exc.Message}"); } catch (Exception exc) { logger.WriteToLog_mediumPain($"could not proxy REGISTER request: {exc}"); } finally { _pendingRegisterRequests.Remove(req.RequesterRegistrationId); } return(false); }
/// <summary> /// is used to expand neighborhood /// </summary> internal async Task RegisterAsync(uint minimalDistanceToNeighbor, ushort busySectorIds, byte numberOfHopsRemaining, byte numberOfRandomHopsRemaining, double[] directionVectorNullable, bool allowConnectionsToRequesterRegistrationId) { _engine.WriteToLog_reg_requesterSide_detail($">> ConnectionToNeighbor.RegisterAsync(minimalDistanceToNeighbor={minimalDistanceToNeighbor}", null, null); _localDrpPeer.CurrentRegistrationOperationsCount++; try { var newConnectionToNeighbor = new ConnectionToNeighbor(_engine, _localDrpPeer, ConnectedDrpPeerInitiatedBy.localPeer, null); PongPacket pong; // PendingLowLevelUdpRequest pendingPingRequest; var req = new RegisterRequestPacket { RequesterRegistrationId = _localDrpPeer.Configuration.LocalPeerRegistrationId, ReqTimestamp64 = _engine.Timestamp64, MinimalDistanceToNeighbor = minimalDistanceToNeighbor, RequesterNatBehaviour = _engine.LocalNatBehaviour, AllowConnectionsToRequesterRegistrationId = allowConnectionsToRequesterRegistrationId, RequesterNeighborsBusySectorIds = busySectorIds, NumberOfHopsRemaining = numberOfHopsRemaining, NumberOfRandomHopsRemaining = numberOfRandomHopsRemaining, RequesterEcdhePublicKey = new EcdhPublicKey(newConnectionToNeighbor.LocalEcdhe25519PublicKey), ReqP2pSeq16 = GetNewRequestP2pSeq16_P2P(), EpEndpoint = this.RemoteEndpoint, DirectionVectorNullableD = directionVectorNullable }; var logger = new Logger(Engine, LocalDrpPeer, req, DrpPeerEngine.VisionChannelModuleName_reg_requesterSide); try { _engine.RecentUniquePublicEcdhKeys.AssertIsUnique(req.RequesterEcdhePublicKey.Ecdh25519PublicKey, $"req.RequesterEcdhePublicKey {req}"); req.RequesterSignature = RegistrationSignature.Sign(_engine.CryptoLibrary, w => req.GetSharedSignedFields(w, false), _localDrpPeer.Configuration.LocalPeerRegistrationPrivateKey ); var reqToAck1Stopwatch = Stopwatch.StartNew(); #region wait for ACK1, respond with NPACK if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending {req}, waiting for NPACK. ReqP2pSeq16={req.ReqP2pSeq16}"); } var sentRequest = new SentRequest(Engine, logger, this.RemoteEndpoint, this, req.Encode_OptionallySignNeighborHMAC(this), req.ReqP2pSeq16, RegisterAck1Packet.GetScanner(logger, req, this)); var ack1UdpData = await sentRequest.SendRequestAsync("reg req ack1 42084"); var ack1 = RegisterAck1Packet.DecodeAndOptionallyVerify(logger, ack1UdpData, req, newConnectionToNeighbor); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified ACK1, sending NPACK to ACK1"); } _engine.SendNeighborPeerAckResponseToRegisterAck1(ack1, this); #endregion if (newConnectionToNeighbor.IsDisposed) { logger.WriteToLog_needsAttention($"connection {newConnectionToNeighbor} is disposed during reg. request 5345322345"); return; } if (IsDisposed) { logger.WriteToLog_needsAttention($"connection {this} is disposed during reg. request 5345322345"); return; } _engine.RecentUniquePublicEcdhKeys.AssertIsUnique(ack1.ResponderEcdhePublicKey.Ecdh25519PublicKey, $"ack1.ResponderEcdhePublicKey from {newConnectionToNeighbor}"); newConnectionToNeighbor.LocalEndpoint = this.LocalEndpoint; newConnectionToNeighbor.RemoteRegistrationId = ack1.ResponderRegistrationId; reqToAck1Stopwatch.Stop(); var reqToAck1TimeMs = reqToAck1Stopwatch.Elapsed.TotalMilliseconds; if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"measured REQ-ACK1 RTT = {(int)reqToAck1TimeMs}ms"); } #region send ACK2, encode local IP var ack2 = new RegisterAck2Packet { ReqTimestamp64 = req.ReqTimestamp64, RequesterRegistrationId = _localDrpPeer.Configuration.LocalPeerRegistrationId, ReqP2pSeq16 = GetNewRequestP2pSeq16_P2P(), }; ack2.ToRequesterTxParametersEncrypted = newConnectionToNeighbor.Encrypt_ack2_ToRequesterTxParametersEncrypted_AtRequester(logger, req, ack1, ack2); newConnectionToNeighbor.InitializeP2pStream(req, ack1, ack2); ack2.RequesterSignature = RegistrationSignature.Sign(_engine.CryptoLibrary, w => { req.GetSharedSignedFields(w, true); ack1.GetSharedSignedFields(w, true, true); ack2.GetSharedSignedFields(w, false, true); }, _localDrpPeer.Configuration.LocalPeerRegistrationPrivateKey ); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending ACK2 (in response to ACK1), waiting for NPACK"); } await _engine.OptionallySendUdpRequestAsync_Retransmit_WaitForNeighborPeerAck("ack2 1235739", ack2.Encode_OptionallySignNeighborHMAC(this), this.RemoteEndpoint, ack2.ReqP2pSeq16); #endregion var neighborWaitTimeMs = reqToAck1TimeMs * 0.5 - 100; if (neighborWaitTimeMs < 0) { neighborWaitTimeMs = 0; } if (neighborWaitTimeMs > 20) { await _engine.EngineThreadQueue.WaitAsync(TimeSpan.FromMilliseconds(neighborWaitTimeMs), "neighborWaitTimeMs45236"); // wait until the ACK2 reaches neighbor N via peers } if (newConnectionToNeighbor.IsDisposed) { logger.WriteToLog_needsAttention($"connection {newConnectionToNeighbor} is disposed during reg. request 234574568"); return; } if (IsDisposed) { logger.WriteToLog_needsAttention($"connection {this} is disposed during reg. request 234574568"); return; } _localDrpPeer.AddToConnectedNeighbors(newConnectionToNeighbor, req); #region send ping request directly to neighbor N, retransmit var pingRequest = newConnectionToNeighbor.CreatePing(true, false, _localDrpPeer.ConnectedNeighborsBusySectorIds, _localDrpPeer.AnotherNeighborToSameSectorExists(newConnectionToNeighbor)); newConnectionToNeighbor.InitialPendingPingRequest = new PendingLowLevelUdpRequest("pendingPingRequest 12247", newConnectionToNeighbor.RemoteEndpoint, PongPacket.GetScanner(newConnectionToNeighbor.LocalNeighborToken32, pingRequest.PingRequestId32), _engine.DateTimeNowUtc, _engine.Configuration.InitialPingRequests_ExpirationTimeoutS, pingRequest.Encode(), _engine.Configuration.InitialPingRequests_InitialRetransmissionTimeoutS, _engine.Configuration.InitialPingRequests_RetransmissionTimeoutIncrement ); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending PING, waiting for PONG"); } var pongPacketData = await _engine.SendUdpRequestAsync_Retransmit(newConnectionToNeighbor.InitialPendingPingRequest); if (pongPacketData == null) { throw new DrpTimeoutException($"reg. requester initial PING to {newConnectionToNeighbor} (timeout={_engine.Configuration.InitialPingRequests_ExpirationTimeoutS}s)"); } if (newConnectionToNeighbor.IsDisposed) { logger.WriteToLog_needsAttention($"connection {newConnectionToNeighbor} is disposed during reg. request 548798"); return; } if (IsDisposed) { logger.WriteToLog_needsAttention($"connection {this} is disposed during reg. request 548798"); return; } pong = PongPacket.DecodeAndVerify(_engine.CryptoLibrary, pongPacketData, pingRequest, newConnectionToNeighbor, true); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"verified PONG"); } newConnectionToNeighbor.OnReceivedVerifiedPong(pong, newConnectionToNeighbor.InitialPendingPingRequest.ResponseReceivedAtUtc.Value, newConnectionToNeighbor.InitialPendingPingRequest.ResponseReceivedAtUtc.Value - newConnectionToNeighbor.InitialPendingPingRequest.InitialTxTimeUTC.Value); #endregion } catch { // todo update QoS newConnectionToNeighbor.Dispose(); // remove from token32 table throw; } #region send registration confirmation packet to X->N try { if (newConnectionToNeighbor.IsDisposed) { logger.WriteToLog_needsAttention($"connection {newConnectionToNeighbor} is disposed during reg. request 541687987"); return; } if (IsDisposed) { logger.WriteToLog_needsAttention($"connection {this} is disposed during reg. request 541687987"); return; } var cfm = new RegisterConfirmationPacket { ReqTimestamp64 = req.ReqTimestamp64, RequesterRegistrationId = _localDrpPeer.Configuration.LocalPeerRegistrationId, ResponderRegistrationConfirmationSignature = pong.ResponderRegistrationConfirmationSignature, ReqP2pSeq16 = GetNewRequestP2pSeq16_P2P() }; cfm.RequesterRegistrationConfirmationSignature = RegistrationSignature.Sign(_engine.CryptoLibrary, w => newConnectionToNeighbor.GetRequesterRegistrationConfirmationSignatureFields(w, cfm.ResponderRegistrationConfirmationSignature), _localDrpPeer.Configuration.LocalPeerRegistrationPrivateKey); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending CFM, waiting for NPACK"); } await _engine.OptionallySendUdpRequestAsync_Retransmit_WaitForNeighborPeerAck("cfm 14478", cfm.Encode_OptionallySignNeighborHMAC(this), this.RemoteEndpoint, cfm.ReqP2pSeq16); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received NPACK to CFM"); } } catch (DrpTimeoutException exc) { // we ingnore exceptions here, just wite warning to log. the connection is alive already, as direct ping channel to neighbor is set up logger.WriteToLog_needsAttention($"... registration confirmation request failed: {exc}"); } catch (Exception exc) { // we ingnore exceptions here, just wite warning to log. the connection is alive already, as direct ping channel to neighbor is set up logger.WriteToLog_mediumPain($"... registration confirmation request failed: {exc}"); } #endregion return;// newConnectionToNeighbor; } finally { _localDrpPeer.CurrentRegistrationOperationsCount--; } }
const ushort Magic16_responderToRequester = 0x60C1; // is used to validate decrypted data /// <summary> /// when sending ACK1 /// </summary> public byte[] Encrypt_ack1_ToResponderTxParametersEncrypted_AtResponder_DeriveSharedDhSecret(Logger logger, RegisterRequestPacket req, RegisterAck1Packet ack1, ConnectionToNeighbor neighbor) { IPEndPoint localResponderEndpoint; if (neighbor != null) { localResponderEndpoint = neighbor.LocalEndpoint; } else { localResponderEndpoint = req.EpEndpoint; } if (localResponderEndpoint.Address.AddressFamily != System.Net.Sockets.AddressFamily.InterNetwork) { throw new NotImplementedException(); } SharedDhSecret = _engine.CryptoLibrary.DeriveEcdh25519SharedSecret(LocalEcdhe25519PrivateKey, req.RequesterEcdhePublicKey.Ecdh25519PublicKey); #region key, iv PacketProcedures.CreateBinaryWriter(out var ms, out var writer); req.GetSharedSignedFields(writer, true); ack1.GetSharedSignedFields(writer, false, false); var iv = _engine.CryptoLibrary.GetHashSHA256(ms.ToArray()).Take(16).ToArray();; ms.Write(SharedDhSecret, 0, SharedDhSecret.Length); var aesKey = _engine.CryptoLibrary.GetHashSHA256(ms.ToArray()); // here SHA256 is used as KDF, together with common fields from packets, including both ECDH public keys and timestamp #endregion // encode localRxParameters PacketProcedures.CreateBinaryWriter(out var msRxParameters, out var wRxParameters); PacketProcedures.EncodeIPEndPoint(wRxParameters, localResponderEndpoint); // max 19 LocalNeighborToken32.Encode(wRxParameters); // +4 max 23 if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"encrypting local responder endpoint={localResponderEndpoint}, localNeighborToken={LocalNeighborToken32} into ACK1"); } wRxParameters.Write(Magic16_responderToRequester); // +2 max 25 var bytesRemaining = RegisterAck1Packet.ToResponderTxParametersEncryptedLength - (int)msRxParameters.Length; wRxParameters.Write(_engine.CryptoLibrary.GetRandomBytes(bytesRemaining)); var localRxParametersDecrypted = msRxParameters.ToArray(); // total 16 bytes var localRxParametersEncrypted = new byte[localRxParametersDecrypted.Length]; _engine.CryptoLibrary.ProcessAesCbcBlocks(true, aesKey, iv, localRxParametersDecrypted, localRxParametersEncrypted); if (localRxParametersEncrypted.Length != RegisterAck1Packet.ToResponderTxParametersEncryptedLength) { throw new Exception(); } return(localRxParametersEncrypted); }
/// <param name="waitNhaFromNeighborNullable">is used to verify NPACK.NeighborHMAC</param> internal async Task <NeighborPeerAckPacket> OptionallySendUdpRequestAsync_Retransmit_WaitForNeighborPeerAck(string completionActionVisibleId, byte[] requestPacketDataNullable, IPEndPoint responderEndpoint, RequestP2pSequenceNumber16 reqP2pSeq16, ConnectionToNeighbor waitNhaFromNeighborNullable = null, Action <BinaryWriter> npaRequestFieldsForNeighborHmacNullable = null) { var npaScanner = NeighborPeerAckPacket.GetScanner(reqP2pSeq16, waitNhaFromNeighborNullable, npaRequestFieldsForNeighborHmacNullable); if (WriteToLog_udp_deepDetail_enabled) { WriteToLog_udp_deepDetail($"waiting for NPACK, scanner: {MiscProcedures.ByteArrayToString(npaScanner.ResponseFirstBytes)} npaSeq={reqP2pSeq16}"); } var nextHopResponsePacketData = await SendUdpRequestAsync_Retransmit( new PendingLowLevelUdpRequest(completionActionVisibleId, responderEndpoint, npaScanner, DateTimeNowUtc, Configuration.UdpLowLevelRequests_ExpirationTimeoutS, requestPacketDataNullable, Configuration.UdpLowLevelRequests_InitialRetransmissionTimeoutS, Configuration.UdpLowLevelRequests_RetransmissionTimeoutIncrement )); if (nextHopResponsePacketData == null) { string desc = "no NPACK response to DRP request '"; if (requestPacketDataNullable != null) { desc += (PacketTypes)requestPacketDataNullable[0]; } desc += $"' - timeout expired ({Configuration.UdpLowLevelRequests_ExpirationTimeoutS}s) completionAction={completionActionVisibleId}"; if (waitNhaFromNeighborNullable != null) { desc += $", neighbor={waitNhaFromNeighborNullable}"; } throw new DrpTimeoutException(desc); } var nextHopResponsePacket = new NeighborPeerAckPacket(nextHopResponsePacketData); if (nextHopResponsePacket.ResponseCode != ResponseOrFailureCode.accepted) { if (WriteToLog_udp_deepDetail_enabled) { WriteToLog_udp_deepDetail($"got NPACK with {nextHopResponsePacket.ResponseCode} throwing exception"); } throw new RequestRejectedException(nextHopResponsePacket.ResponseCode); } return(nextHopResponsePacket); }
/// <summary> /// main routing procedure for register REQ requests /// </summary> /// <param name="receivedAtLocalDrpPeerNullable"> /// is set when routing REQ packets that are received via P2P connection from neighbor to the LocalDrpPeer /// is null in A-EP mode /// </param> internal bool RouteRegistrationRequest(LocalDrpPeer receivedAtLocalDrpPeerNullable, RoutedRequest routedRequest, out ConnectionToNeighbor proxyToDestinationPeer, out LocalDrpPeer acceptAt) { proxyToDestinationPeer = null; acceptAt = null; var req = routedRequest.RegisterReq; var logger = routedRequest.Logger; if (req.NumberOfHopsRemaining <= 1) { var possibleAcceptAt = receivedAtLocalDrpPeerNullable ?? routedRequest.ReceivedFromNeighborNullable?.LocalDrpPeer; if (possibleAcceptAt == null) { possibleAcceptAt = LocalPeers.Values.Where(x => x.Configuration.LocalPeerRegistrationId.Equals(req.RequesterRegistrationId) == false).FirstOrDefault(); } if (possibleAcceptAt != null) { if (!possibleAcceptAt.ConnectedNeighbors.Any(x => x.RemoteRegistrationId.Equals(req.RequesterRegistrationId))) { logger.WriteToLog_routing_higherLevelDetail($"accepting registration request {req.RequesterRegistrationId} at local DRP peer {acceptAt}: low number of hops remaining"); acceptAt = possibleAcceptAt; return(true); } else { logger.WriteToLog_routing_higherLevelDetail($"not accepting registration at local DRP peer" + $" {acceptAt} when low number of hops remaining: already connected"); } } } if (req.RandomModeAtThisHop) { // random mode var itemsForRouting = new List <object>(); if (routedRequest.ReceivedFromNeighborNullable == null) { foreach (var localDrpPeer in LocalPeers.Values) { itemsForRouting.AddRange(localDrpPeer.GetConnectedNeighborsForRouting(routedRequest)); if (!localDrpPeer.Configuration.LocalPeerRegistrationId.Equals(req.RequesterRegistrationId)) { itemsForRouting.Add(localDrpPeer); } } } else { itemsForRouting.AddRange(routedRequest.ReceivedFromNeighborNullable.LocalDrpPeer.GetConnectedNeighborsForRouting(routedRequest)); if (!routedRequest.ReceivedFromNeighborNullable.LocalDrpPeer.Configuration.LocalPeerRegistrationId.Equals(req.RequesterRegistrationId)) { itemsForRouting.Add(routedRequest.ReceivedFromNeighborNullable.LocalDrpPeer); } } if (itemsForRouting.Count != 0) { var itemForRouting = itemsForRouting[_insecureRandom.Next(itemsForRouting.Count - 1)]; logger.WriteToLog_routing_higherLevelDetail($"routing registration in random mode to one of {itemsForRouting.Count} destinations: {proxyToDestinationPeer}"); if (itemForRouting is ConnectionToNeighbor) { proxyToDestinationPeer = (ConnectionToNeighbor)itemForRouting; } else { acceptAt = (LocalDrpPeer)itemForRouting; } } else { logger.WriteToLog_routing_needsAttention($"can not route registration in random mode: no destinations available including local peers"); } } else { double?maxP2pConnectionValue = null; if (receivedAtLocalDrpPeerNullable != null) { RouteRegistrationRequest_LocalDrpPeerIteration(receivedAtLocalDrpPeerNullable, routedRequest, ref maxP2pConnectionValue, ref proxyToDestinationPeer, ref acceptAt); } else { foreach (var localDrpPeer in LocalPeers.Values) { RouteRegistrationRequest_LocalDrpPeerIteration(localDrpPeer, routedRequest, ref maxP2pConnectionValue, ref proxyToDestinationPeer, ref acceptAt); } } } if (proxyToDestinationPeer != null) { logger.WriteToLog_routing_higherLevelDetail($"proxying registration to {proxyToDestinationPeer}"); return(true); } else if (acceptAt != null) { logger.WriteToLog_routing_higherLevelDetail($"accepting registration at local DRP peer {acceptAt}"); return(true); } else { logger.WriteToLog_routing_higherLevelDetail($"no route found for REGISTER request to {req.RequesterRegistrationId}"); return(false); } }
void RouteRegistrationRequest_LocalDrpPeerIteration(LocalDrpPeer localDrpPeer, RoutedRequest routedRequest, ref double?maxP2pConnectionValue, ref ConnectionToNeighbor proxyToDestinationPeer, ref LocalDrpPeer acceptAt) { var req = routedRequest.RegisterReq; var connectedNeighborsForRouting = localDrpPeer.GetConnectedNeighborsForRouting(routedRequest).ToList(); var logger = routedRequest.Logger; var distancesToNeighbors = new List <RegistrationIdDistance>(); var requestedDirectionMulResults = new List <double>(); int connectedNeighborsCountThatMatchReqFilters = 0; foreach (var neighbor in connectedNeighborsForRouting) { if (req.MinimalDistanceToNeighbor != 0) { var distanceToNeighbor = req.RequesterRegistrationId.GetDistanceTo(_cryptoLibrary, neighbor.RemoteRegistrationId, NumberOfDimensions); distancesToNeighbors.Add(distanceToNeighbor); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"distanceToNeighbor={distanceToNeighbor} from REGISTER REQ {req.RequesterRegistrationId} to {neighbor} (req.min={req.MinimalDistanceToNeighbor})"); } if (distanceToNeighbor.IsLessThan(req.MinimalDistanceToNeighbor)) { // skip: this is too close than requested if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"skipping connection to {neighbor}: distance={distanceToNeighbor} is less than requested={req.MinimalDistanceToNeighbor}"); } continue; } } if (req.DirectionVectorNullable != null) { var requestedDirectionVector = req.DirectionVectorNullableD; var vectorFromThisToNeighbor = RegistrationId.GetDifferenceVector(req.RequesterRegistrationId, neighbor.RemoteRegistrationId, CryptoLibrary, Configuration.SandboxModeOnly_NumberOfDimensions); double mulResult = 0; for (int i = 0; i < requestedDirectionVector.Length; i++) { mulResult += requestedDirectionVector[i] * requestedDirectionVector[i]; } requestedDirectionMulResults.Add(mulResult); if (mulResult < 0) { if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"skipping connection to {neighbor}: direction from requester to neighbor does not match requested vector"); } continue; } } connectedNeighborsCountThatMatchReqFilters++; var p2pConnectionValue_withNeighbor = P2pConnectionValueCalculator.GetMutualP2pConnectionValue(CryptoLibrary, req.RequesterRegistrationId, req.RequesterNeighborsBusySectorIds, neighbor.RemoteRegistrationId, neighbor.RemoteNeighborsBusySectorIds ?? 0, NumberOfDimensions, false, false, false); if (logger.WriteToLog_deepDetail_enabled) { logger.WriteToLog_deepDetail($"p2pConnectionValue_withNeighbor={p2pConnectionValue_withNeighbor} from REGISTER REQ {req.RequesterRegistrationId} to {neighbor}"); } if (maxP2pConnectionValue == null || maxP2pConnectionValue < p2pConnectionValue_withNeighbor) { maxP2pConnectionValue = p2pConnectionValue_withNeighbor; proxyToDestinationPeer = neighbor; acceptAt = null; } } if (connectedNeighborsCountThatMatchReqFilters == 0 && connectedNeighborsForRouting.Count != 0) { if (req.MinimalDistanceToNeighbor != 0) { // special case: we are inside the "minDistance" hypersphere: move away from the requester, proxy to most distant neighbor if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"special case: move away from the requester, proxy to most distant neighbor"); } RegistrationIdDistance maxDistance = null; for (int i = 0; i < connectedNeighborsForRouting.Count; i++) { var neighbor = connectedNeighborsForRouting[i]; var distanceToNeighbor = distancesToNeighbors[i]; if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"distanceToConnectedPeer={distanceToNeighbor} from REGISTER REQ {req.RequesterRegistrationId} to {neighbor} (req.min={req.MinimalDistanceToNeighbor})"); } if (maxDistance == null || distanceToNeighbor.IsGreaterThan(maxDistance)) { maxDistance = distanceToNeighbor; proxyToDestinationPeer = neighbor; acceptAt = null; } } } if (req.DirectionVectorNullable != null) { if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"special case: move towards the specified direction"); } double?maxMulResult = null; for (int i = 0; i < connectedNeighborsForRouting.Count; i++) { var neighbor = connectedNeighborsForRouting[i]; var mulResult = requestedDirectionMulResults[i]; if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"mulResult={mulResult} for {neighbor}"); } if (maxMulResult == null || mulResult > maxMulResult) { maxMulResult = mulResult; proxyToDestinationPeer = neighbor; acceptAt = null; } } } } // dont connect to local peer if already connected if (localDrpPeer.Configuration.LocalPeerRegistrationId.Equals(req.RequesterRegistrationId) == true) { if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"not accepting request at local peer: it has same regID {req.RequesterRegistrationId}"); } } else if (localDrpPeer.ConnectedNeighbors.Any(x => x.RemoteRegistrationId.Equals(req.RequesterRegistrationId)) == true) { if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"not accepting request at local peer: already connected to {req.RequesterRegistrationId}"); } } else if (localDrpPeer.ConnectedNeighbors.Count > localDrpPeer.Configuration.AbsoluteMaxNumberOfNeighbors) { if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"not accepting request at local peer: already too many neighbors ({localDrpPeer.ConnectedNeighbors.Count})"); } } else { var p2pConnectionValue_withLocalPeer = P2pConnectionValueCalculator.GetMutualP2pConnectionValue(CryptoLibrary, req.RequesterRegistrationId, req.RequesterNeighborsBusySectorIds, localDrpPeer.Configuration.LocalPeerRegistrationId, localDrpPeer.ConnectedNeighborsBusySectorIds, NumberOfDimensions, false, false, false); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"p2pConnectionValue_withLocalPeer={p2pConnectionValue_withLocalPeer} from REGISTER REQ {req.RequesterRegistrationId} to {localDrpPeer.Configuration.LocalPeerRegistrationId}"); } if (maxP2pConnectionValue == null || p2pConnectionValue_withLocalPeer > maxP2pConnectionValue) { maxP2pConnectionValue = p2pConnectionValue_withLocalPeer; proxyToDestinationPeer = null; acceptAt = localDrpPeer; } } if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"<< RouteRegistrationRequest_LocalDrpPeerIteration() proxyTo={proxyToDestinationPeer}, acceptAt={acceptAt}"); } }