Improve logging in CallService.

// FREEBIE
pull/1/head
Matthew Chen 8 years ago
parent 12e083b4e0
commit 9fc92990f5

@ -130,8 +130,6 @@ protocol CallServiceObserver: class {
} }
} }
// TODO code cleanup: move thread into SignalCall? Or refactor messageSender to take SignalRecipient identifier.
var thread: TSContactThread?
var call: SignalCall? { var call: SignalCall? {
didSet { didSet {
AssertIsOnMainThread() AssertIsOnMainThread()
@ -142,7 +140,7 @@ protocol CallServiceObserver: class {
updateIsVideoEnabled() updateIsVideoEnabled()
updateLockTimerEnabling() updateLockTimerEnabling()
Logger.debug("\(self.TAG) .call setter: \(oldValue != nil) -> \(call != nil) \(String(describing: call))") Logger.debug("\(self.TAG) .call setter: \(oldValue?.debugString as Optional) -> \(call?.debugString as Optional)")
for observer in observers { for observer in observers {
observer.value?.didUpdateCall(call:call) observer.value?.didUpdateCall(call:call)
@ -161,9 +159,6 @@ protocol CallServiceObserver: class {
var sendIceUpdatesImmediately = true var sendIceUpdatesImmediately = true
var pendingIceUpdateMessages = [OWSCallIceUpdateMessage]() var pendingIceUpdateMessages = [OWSCallIceUpdateMessage]()
// ensure the incoming call promise isn't dealloc'd prematurely
var incomingCallPromise: Promise<Void>?
// Used to coordinate promises across delegate methods // Used to coordinate promises across delegate methods
var fulfillCallConnectedPromise: (() -> Void)? var fulfillCallConnectedPromise: (() -> Void)?
@ -265,18 +260,15 @@ protocol CallServiceObserver: class {
self.call = call self.call = call
let thread = TSContactThread.getOrCreateThread(contactId: call.remotePhoneNumber)
self.thread = thread
sendIceUpdatesImmediately = false sendIceUpdatesImmediately = false
pendingIceUpdateMessages = [] pendingIceUpdateMessages = []
let callRecord = TSCall(timestamp: NSDate.ows_millisecondTimeStamp(), withCallNumber: call.remotePhoneNumber, callType: RPRecentCallTypeOutgoingIncomplete, in: thread) let callRecord = TSCall(timestamp: NSDate.ows_millisecondTimeStamp(), withCallNumber: call.remotePhoneNumber, callType: RPRecentCallTypeOutgoingIncomplete, in: call.thread)
callRecord.save() callRecord.save()
call.callRecord = callRecord call.callRecord = callRecord
return getIceServers().then { iceServers -> Promise<HardenedRTCSessionDescription> in let promise = getIceServers().then { iceServers -> Promise<HardenedRTCSessionDescription> in
Logger.debug("\(self.TAG) got ice servers:\(iceServers)") Logger.debug("\(self.TAG) got ice servers:\(iceServers) for call: \(call.debugString)")
guard self.call == call else { guard self.call == call else {
throw CallError.obsoleteCall(description:"obsolete call in \(#function)") throw CallError.obsoleteCall(description:"obsolete call in \(#function)")
@ -291,7 +283,7 @@ protocol CallServiceObserver: class {
let useTurnOnly = Environment.getCurrent().preferences.doCallsHideIPAddress() let useTurnOnly = Environment.getCurrent().preferences.doCallsHideIPAddress()
let peerConnectionClient = PeerConnectionClient(iceServers: iceServers, delegate: self, callDirection: .outgoing, useTurnOnly: useTurnOnly) let peerConnectionClient = PeerConnectionClient(iceServers: iceServers, delegate: self, callDirection: .outgoing, useTurnOnly: useTurnOnly)
Logger.debug("\(self.TAG) setting peerConnectionClient in \(#function)") Logger.debug("\(self.TAG) setting peerConnectionClient in \(#function) for call: \(call.debugString)")
self.peerConnectionClient = peerConnectionClient self.peerConnectionClient = peerConnectionClient
return peerConnectionClient.createOffer() return peerConnectionClient.createOffer()
@ -306,7 +298,7 @@ protocol CallServiceObserver: class {
return peerConnectionClient.setLocalSessionDescription(sessionDescription).then { return peerConnectionClient.setLocalSessionDescription(sessionDescription).then {
let offerMessage = OWSCallOfferMessage(callId: call.signalingId, sessionDescription: sessionDescription.sdp) let offerMessage = OWSCallOfferMessage(callId: call.signalingId, sessionDescription: sessionDescription.sdp)
let callMessage = OWSOutgoingCallMessage(thread: thread, offerMessage: offerMessage) let callMessage = OWSOutgoingCallMessage(thread: call.thread, offerMessage: offerMessage)
return self.messageSender.sendCallMessage(callMessage) return self.messageSender.sendCallMessage(callMessage)
} }
}.then { }.then {
@ -326,10 +318,10 @@ protocol CallServiceObserver: class {
return race(timeout, callConnectedPromise) return race(timeout, callConnectedPromise)
}.then { }.then {
Logger.info(self.call == call Logger.info(self.call == call
? "\(self.TAG) outgoing call connected." ? "\(self.TAG) outgoing call connected: \(call.debugString)."
: "\(self.TAG) obsolete outgoing call connected.") : "\(self.TAG) obsolete outgoing call connected: \(call.debugString).")
}.catch { error in }.catch { error in
Logger.error("\(self.TAG) placing call failed with error: \(error)") Logger.error("\(self.TAG) placing call \(call.debugString) failed with error: \(error)")
if let callError = error as? CallError { if let callError = error as? CallError {
self.handleFailedCall(failedCall: call, error: callError) self.handleFailedCall(failedCall: call, error: callError)
@ -338,22 +330,24 @@ protocol CallServiceObserver: class {
self.handleFailedCall(failedCall: call, error: externalError) self.handleFailedCall(failedCall: call, error: externalError)
} }
} }
promise.retainUntilComplete()
return promise
} }
/** /**
* Called by the call initiator after receiving a CallAnswer from the callee. * Called by the call initiator after receiving a CallAnswer from the callee.
*/ */
public func handleReceivedAnswer(thread: TSContactThread, callId: UInt64, sessionDescription: String) { public func handleReceivedAnswer(thread: TSContactThread, callId: UInt64, sessionDescription: String) {
Logger.info("\(TAG) received call answer for call: \(callId) thread: \(thread)") Logger.info("\(TAG) received call answer for call: \(callId) thread: \(thread.contactIdentifier())")
AssertIsOnMainThread() AssertIsOnMainThread()
guard let call = self.call else { guard let call = self.call else {
Logger.warn("\(self.TAG) ignoring obsolete call in \(#function)") Logger.warn("\(self.TAG) ignoring obsolete call: \(callId) in \(#function)")
return return
} }
guard call.signalingId == callId else { guard call.signalingId == callId else {
Logger.warn("\(self.TAG) ignoring obsolete call in \(#function)") Logger.warn("\(self.TAG) ignoring obsolete call: \(callId) in \(#function)")
return return
} }
@ -417,7 +411,7 @@ protocol CallServiceObserver: class {
* Received a call while already in another call. * Received a call while already in another call.
*/ */
private func handleLocalBusyCall(_ call: SignalCall, thread: TSContactThread) { private func handleLocalBusyCall(_ call: SignalCall, thread: TSContactThread) {
Logger.info("\(TAG) \(#function) for call: \(call) thread: \(thread)") Logger.info("\(TAG) \(#function) for call: \(call.debugString) thread: \(thread.contactIdentifier())")
AssertIsOnMainThread() AssertIsOnMainThread()
let busyMessage = OWSCallBusyMessage(callId: call.signalingId) let busyMessage = OWSCallBusyMessage(callId: call.signalingId)
@ -432,7 +426,7 @@ protocol CallServiceObserver: class {
* The callee was already in another call. * The callee was already in another call.
*/ */
public func handleRemoteBusy(thread: TSContactThread) { public func handleRemoteBusy(thread: TSContactThread) {
Logger.info("\(TAG) \(#function) for thread: \(thread)") Logger.info("\(TAG) \(#function) for thread: \(thread.contactIdentifier())")
AssertIsOnMainThread() AssertIsOnMainThread()
guard let call = self.call else { guard let call = self.call else {
@ -457,14 +451,14 @@ protocol CallServiceObserver: class {
public func handleReceivedOffer(thread: TSContactThread, callId: UInt64, sessionDescription callerSessionDescription: String) { public func handleReceivedOffer(thread: TSContactThread, callId: UInt64, sessionDescription callerSessionDescription: String) {
AssertIsOnMainThread() AssertIsOnMainThread()
Logger.info("\(TAG) receivedCallOffer for thread:\(thread)")
let newCall = SignalCall.incomingCall(localId: UUID(), remotePhoneNumber: thread.contactIdentifier(), signalingId: callId) let newCall = SignalCall.incomingCall(localId: UUID(), remotePhoneNumber: thread.contactIdentifier(), signalingId: callId)
Logger.info("\(TAG) receivedCallOffer: \(newCall.debugString)")
let untrustedIdentity = OWSIdentityManager.shared().untrustedIdentityForSending(toRecipientId: thread.contactIdentifier()) let untrustedIdentity = OWSIdentityManager.shared().untrustedIdentityForSending(toRecipientId: thread.contactIdentifier())
guard untrustedIdentity == nil else { guard untrustedIdentity == nil else {
Logger.warn("\(TAG) missed a call due to untrusted identity") Logger.warn("\(TAG) missed a call due to untrusted identity: \(newCall.debugString)")
let callerName = self.contactsManager.displayName(forPhoneIdentifier: thread.contactIdentifier()) let callerName = self.contactsManager.displayName(forPhoneIdentifier: thread.contactIdentifier())
@ -494,16 +488,15 @@ protocol CallServiceObserver: class {
guard self.call == nil else { guard self.call == nil else {
// TODO on iOS10+ we can use CallKit to swap calls rather than just returning busy immediately. // TODO on iOS10+ we can use CallKit to swap calls rather than just returning busy immediately.
Logger.info("\(TAG) receivedCallOffer for thread: \(thread) but we're already in call: \(call!)") Logger.info("\(TAG) receivedCallOffer: \(newCall.debugString) but we're already in call: \(call!.debugString)")
handleLocalBusyCall(newCall, thread: thread) handleLocalBusyCall(newCall, thread: thread)
return return
} }
Logger.info("\(TAG) starting new call: \(newCall)") Logger.info("\(TAG) starting new call: \(newCall.debugString)")
self.thread = thread
self.call = newCall self.call = newCall
let backgroundTask = UIApplication.shared.beginBackgroundTask { let backgroundTask = UIApplication.shared.beginBackgroundTask {
@ -517,7 +510,7 @@ protocol CallServiceObserver: class {
} }
} }
incomingCallPromise = firstly { let incomingCallPromise = firstly {
return getIceServers() return getIceServers()
}.then { (iceServers: [RTCIceServer]) -> Promise<HardenedRTCSessionDescription> in }.then { (iceServers: [RTCIceServer]) -> Promise<HardenedRTCSessionDescription> in
// FIXME for first time call recipients I think we'll see mic/camera permission requests here, // FIXME for first time call recipients I think we'll see mic/camera permission requests here,
@ -533,7 +526,7 @@ protocol CallServiceObserver: class {
let useTurnOnly = unknownCaller || Environment.getCurrent().preferences.doCallsHideIPAddress() let useTurnOnly = unknownCaller || Environment.getCurrent().preferences.doCallsHideIPAddress()
Logger.debug("\(self.self.TAG) setting peerConnectionClient in \(#function)") Logger.debug("\(self.TAG) setting peerConnectionClient in \(#function) for: \(newCall.debugString)")
let peerConnectionClient = PeerConnectionClient(iceServers: iceServers, delegate: self, callDirection: .incoming, useTurnOnly: useTurnOnly) let peerConnectionClient = PeerConnectionClient(iceServers: iceServers, delegate: self, callDirection: .incoming, useTurnOnly: useTurnOnly)
self.peerConnectionClient = peerConnectionClient self.peerConnectionClient = peerConnectionClient
@ -546,7 +539,7 @@ protocol CallServiceObserver: class {
guard self.call == newCall else { guard self.call == newCall else {
throw CallError.obsoleteCall(description: "negotiateSessionDescription() response for obsolete call") throw CallError.obsoleteCall(description: "negotiateSessionDescription() response for obsolete call")
} }
Logger.debug("\(self.TAG) set the remote description") Logger.debug("\(self.TAG) set the remote description for: \(newCall.debugString)")
let answerMessage = OWSCallAnswerMessage(callId: newCall.signalingId, sessionDescription: negotiatedSessionDescription.sdp) let answerMessage = OWSCallAnswerMessage(callId: newCall.signalingId, sessionDescription: negotiatedSessionDescription.sdp)
let callAnswerMessage = OWSOutgoingCallMessage(thread: thread, answerMessage: answerMessage) let callAnswerMessage = OWSOutgoingCallMessage(thread: thread, answerMessage: answerMessage)
@ -556,7 +549,7 @@ protocol CallServiceObserver: class {
guard self.call == newCall else { guard self.call == newCall else {
throw CallError.obsoleteCall(description: "sendCallMessage() response for obsolete call") throw CallError.obsoleteCall(description: "sendCallMessage() response for obsolete call")
} }
Logger.debug("\(self.TAG) successfully sent callAnswerMessage") Logger.debug("\(self.TAG) successfully sent callAnswerMessage for: \(newCall.debugString)")
let (promise, fulfill, _) = Promise<Void>.pending() let (promise, fulfill, _) = Promise<Void>.pending()
@ -571,11 +564,11 @@ protocol CallServiceObserver: class {
return race(promise, timeout) return race(promise, timeout)
}.then { }.then {
Logger.info(self.call == newCall Logger.info(self.call == newCall
? "\(self.TAG) incoming call connected." ? "\(self.TAG) incoming call connected: \(newCall.debugString)."
: "\(self.TAG) obsolete incoming call connected.") : "\(self.TAG) obsolete incoming call connected: \(newCall.debugString).")
}.catch { error in }.catch { error in
guard self.call == newCall else { guard self.call == newCall else {
Logger.debug("\(self.TAG) error for obsolete call: \(error)") Logger.debug("\(self.TAG) error: \(error) for obsolete call: \(newCall.debugString).")
return return
} }
if let callError = error as? CallError { if let callError = error as? CallError {
@ -588,6 +581,7 @@ protocol CallServiceObserver: class {
Logger.debug("\(self.TAG) ending background task awaiting inbound call connection") Logger.debug("\(self.TAG) ending background task awaiting inbound call connection")
UIApplication.shared.endBackgroundTask(backgroundTask) UIApplication.shared.endBackgroundTask(backgroundTask)
} }
incomingCallPromise.retainUntilComplete()
} }
/** /**
@ -597,28 +591,23 @@ protocol CallServiceObserver: class {
AssertIsOnMainThread() AssertIsOnMainThread()
Logger.info("\(TAG) called \(#function)") Logger.info("\(TAG) called \(#function)")
guard let currentThread = self.thread else { guard let call = self.call else {
Logger.warn("ignoring remote ice update for thread: \(thread.uniqueId) since there is no current thread. Call already ended?")
return
}
guard thread.contactIdentifier() == currentThread.contactIdentifier() else {
Logger.warn("ignoring remote ice update for thread: \(thread.uniqueId) since there is no current thread. Call already ended?") Logger.warn("ignoring remote ice update for thread: \(thread.uniqueId) since there is no current thread. Call already ended?")
return return
} }
guard let call = self.call else { guard call.signalingId == callId else {
Logger.warn("ignoring remote ice update for thread: \(thread.uniqueId) since there is no current thread. Call already ended?") Logger.warn("ignoring remote ice update for thread: \(thread.uniqueId) due to callId mismatch. Call already ended?")
return return
} }
guard call.signalingId == callId else { guard thread.contactIdentifier() == call.thread.contactIdentifier() else {
Logger.warn("ignoring remote ice update for thread: \(thread.uniqueId) since there is no current thread. Call already ended?") Logger.warn("ignoring remote ice update for thread: \(thread.uniqueId) due to thread mismatch. Call already ended?")
return return
} }
guard let peerConnectionClient = self.peerConnectionClient else { guard let peerConnectionClient = self.peerConnectionClient else {
Logger.warn("ignoring remote ice update for thread: \(thread.uniqueId) since there is no current thread. Call already ended?") Logger.warn("ignoring remote ice update for thread: \(thread.uniqueId) since there is no current peerConnectionClient. Call already ended?")
return return
} }
@ -646,18 +635,11 @@ protocol CallServiceObserver: class {
return return
} }
guard let thread = self.thread else {
// This will only be called for the current peerConnectionClient, so
// fail the current call.
handleFailedCurrentCall(error: .assertionError(description: "ignoring local ice candidate, because there was no current TSContactThread."))
return
}
let iceUpdateMessage = OWSCallIceUpdateMessage(callId: call.signalingId, sdp: iceCandidate.sdp, sdpMLineIndex: iceCandidate.sdpMLineIndex, sdpMid: iceCandidate.sdpMid) let iceUpdateMessage = OWSCallIceUpdateMessage(callId: call.signalingId, sdp: iceCandidate.sdp, sdpMLineIndex: iceCandidate.sdpMLineIndex, sdpMid: iceCandidate.sdpMid)
if self.sendIceUpdatesImmediately { if self.sendIceUpdatesImmediately {
Logger.info("\(TAG) in \(#function). Sending immediately.") Logger.info("\(TAG) in \(#function). Sending immediately.")
let callMessage = OWSOutgoingCallMessage(thread: thread, iceUpdateMessage: iceUpdateMessage) let callMessage = OWSOutgoingCallMessage(thread: call.thread, iceUpdateMessage: iceUpdateMessage)
let sendPromise = self.messageSender.sendCallMessage(callMessage) let sendPromise = self.messageSender.sendCallMessage(callMessage)
sendPromise.retainUntilComplete() sendPromise.retainUntilComplete()
} else { } else {
@ -679,8 +661,6 @@ protocol CallServiceObserver: class {
private func handleIceConnected() { private func handleIceConnected() {
AssertIsOnMainThread() AssertIsOnMainThread()
Logger.debug("\(TAG) in \(#function)")
guard let call = self.call else { guard let call = self.call else {
// This will only be called for the current peerConnectionClient, so // This will only be called for the current peerConnectionClient, so
// fail the current call. // fail the current call.
@ -688,25 +668,20 @@ protocol CallServiceObserver: class {
return return
} }
guard let thread = self.thread else { Logger.info("\(TAG) in \(#function): \(call.debugString).")
// This will only be called for the current peerConnectionClient, so
// fail the current call.
handleFailedCurrentCall(error: .assertionError(description:"\(TAG) ignoring \(#function) since there is no current thread."))
return
}
switch call.state { switch call.state {
case .dialing: case .dialing:
call.state = .remoteRinging call.state = .remoteRinging
case .answering: case .answering:
call.state = .localRinging call.state = .localRinging
self.callUIAdapter.reportIncomingCall(call, thread: thread) self.callUIAdapter.reportIncomingCall(call, thread: call.thread)
case .remoteRinging: case .remoteRinging:
Logger.info("\(TAG) call alreading ringing. Ignoring \(#function)") Logger.info("\(TAG) call already ringing. Ignoring \(#function): \(call.debugString).")
case .connected: case .connected:
Logger.info("\(TAG) Call reconnected \(#function)") Logger.info("\(TAG) Call reconnected \(#function): \(call.debugString).")
default: default:
Logger.debug("\(TAG) unexpected call state for \(#function): \(call.state)") Logger.debug("\(TAG) unexpected call state for \(#function): \(call.state): \(call.debugString).")
} }
} }
@ -717,20 +692,21 @@ protocol CallServiceObserver: class {
Logger.debug("\(TAG) in \(#function)") Logger.debug("\(TAG) in \(#function)")
AssertIsOnMainThread() AssertIsOnMainThread()
guard thread.contactIdentifier() == self.thread?.contactIdentifier() else { guard let call = self.call else {
// This can safely be ignored. // This may happen if we hang up slightly before they hang up.
// We don't want to fail the current call because an old call was slow to send us the hangup message. handleFailedCurrentCall(error: .assertionError(description:"\(TAG) call was unexpectedly nil in \(#function)"))
Logger.warn("\(TAG) ignoring hangup for thread:\(thread) which is not the current thread: \(String(describing: self.thread))")
return return
} }
guard let call = self.call else { guard thread.contactIdentifier() == call.thread.contactIdentifier() else {
// This should never happen; return to a known good state. // This can safely be ignored.
assertionFailure("\(TAG) call was unexpectedly nil in \(#function)") // We don't want to fail the current call because an old call was slow to send us the hangup message.
handleFailedCurrentCall(error: .assertionError(description:"\(TAG) call was unexpectedly nil in \(#function)")) Logger.warn("\(TAG) ignoring hangup for thread: \(thread.contactIdentifier()) which is not the current call: \(call.debugString)")
return return
} }
Logger.info("\(TAG) in \(#function): \(call.debugString).")
switch call.state { switch call.state {
case .idle, .dialing, .answering, .localRinging, .localFailure, .remoteBusy, .remoteRinging: case .idle, .dialing, .answering, .localRinging, .localFailure, .remoteBusy, .remoteRinging:
handleMissedCall(call, thread: thread) handleMissedCall(call, thread: thread)
@ -791,17 +767,14 @@ protocol CallServiceObserver: class {
return return
} }
guard let thread = self.thread else {
handleFailedCall(failedCall: call, error: .assertionError(description:"\(TAG) ignoring \(#function) for call other than current call"))
return
}
guard let peerConnectionClient = self.peerConnectionClient else { guard let peerConnectionClient = self.peerConnectionClient else {
handleFailedCall(failedCall: call, error: .assertionError(description:"\(TAG) missing peerconnection client in \(#function)")) handleFailedCall(failedCall: call, error: .assertionError(description:"\(TAG) missing peerconnection client in \(#function)"))
return return
} }
let callRecord = TSCall(timestamp: NSDate.ows_millisecondTimeStamp(), withCallNumber: call.remotePhoneNumber, callType: RPRecentCallTypeIncomingIncomplete, in: thread) Logger.info("\(TAG) in \(#function): \(call.debugString).")
let callRecord = TSCall(timestamp: NSDate.ows_millisecondTimeStamp(), withCallNumber: call.remotePhoneNumber, callType: RPRecentCallTypeIncomingIncomplete, in: call.thread)
callRecord.save() callRecord.save()
call.callRecord = callRecord call.callRecord = callRecord
@ -824,6 +797,8 @@ protocol CallServiceObserver: class {
return return
} }
Logger.info("\(TAG) handleConnectedCall: \(call.debugString).")
assert(self.fulfillCallConnectedPromise != nil) assert(self.fulfillCallConnectedPromise != nil)
// cancel connection timeout // cancel connection timeout
self.fulfillCallConnectedPromise?() self.fulfillCallConnectedPromise?()
@ -870,7 +845,7 @@ protocol CallServiceObserver: class {
public func handleDeclineCall(_ call: SignalCall) { public func handleDeclineCall(_ call: SignalCall) {
AssertIsOnMainThread() AssertIsOnMainThread()
Logger.info("\(TAG) in \(#function)") Logger.info("\(TAG) in \(#function): \(call.debugString).")
// Currently we just handle this as a hangup. But we could offer more descriptive action. e.g. DataChannel message // Currently we just handle this as a hangup. But we could offer more descriptive action. e.g. DataChannel message
handleLocalHungupCall(call) handleLocalHungupCall(call)
@ -899,10 +874,7 @@ protocol CallServiceObserver: class {
return return
} }
guard let thread = self.thread else { Logger.info("\(TAG) in \(#function): \(call.debugString).")
handleFailedCall(failedCall: call, error: .assertionError(description:"\(TAG) missing thread in \(#function)"))
return
}
call.state = .localHangup call.state = .localHangup
@ -916,11 +888,11 @@ protocol CallServiceObserver: class {
// If the call hasn't started yet, we don't have a data channel to communicate the hang up. Use Signal Service Message. // If the call hasn't started yet, we don't have a data channel to communicate the hang up. Use Signal Service Message.
let hangupMessage = OWSCallHangupMessage(callId: call.signalingId) let hangupMessage = OWSCallHangupMessage(callId: call.signalingId)
let callMessage = OWSOutgoingCallMessage(thread: thread, hangupMessage: hangupMessage) let callMessage = OWSOutgoingCallMessage(thread: call.thread, hangupMessage: hangupMessage)
let sendPromise = self.messageSender.sendCallMessage(callMessage).then { let sendPromise = self.messageSender.sendCallMessage(callMessage).then {
Logger.debug("\(self.TAG) successfully sent hangup call message to \(thread)") Logger.debug("\(self.TAG) successfully sent hangup call message to \(call.thread.contactIdentifier())")
}.catch { error in }.catch { error in
Logger.error("\(self.TAG) failed to send hangup call message to \(thread) with error: \(error)") Logger.error("\(self.TAG) failed to send hangup call message to \(call.thread.contactIdentifier()) with error: \(error)")
} }
sendPromise.retainUntilComplete() sendPromise.retainUntilComplete()
@ -1035,7 +1007,7 @@ protocol CallServiceObserver: class {
} }
if message.hasConnected() { if message.hasConnected() {
Logger.debug("\(TAG) remote participant sent Connected via data channel") Logger.debug("\(TAG) remote participant sent Connected via data channel: \(call.debugString).")
let connected = message.connected! let connected = message.connected!
@ -1050,7 +1022,7 @@ protocol CallServiceObserver: class {
handleConnectedCall(call) handleConnectedCall(call)
} else if message.hasHangup() { } else if message.hasHangup() {
Logger.debug("\(TAG) remote participant sent Hangup via data channel") Logger.debug("\(TAG) remote participant sent Hangup via data channel: \(call.debugString).")
let hangup = message.hangup! let hangup = message.hangup!
@ -1061,20 +1033,13 @@ protocol CallServiceObserver: class {
return return
} }
guard let thread = self.thread else { handleRemoteHangup(thread: call.thread)
// This should never happen; return to a known good state.
assertionFailure("\(TAG) current contact thread is unexpectedly nil when receiving hangup DataChannelMessage")
handleFailedCurrentCall(error: .assertionError(description:"\(TAG) current contact thread is unexpectedly nil when receiving hangup DataChannelMessage"))
return
}
handleRemoteHangup(thread: thread)
} else if message.hasVideoStreamingStatus() { } else if message.hasVideoStreamingStatus() {
Logger.debug("\(TAG) remote participant sent VideoStreamingStatus via data channel") Logger.debug("\(TAG) remote participant sent VideoStreamingStatus via data channel: \(call.debugString).")
self.isRemoteVideoEnabled = message.videoStreamingStatus.enabled() self.isRemoteVideoEnabled = message.videoStreamingStatus.enabled()
} else { } else {
Logger.info("\(TAG) received unknown or empty DataChannelMessage") Logger.info("\(TAG) received unknown or empty DataChannelMessage: \(call.debugString).")
} }
} }
@ -1198,7 +1163,10 @@ protocol CallServiceObserver: class {
// that we want to terminate the current call (if any) in order to // that we want to terminate the current call (if any) in order to
// return to a known good state. // return to a known good state.
public func handleFailedCurrentCall(error: CallError) { public func handleFailedCurrentCall(error: CallError) {
handleFailedCall(failedCall: self.call, error: error, forceTerminate:true) Logger.debug("\(TAG) in \(#function)")
// Return to a known good state by ending the current call, if any.
handleFailedCall(failedCall: self.call, error: error)
} }
// This method should be called when a fatal error occurred for a call. // This method should be called when a fatal error occurred for a call.
@ -1206,26 +1174,24 @@ protocol CallServiceObserver: class {
// * If we know which call it was, we should update that call's state // * If we know which call it was, we should update that call's state
// to reflect the error. // to reflect the error.
// * IFF that call is the current call, we want to terminate it. // * IFF that call is the current call, we want to terminate it.
public func handleFailedCall(failedCall: SignalCall?, error: CallError, forceTerminate: Bool = false) { public func handleFailedCall(failedCall: SignalCall?, error: CallError) {
AssertIsOnMainThread() AssertIsOnMainThread()
Logger.error("\(TAG) call failed with error: \(error)")
guard let failedCall = failedCall else { if let failedCall = failedCall {
Logger.debug("\(TAG) in \(#function) ignoring obsolete call.") // It's essential to set call.state before terminateCall, because terminateCall nils self.call
return failedCall.error = error
} failedCall.state = .localFailure
self.callUIAdapter.failCall(failedCall, error: error)
// It's essential to set call.state before terminateCall, because terminateCall nils self.call // Only terminate the current call if the error pertains to the current call.
failedCall.error = error guard failedCall == self.call else {
failedCall.state = .localFailure Logger.debug("\(TAG) in \(#function) ignoring obsolete call: \(failedCall.debugString).")
self.callUIAdapter.failCall(failedCall, error: error) return
}
// Only terminate the current call if the error pertains to the current call, Logger.error("\(TAG) call: \(failedCall.debugString) failed with error: \(error)")
// or if we're trying to return to a known good state. } else {
let shouldTerminate = forceTerminate || failedCall == self.call Logger.error("\(TAG) unknown call failed with error: \(error)")
guard shouldTerminate else {
Logger.debug("\(TAG) in \(#function) ignoring obsolete call.")
return
} }
// Only terminate the call if it is the current call. // Only terminate the call if it is the current call.
@ -1251,11 +1217,10 @@ protocol CallServiceObserver: class {
call?.removeAllObservers() call?.removeAllObservers()
call = nil call = nil
thread = nil
incomingCallPromise = nil
sendIceUpdatesImmediately = true sendIceUpdatesImmediately = true
Logger.info("\(TAG) clearing pendingIceUpdateMessages") Logger.info("\(TAG) clearing pendingIceUpdateMessages")
pendingIceUpdateMessages = [] pendingIceUpdateMessages = []
fulfillCallConnectedPromise = nil
} }
// MARK: - CallObserver // MARK: - CallObserver

@ -49,6 +49,8 @@ protocol CallObserver: class {
// Distinguishes between calls locally, e.g. in CallKit // Distinguishes between calls locally, e.g. in CallKit
let localId: UUID let localId: UUID
let thread: TSContactThread
var callRecord: TSCall? { var callRecord: TSCall? {
didSet { didSet {
AssertIsOnMainThread() AssertIsOnMainThread()
@ -71,7 +73,7 @@ protocol CallObserver: class {
var state: CallState { var state: CallState {
didSet { didSet {
AssertIsOnMainThread() AssertIsOnMainThread()
Logger.debug("\(TAG) state changed: \(oldValue) -> \(self.state)") Logger.debug("\(TAG) state changed: \(oldValue) -> \(self.state) for call: \(self.debugString)")
// Update connectedDate // Update connectedDate
if self.state == .connected { if self.state == .connected {
@ -128,6 +130,12 @@ protocol CallObserver: class {
self.signalingId = signalingId self.signalingId = signalingId
self.state = state self.state = state
self.remotePhoneNumber = remotePhoneNumber self.remotePhoneNumber = remotePhoneNumber
self.thread = TSContactThread.getOrCreateThread(contactId: remotePhoneNumber)
}
var debugString: String {
return "{\(remotePhoneNumber), \(localId), \(signalingId)}"
} }
class func outgoingCall(localId: UUID, remotePhoneNumber: String) -> SignalCall { class func outgoingCall(localId: UUID, remotePhoneNumber: String) -> SignalCall {

Loading…
Cancel
Save