From d910da01571396220e0c65d74f394a3c7b0c3390 Mon Sep 17 00:00:00 2001 From: Michael Kirk Date: Tue, 11 Jul 2017 15:42:05 -0400 Subject: [PATCH 1/4] Partial revert of: Send ICE updates immediately - 2dcfb4e3b8b07bb2b5419cad6fa324e5e585c3da That change makes it more likely that the remote client will receive an ICE update before their peer connection client is set. We want to ship the robustness fix (waitForPeerConnection in handleRemoteAddedIceCandidate) before we have the caller start sending ICE updates immediately, in a future release. At that time, we can simply revert this commit. // FREEBIE --- Signal/src/call/CallService.swift | 45 +++++++++++++++++++++++++++++-- 1 file changed, 43 insertions(+), 2 deletions(-) diff --git a/Signal/src/call/CallService.swift b/Signal/src/call/CallService.swift index 6a1bb46fd..9363e6be8 100644 --- a/Signal/src/call/CallService.swift +++ b/Signal/src/call/CallService.swift @@ -160,6 +160,17 @@ protocol CallServiceObserver: class { // Used to coordinate promises across delegate methods private var fulfillCallConnectedPromise: (() -> Void)? + /** + * In the process of establishing a connection between the clients (ICE process) we must exchange ICE updates. + * Because this happens via Signal Service it's possible the callee user has not accepted any change in the caller's + * identity. In which case *each* ICE update would cause an "identity change" warning on the callee's device. Since + * this could be several messages, the caller stores all ICE updates until receiving positive confirmation that the + * callee has received a message from us. This positive confirmation comes in the form of the callees `CallAnswer` + * message. + */ + var sendIceUpdatesImmediately = true + var pendingIceUpdateMessages = [OWSCallIceUpdateMessage]() + // Used by waitForPeerConnectionClient to make sure any received // ICE messages wait until the peer connection client is set up. private var fulfillPeerConnectionClientPromise: (() -> Void)? @@ -260,6 +271,9 @@ protocol CallServiceObserver: class { self.call = call + sendIceUpdatesImmediately = false + pendingIceUpdateMessages = [] + let callRecord = TSCall(timestamp: NSDate.ows_millisecondTimeStamp(), withCallNumber: call.remotePhoneNumber, callType: RPRecentCallTypeOutgoingIncomplete, in: call.thread) callRecord.save() call.callRecord = callRecord @@ -349,6 +363,19 @@ protocol CallServiceObserver: class { return } + // Now that we know the recipient trusts our identity, we no longer need to enqueue ICE updates. + self.sendIceUpdatesImmediately = true + + if pendingIceUpdateMessages.count > 0 { + Logger.error("\(self.TAG) Sending \(pendingIceUpdateMessages.count) pendingIceUpdateMessages") + + let callMessage = OWSOutgoingCallMessage(thread: thread, iceUpdateMessages: pendingIceUpdateMessages) + let sendPromise = messageSender.sendCallMessage(callMessage).catch { error in + Logger.error("\(self.TAG) failed to send ice updates in \(#function) with error: \(error)") + } + sendPromise.retainUntilComplete() + } + guard let peerConnectionClient = self.peerConnectionClient else { handleFailedCall(failedCall: call, error: CallError.assertionError(description: "peerConnectionClient was unexpectedly nil in \(#function)")) return @@ -648,8 +675,19 @@ protocol CallServiceObserver: class { let iceUpdateMessage = OWSCallIceUpdateMessage(callId: call.signalingId, sdp: iceCandidate.sdp, sdpMLineIndex: iceCandidate.sdpMLineIndex, sdpMid: iceCandidate.sdpMid) - let callMessage = OWSOutgoingCallMessage(thread: call.thread, iceUpdateMessage: iceUpdateMessage) - self.messageSender.sendCallMessage(callMessage).retainUntilComplete() + if self.sendIceUpdatesImmediately { + Logger.info("\(TAG) in \(#function). Sending immediately.") + let callMessage = OWSOutgoingCallMessage(thread: call.thread, iceUpdateMessage: iceUpdateMessage) + let sendPromise = self.messageSender.sendCallMessage(callMessage) + sendPromise.retainUntilComplete() + } else { + // For outgoing messages, we wait to send ice updates until we're sure client received our call message. + // e.g. if the client has blocked our message due to an identity change, we'd otherwise + // bombard them with a bunch *more* undecipherable messages. + Logger.info("\(TAG) in \(#function). Enqueing for later.") + self.pendingIceUpdateMessages.append(iceUpdateMessage) + return + } } /** @@ -1273,6 +1311,9 @@ protocol CallServiceObserver: class { self.call?.removeAllObservers() self.call = nil + self.sendIceUpdatesImmediately = true + Logger.info("\(TAG) clearing pendingIceUpdateMessages") + self.pendingIceUpdateMessages = [] self.fulfillCallConnectedPromise = nil // In case we're still waiting on the peer connection setup somewhere, we need to reject it to avoid a memory leak. From 438635393b88b421c93961d74f64688613819f89 Mon Sep 17 00:00:00 2001 From: Michael Kirk Date: Tue, 11 Jul 2017 17:42:43 -0400 Subject: [PATCH 2/4] Don't send ICE updates until after the CallOffer has been sent. This ensures message ordering for clients that can't handle out of order call messages (legacy iOS and Android). Even when we revert the previous commit, to send ICE Updates sooner, we'll want to keep this (until we're confident all clients can receive out of order call messages) // FREEBIE --- Signal/src/call/CallService.swift | 138 ++++++++++++++++++++++++------ 1 file changed, 114 insertions(+), 24 deletions(-) diff --git a/Signal/src/call/CallService.swift b/Signal/src/call/CallService.swift index 9363e6be8..25c931ea1 100644 --- a/Signal/src/call/CallService.swift +++ b/Signal/src/call/CallService.swift @@ -177,6 +177,12 @@ protocol CallServiceObserver: class { private var rejectPeerConnectionClientPromise: ((Error) -> Void)? private var peerConnectionClientPromise: Promise? + // Used by waituntilReadyToSendIceUpdates to make sure CallOffer was + // sent before sending any ICE updates. + private var fulfillReadyToSendIceUpdatesPromise: (() -> Void)? + private var rejectReadyToSendIceUpdatesPromise: ((Error) -> Void)? + private var readyToSendIceUpdatesPromise: Promise? + weak var localVideoTrack: RTCVideoTrack? { didSet { AssertIsOnMainThread() @@ -318,6 +324,10 @@ protocol CallServiceObserver: class { throw CallError.obsoleteCall(description:"obsolete call in \(#function)") } + // For outgoing calls, wait until call offer is sent before we send any ICE updates, to ensure message ordering for + // clients that don't support receiving ICE updates before receiving the call offer. + self.readyToSendIceUpdates(call: call) + let (callConnectedPromise, fulfill, _) = Promise.pending() self.fulfillCallConnectedPromise = fulfill @@ -346,6 +356,26 @@ protocol CallServiceObserver: class { return promise } + func readyToSendIceUpdates(call: SignalCall) { + AssertIsOnMainThread() + + guard self.call == call else { + self.handleFailedCall(failedCall: call, error: .obsoleteCall(description:"obsolete call in \(#function)")) + return + } + + if self.fulfillReadyToSendIceUpdatesPromise == nil { + createReadyToSendIceUpdatesPromise() + } + + guard let fulfillReadyToSendIceUpdatesPromise = self.fulfillReadyToSendIceUpdatesPromise else { + self.handleFailedCall(failedCall: call, error: .assertionError(description: "failed to create fulfillReadyToSendIceUpdatesPromise")) + return + } + + fulfillReadyToSendIceUpdatesPromise() + } + /** * Called by the call initiator after receiving a CallAnswer from the callee. */ @@ -586,6 +616,10 @@ protocol CallServiceObserver: class { } Logger.debug("\(self.TAG) successfully sent callAnswerMessage for: \(newCall.identifiersForLogs)") + // There's nothing technically forbidding receiving ICE updates before receiving the CallAnswer, but this + // a more intuitive ordering. + self.readyToSendIceUpdates(call: newCall) + let (promise, fulfill, _) = Promise.pending() let timeout: Promise = after(interval: TimeInterval(connectingTimeoutSeconds)).then { () -> Void in @@ -648,7 +682,7 @@ protocol CallServiceObserver: class { peerConnectionClient.addRemoteIceCandidate(RTCIceCandidate(sdp: sdp, sdpMLineIndex: lineIndex, sdpMid: mid)) }.catch { error in - Logger.error("\(self.TAG) in \(#function) failed with error: \(error)") + owsFail("\(self.TAG) in \(#function) waitForPeerConnectionClient failed with error: \(error)") }.retainUntilComplete() } @@ -660,34 +694,43 @@ protocol CallServiceObserver: class { AssertIsOnMainThread() guard let call = self.call else { - // This will only be called for the current peerConnectionClient, so - // fail the current call. - handleFailedCurrentCall(error: .assertionError(description: "ignoring local ice candidate, since there is no current call.")) + self.handleFailedCurrentCall(error: .assertionError(description: "ignoring local ice candidate, since there is no current call.")) return } - guard call.state != .idle else { - // This will only be called for the current peerConnectionClient, so - // fail the current call. - handleFailedCurrentCall(error: .assertionError(description: "ignoring local ice candidate, since call is now idle.")) - return - } + // Wait until we've sent the CallOffer before sending any ice updates for the call to ensure + // intuitive message ordering for other clients. + waitUntilReadyToSendIceUpdates().then { () -> Void in + guard call == self.call else { + self.handleFailedCurrentCall(error: .obsoleteCall(description: "current call changed since we became ready to send ice updates")) + return + } - let iceUpdateMessage = OWSCallIceUpdateMessage(callId: call.signalingId, sdp: iceCandidate.sdp, sdpMLineIndex: iceCandidate.sdpMLineIndex, sdpMid: iceCandidate.sdpMid) + guard call.state != .idle else { + // This will only be called for the current peerConnectionClient, so + // fail the current call. + self.handleFailedCurrentCall(error: .assertionError(description: "ignoring local ice candidate, since call is now idle.")) + return + } - if self.sendIceUpdatesImmediately { - Logger.info("\(TAG) in \(#function). Sending immediately.") - let callMessage = OWSOutgoingCallMessage(thread: call.thread, iceUpdateMessage: iceUpdateMessage) - let sendPromise = self.messageSender.sendCallMessage(callMessage) - sendPromise.retainUntilComplete() - } else { - // For outgoing messages, we wait to send ice updates until we're sure client received our call message. - // e.g. if the client has blocked our message due to an identity change, we'd otherwise - // bombard them with a bunch *more* undecipherable messages. - Logger.info("\(TAG) in \(#function). Enqueing for later.") - self.pendingIceUpdateMessages.append(iceUpdateMessage) - return - } + let iceUpdateMessage = OWSCallIceUpdateMessage(callId: call.signalingId, sdp: iceCandidate.sdp, sdpMLineIndex: iceCandidate.sdpMLineIndex, sdpMid: iceCandidate.sdpMid) + + if self.sendIceUpdatesImmediately { + Logger.info("\(self.TAG) in \(#function). Sending immediately.") + let callMessage = OWSOutgoingCallMessage(thread: call.thread, iceUpdateMessage: iceUpdateMessage) + let sendPromise = self.messageSender.sendCallMessage(callMessage) + sendPromise.retainUntilComplete() + } else { + // For outgoing messages, we wait to send ice updates until we're sure client received our call message. + // e.g. if the client has blocked our message due to an identity change, we'd otherwise + // bombard them with a bunch *more* undecipherable messages. + Logger.info("\(self.TAG) in \(#function). Enqueing for later.") + self.pendingIceUpdateMessages.append(iceUpdateMessage) + return + } + }.catch { error in + owsFail("\(self.TAG) in \(#function) waitUntilReadyToSendIceUpdates failed with error: \(error)") + }.retainUntilComplete() } /** @@ -1175,6 +1218,44 @@ protocol CallServiceObserver: class { // MARK: Helpers + private func waitUntilReadyToSendIceUpdates() -> Promise { + AssertIsOnMainThread() + + if self.readyToSendIceUpdatesPromise == nil { + createReadyToSendIceUpdatesPromise() + } + + guard let readyToSendIceUpdatesPromise = self.readyToSendIceUpdatesPromise else { + return Promise(error: CallError.assertionError(description: "failed to create readyToSendIceUpdatesPromise")) + } + + return readyToSendIceUpdatesPromise + } + + private func createReadyToSendIceUpdatesPromise() { + AssertIsOnMainThread() + + guard self.readyToSendIceUpdatesPromise == nil else { + Logger.error("expected readyToSendIceUpdatesPromise to be nil") + return + } + + guard self.fulfillReadyToSendIceUpdatesPromise == nil else { + Logger.error("expected fulfillReadyToSendIceUpdatesPromise to be nil") + return + } + + guard self.rejectReadyToSendIceUpdatesPromise == nil else { + Logger.error("expected rejectReadyToSendIceUpdatesPromise to be nil") + return + } + + let (promise, fulfill, reject) = Promise.pending() + self.fulfillReadyToSendIceUpdatesPromise = fulfill + self.rejectReadyToSendIceUpdatesPromise = reject + self.readyToSendIceUpdatesPromise = promise + } + private func waitForPeerConnectionClient() -> Promise { AssertIsOnMainThread() @@ -1324,6 +1405,15 @@ protocol CallServiceObserver: class { self.rejectPeerConnectionClientPromise = nil self.fulfillPeerConnectionClientPromise = nil self.peerConnectionClientPromise = nil + + // In case we're still waiting on this promise somewhere, we need to reject it to avoid a memory leak. + // There is no harm in rejecting a previously fulfilled promise. + if let rejectReadyToSendIceUpdatesPromise = self.rejectReadyToSendIceUpdatesPromise { + rejectReadyToSendIceUpdatesPromise(CallError.obsoleteCall(description: "Terminating call")) + } + self.fulfillReadyToSendIceUpdatesPromise = nil + self.rejectReadyToSendIceUpdatesPromise = nil + self.readyToSendIceUpdatesPromise = nil } // MARK: - CallObserver From b82aedc3a0cbeb2c17b33944ad44b93b315e4395 Mon Sep 17 00:00:00 2001 From: Michael Kirk Date: Tue, 11 Jul 2017 18:56:25 -0400 Subject: [PATCH 3/4] Assertion failures for unexpected promise state These don't currently result in failed calls, but we should at least know about it in debug. // FREEBIE --- Signal/src/call/CallService.swift | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/Signal/src/call/CallService.swift b/Signal/src/call/CallService.swift index 25c931ea1..c782d487b 100644 --- a/Signal/src/call/CallService.swift +++ b/Signal/src/call/CallService.swift @@ -682,7 +682,7 @@ protocol CallServiceObserver: class { peerConnectionClient.addRemoteIceCandidate(RTCIceCandidate(sdp: sdp, sdpMLineIndex: lineIndex, sdpMid: mid)) }.catch { error in - owsFail("\(self.TAG) in \(#function) waitForPeerConnectionClient failed with error: \(error)") + Logger.error("\(self.TAG) in \(#function) waitForPeerConnectionClient failed with error: \(error)") }.retainUntilComplete() } @@ -729,7 +729,7 @@ protocol CallServiceObserver: class { return } }.catch { error in - owsFail("\(self.TAG) in \(#function) waitUntilReadyToSendIceUpdates failed with error: \(error)") + Logger.error("\(self.TAG) in \(#function) waitUntilReadyToSendIceUpdates failed with error: \(error)") }.retainUntilComplete() } @@ -1236,17 +1236,17 @@ protocol CallServiceObserver: class { AssertIsOnMainThread() guard self.readyToSendIceUpdatesPromise == nil else { - Logger.error("expected readyToSendIceUpdatesPromise to be nil") + owsFail("expected readyToSendIceUpdatesPromise to be nil") return } guard self.fulfillReadyToSendIceUpdatesPromise == nil else { - Logger.error("expected fulfillReadyToSendIceUpdatesPromise to be nil") + owsFail("expected fulfillReadyToSendIceUpdatesPromise to be nil") return } guard self.rejectReadyToSendIceUpdatesPromise == nil else { - Logger.error("expected rejectReadyToSendIceUpdatesPromise to be nil") + owsFail("expected rejectReadyToSendIceUpdatesPromise to be nil") return } @@ -1279,17 +1279,17 @@ protocol CallServiceObserver: class { AssertIsOnMainThread() guard self.peerConnectionClientPromise == nil else { - Logger.error("expected peerConnectionClientPromise to be nil") + owsFail("expected peerConnectionClientPromise to be nil") return } guard self.fulfillPeerConnectionClientPromise == nil else { - Logger.error("expected fulfillPeerConnectionClientPromise to be nil") + owsFail("expected fulfillPeerConnectionClientPromise to be nil") return } guard self.rejectPeerConnectionClientPromise == nil else { - Logger.error("expected rejectPeerConnectionClientPromise to be nil") + owsFail("expected rejectPeerConnectionClientPromise to be nil") return } From d9dfc3d7c7e8166ebfb9a763db9fcfa1a01c09f2 Mon Sep 17 00:00:00 2001 From: Michael Kirk Date: Wed, 12 Jul 2017 16:18:43 -0400 Subject: [PATCH 4/4] update fastlane ci // FREEBIE --- Gemfile.lock | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/Gemfile.lock b/Gemfile.lock index 3d0a51079..4302eda55 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -63,7 +63,7 @@ GEM faraday_middleware (0.11.0.1) faraday (>= 0.7.4, < 1.0) fastimage (2.1.0) - fastlane (2.46.0) + fastlane (2.46.1) CFPropertyList (>= 2.3, < 3.0.0) addressable (>= 2.3, < 3.0.0) babosa (>= 1.0.2, < 2.0.0) @@ -117,7 +117,7 @@ GEM http-cookie (1.0.3) domain_name (~> 0.5) httpclient (2.8.3) - i18n (0.8.4) + i18n (0.8.6) json (2.1.0) jwt (1.5.6) little-plugger (1.1.4)