/// <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); } }
/// <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> /// Timestamp32S, NeighborToken32 and NeighborHMAC are verified at this time /// </summary> internal async Task AcceptInviteRequestAsync(RoutedRequest routedRequest) { if (routedRequest.ReceivedFromNeighborNullable == null) { throw new ArgumentException(); } var req = routedRequest.InviteReq; if (!req.ResponderRegistrationId.Equals(this.Configuration.LocalPeerRegistrationId)) { throw new ArgumentException(); } var logger = routedRequest.Logger; logger.ModuleName = DrpPeerEngine.VisionChannelModuleName_inv_responderSide; if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"accepting {req} from sourcePeer={routedRequest.ReceivedFromNeighborNullable}"); } // check if regID exists in contact book, get userID from the local contact book // ignore the REQ packet if no such user in contacts this._drpPeerApp.OnReceivedInvite(req.RequesterRegistrationId, req.ContactInvitationTokenNullable, out var remoteRequesterUserIdFromLocalContactBookNullable, out var localUserCertificateWithPrivateKey, out var autoReply); if (autoReply == false) { if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_needsAttention($"ignored invite: autoReply = false"); } return; } localUserCertificateWithPrivateKey?.AssertHasPrivateKey(); if (remoteRequesterUserIdFromLocalContactBookNullable != null) { if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"resolved user {remoteRequesterUserIdFromLocalContactBookNullable} by requester regID={req.RequesterRegistrationId}"); } } if (!Engine.RecentUniquePublicEcdhKeys.Filter(req.RequesterEcdhePublicKey.Ecdh25519PublicKey)) { logger.WriteToLog_mediumPain($"RequesterEcdhePublicKey {req.RequesterEcdhePublicKey} is not unique, it has been recently processed"); return; } if (!Engine.RecentUniqueInviteRequests.Filter(req.GetUniqueRequestIdFields)) { logger.WriteToLog_mediumPain($"{req} fields are not unique, the request has been recently processed"); return; } // verify requester reg. signature if (!req.RequesterRegistrationSignature.Verify(Engine.CryptoLibrary, req.GetSharedSignedFields, req.RequesterRegistrationId)) { throw new BadSignatureException("invalid INVITE REQ RequesterRegistrationSignature 2349"); } _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(); var session = new InviteSession(this) { Logger = logger }; try { session.DeriveSharedInviteAckDhSecret(Engine.CryptoLibrary, req.RequesterEcdhePublicKey.Ecdh25519PublicKey); session.LocalSessionDescription = new InviteSessionDescription { DirectChannelEndPoint = routedRequest.ReceivedFromNeighborNullable.LocalEndpoint, NatBehaviour = Engine.LocalNatBehaviour, DirectChannelToken32 = session.LocalDirectChannelToken32 }; if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"responding with local session {session.LocalSessionDescription}"); } session.LocalSessionDescription.UserCertificate = localUserCertificateWithPrivateKey; #region send ACK1. sign local SD by local user var ack1 = new InviteAck1Packet { ReqTimestamp32S = req.ReqTimestamp32S, RequesterRegistrationId = req.RequesterRegistrationId, ResponderRegistrationId = req.ResponderRegistrationId, ResponderEcdhePublicKey = new EcdhPublicKey(session.LocalInviteAckEcdhePublicKey), }; session.LocalSessionDescription.UserCertificateSignature = UserCertificateSignature.Sign(Engine.CryptoLibrary, w => { req.GetSharedSignedFields(w); ack1.GetSharedSignedFields(w, false); session.LocalSessionDescription.WriteSignedFields(w); }, localUserCertificateWithPrivateKey); ack1.ToResponderSessionDescriptionEncrypted = session.LocalSessionDescription.Encrypt(Engine.CryptoLibrary, req, ack1, session, false); ack1.ResponderRegistrationSignature = RegistrationSignature.Sign(Engine.CryptoLibrary, w => { req.GetSharedSignedFields(w); ack1.GetSharedSignedFields(w, true); }, this.Configuration.LocalPeerRegistrationPrivateKey ); var ack1UdpData = ack1.Encode_SetP2pFields(routedRequest.ReceivedFromNeighborNullable); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending ACK1 to source peer, awaiting for NPACK"); } _ = routedRequest.ReceivedFromNeighborNullable.SendUdpRequestAsync_Retransmit_WaitForNPACK("ack1 1450", ack1UdpData, ack1.ReqP2pSeq16, ack1.GetSignedFieldsForNeighborHMAC); // not waiting for NPACK, wait for ACK2 #endregion // wait for ACK2 if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"waiting for ACK2"); } var ack2UdpData = await Engine.OptionallySendUdpRequestAsync_Retransmit_WaitForResponse("ack2 23467789", routedRequest.ReceivedFromNeighborNullable.ToString(), null, routedRequest.ReceivedFromNeighborNullable.RemoteEndpoint, InviteAck2Packet.GetScanner(logger, req, routedRequest.ReceivedFromNeighborNullable)); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received ACK2"); } var ack2 = InviteAck2Packet.Decode(ack2UdpData); if (!ack2.RequesterRegistrationSignature.Verify(Engine.CryptoLibrary, w => { req.GetSharedSignedFields(w); ack1.GetSharedSignedFields(w, true); ack2.GetSharedSignedFields(w); }, req.RequesterRegistrationId)) { throw new BadSignatureException("invalid INVITE ACK2 RequesterRegistrationSignature 2348"); } // decrypt, verify SD remote user's certificate and signature session.RemoteSessionDescription = InviteSessionDescription.Decrypt_Verify(Engine.CryptoLibrary, ack2.ToRequesterSessionDescriptionEncrypted, req, ack1, true, session, remoteRequesterUserIdFromLocalContactBookNullable, Engine.DateTimeNowUtc); session.LocalSessionDescription.SessionType = session.RemoteSessionDescription.SessionType; switch (session.RemoteSessionDescription.SessionType) { case SessionType.asyncShortSingleMessage: break; case SessionType.ike1: if (_drpPeerApp.OnReceivedInvite_GetLocalIke1Data(req.ContactInvitationTokenNullable) == null) { throw new BadSignatureException("bad ContactInvitationToken 21379"); } break; default: throw new NotImplementedException(); } // send NPACK to ACK2 if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending NPACK to ACK2 to source peer"); } SendNeighborPeerAckResponseToAck2(ack2, routedRequest.ReceivedFromNeighborNullable); // send CFM with signature var cfm = new InviteConfirmationPacket { ReqTimestamp32S = req.ReqTimestamp32S, RequesterRegistrationId = req.RequesterRegistrationId, ResponderRegistrationId = req.ResponderRegistrationId, }; cfm.ResponderRegistrationSignature = RegistrationSignature.Sign(Engine.CryptoLibrary, w => { req.GetSharedSignedFields(w); ack1.GetSharedSignedFields(w, true); ack2.GetSharedSignedFields(w); }, this.Configuration.LocalPeerRegistrationPrivateKey); var cfmUdpData = cfm.Encode_SetP2pFields(routedRequest.ReceivedFromNeighborNullable); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"sending CFM to source peer, waiting for NPACK"); } await routedRequest.ReceivedFromNeighborNullable.SendUdpRequestAsync_Retransmit_WaitForNPACK("cfm 49146", cfmUdpData, cfm.ReqP2pSeq16, cfm.GetSignedFieldsForNeighborHMAC); if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"received NPACK to CFM"); } session.DeriveSharedPingPongHmacKey(req, ack1, ack2, cfm); await session.SetupAEkeysAsync(); } catch { session.Dispose(); throw; } if (autoReply) { switch (session.RemoteSessionDescription.SessionType) { case SessionType.asyncShortSingleMessage: if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"autoReply=true: receiving message"); } _ = ReceiveShortSingleMessageAsync(session, req); break; case SessionType.ike1: if (logger.WriteToLog_detail_enabled) { logger.WriteToLog_detail($"autoReply=true: starting IKE1"); } _ = Ike1Async_AtInviteResponder(session, req); break; default: throw new NotImplementedException(); } } else { session.Dispose(); // todo implement other cases } } catch (DrpTimeoutException exc) { logger.WriteToLog_lightPain($"could not accept INVITE request: {exc}"); } catch (Exception exc) { logger.WriteToLog_mediumPain($"could not accept INVITE request: {exc}"); } finally { _pendingInviteRequests.Remove(req.RequesterRegistrationId); } }
/// <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); }