Add call setup time logging.

Signal/src/call/CallService.swift

@@ -106,6 +106,9 @@ protocol SignalCallDataDelegate: class {
 
 // Gather all per-call state in one place.
 private class SignalCallData: NSObject {
+
+    let startTime: UInt64
+
     fileprivate weak var delegate: SignalCallDataDelegate?
 
     public let call: SignalCall
@@ -154,8 +157,9 @@ private class SignalCallData: NSObject {
         }
     }
 
-    required init(call: SignalCall, delegate: SignalCallDataDelegate) {
+    required init(call: SignalCall, startTime: UInt64, delegate: SignalCallDataDelegate) {
         self.call = call
+        self.startTime = startTime
         self.delegate = delegate
 
         let (callConnectedPromise, callConnectedResolver) = Promise<Void>.pending()
@@ -438,6 +442,8 @@ private class SignalCallData: NSObject {
     func handleOutgoingCall(_ call: SignalCall) -> Promise<Void> {
         AssertIsOnMainThread()
 
+        let startTime = NSDate.ows_millisecondTimeStamp()
+
         guard self.call == nil else {
             let errorDescription = "call was unexpectedly already set."
             Logger.error(errorDescription)
@@ -446,7 +452,7 @@ private class SignalCallData: NSObject {
             return Promise(error: CallError.assertionError(description: errorDescription))
         }
 
-        let callData = SignalCallData(call: call, delegate: self)
+        let callData = SignalCallData(call: call, startTime: startTime, delegate: self)
         self.callData = callData
 
         // MJK TODO remove this timestamp param
@@ -677,6 +683,8 @@ private class SignalCallData: NSObject {
     public func handleReceivedOffer(thread: TSContactThread, callId: UInt64, sessionDescription callerSessionDescription: String) {
         AssertIsOnMainThread()
 
+        let startTime = NSDate.ows_millisecondTimeStamp()
+
         let newCall = SignalCall.incomingCall(localId: UUID(), remotePhoneNumber: thread.contactIdentifier(), signalingId: callId)
 
         Logger.info("receivedCallOffer: \(newCall.identifiersForLogs)")
@@ -747,7 +755,7 @@ private class SignalCallData: NSObject {
 
         Logger.info("starting new call: \(newCall.identifiersForLogs)")
 
-        let callData = SignalCallData(call: newCall, delegate: self)
+        let callData = SignalCallData(call: newCall, startTime: startTime, delegate: self)
         self.callData = callData
 
         var backgroundTask: OWSBackgroundTask? = OWSBackgroundTask(label: "\(#function)", completionBlock: { [weak self] status in
@@ -972,20 +980,29 @@ private class SignalCallData: NSObject {
     private func handleIceConnected() {
         AssertIsOnMainThread()
 
-        guard let call = self.call else {
+        guard let callData = self.callData else {
             // This will only be called for the current peerConnectionClient, so
             // fail the current call.
             OWSProdError(OWSAnalyticsEvents.callServiceCallMissing(), file: #file, function: #function, line: #line)
             handleFailedCurrentCall(error: CallError.assertionError(description: "ignoring \(#function) since there is no current call."))
             return
         }
+        let call = callData.call
 
-        Logger.info("\(call.identifiersForLogs).")
+        Logger.info("\(call.identifiersForLogs)")
 
         switch call.state {
         case .dialing:
+            if call.state != .remoteRinging {
+                let connectedTime = NSDate.ows_millisecondTimeStamp()
+                Logger.info("Connected in: \(connectedTime - callData.startTime)")
+            }
             call.state = .remoteRinging
         case .answering:
+            if call.state != .localRinging {
+                let connectedTime = NSDate.ows_millisecondTimeStamp()
+                Logger.info("Connected in: \(connectedTime - callData.startTime)")
+            }
             call.state = .localRinging
             self.callUIAdapter.reportIncomingCall(call, thread: call.thread)
         case .remoteRinging: