APNs push notifications severely delayed

cybex-dev commented 2 years ago

Description

Seeking assistance / advice on resolving a APNs VOiP push notification issue (delayed delivery).

TL;DR - Calls are being received, notified via APNs notifications however they seem to be severely delayed (being received on 'opponents' device, up to 120s). After the first call is successfully received and reported, subsequent calls (mostly) go through almost instantly (accounting for network delay), usually around 3-5s.

I suspect it may have something to do with Pushkit device token being registered to possibly too many users access tokens / users, however upon logout I call unregister(deviceToken, accessToken)that should resolve this.

Context:

A user can login (request access token and register with device token). A user can call another user. A user can logout, login as a different user and make/receive calls meant for the new user (user based, not device based).

Steps to Reproduce

Use sample project (adapted for user-based project, i.e. login/logout)
Place call (caller)
Expect & answer call (opponent/recipient)

Code

Only code adaption (since this is modified into a Flutter package) is: upon launching, the device's push token is cached regardless of TwilioVoiceSDK.register() is successful - this allows for users to login/logout. Upon logout, th

Expected Behavior

Upon first install & login (caller & recipient), first call (possibly slight delay for init, etc) but nothing more than 10s wait time for recipient to be notified of incoming call.

Actual Behavior

Upon first install & login (caller & recipient), first 1-2 (up to around 5) calls are missed/no-answer (on recipient side). After a period of time, the recipient's device console output shows the APNs push notification is received and code handles the (delayed notification) as it should (reporting as missed only, not reported as new incoming call).

Log outputs

On both devices, I get:

LOG|Successfully registered for VoIP push notifications.
flutter: Successfully registered for VoIP push notifications.

Log output correlation to sample iOS swift app

Log outputs which originates from calling register(deviceToken, accessToken) (after user authentication & new access token for user is generated with adapted sample of incoming.js)

Reproduces How Often

Often (min 80% - app breaking)

Twilio Call SID(s)

Sample of delayed workflow as described above. All Call SID's are from the recipient.

Failed, timeout. CA3522338e615b3fd3f4b25254e5d767ac
Failed, timeout CA81a444c2cd9f6e6fd567ea560ad6543f
Failed, timeout CAe3ff825264825b79aa723d6a0ea208e8
Failed, timeout CA5bd89cf8ce6be17ab7dd4307c0010e3c
Received, after ~23s since starting call CAc26200cff057e5082e07012fd16070c0

During these calls, devices are active & have app open with no interaction besides repeat calling until call is received. (both have background & mic permissions, have voice & push notification capabilities, etc)

Voice iOS SDK

6.3.0 (via Podfile.lock)

Xcode

Version 13.3.1 (13E500a)

iOS Version

15.5 (Caller & recipient)

iOS Device

iPhone 7 (Caller & recipient) iPhone 6s (Caller & recipient)

Additional question/request

Where are APNs push notifications stored for Twilio, it would be extremely helpful during developement to see which push notifications were sent, for what call and if they were successfully delivered. I can't find such a page/information on the Twilio Console.

bobiechen-twilio commented 2 years ago

Hi @cybex-dev

Thanks for the detailed description and Call SIDs. I did check the Call SIDs and found that Twilio actually sent out push notification delivery requests to APNS almost immediately when the calls were made to the receiving client, and all the request response were successful.

Please make sure the PushKit instance is initialized in the frontmost component of the iOS app, preferably the AppDelegate. That way the app can handle the incoming VoIP push timely, on the main thread, especially when the app is in the background or not running.

cybex-dev commented 2 years ago

@bobiechen-twilio

Thanks for the rapid response.

Resolved, see unregister() code implementation.

I had another look at the Flutter implementation for user-sessions (specifically for iOS).

Upon logging out by calling unregister(accessToken, deviceToken), the cached token wasn't being cleared (as a result from credentialsInvalidated())

During logout, the following is called.

    public func pushRegistry(_ registry: PKPushRegistry, didInvalidatePushTokenFor type: PKPushType) {
        self.sendPhoneCallEvents(description: "LOG|pushRegistry:didInvalidatePushTokenForType:", isError: false)

        if (type != .voIP) {
            return
        }

        self.unregister()
    }

    func unregister() {

        guard let deviceToken = deviceToken, let token = accessToken else {
            return
        }

        self.unregisterTokens(token: token, deviceToken: deviceToken)
    }

    func unregisterTokens(token: String, deviceToken: Data) {
        TwilioVoiceSDK.unregister(accessToken: token, deviceToken: deviceToken) { (error) in
            if let error = error {
                self.sendPhoneCallEvents(description: "LOG|An error occurred while unregistering: \(error.localizedDescription)", isError: false)
            } else {
                self.sendPhoneCallEvents(description: "LOG|Successfully unregistered from VoIP push notifications.", isError: false)
            }
        }
        UserDefaults.standard.removeObject(forKey: kCachedDeviceToken)

        // Remove the cached binding as credentials are invalidated
        UserDefaults.standard.removeObject(forKey: kCachedBindingDate)
    }

This has allowed login & logout as various users with calls reporting successfully each time.

@bobiechen-twilio for future reference, does Twilio provide an interface to view sent push notifications (via APNs or to other push notification services)?

bobiechen-twilio commented 2 years ago

The unregister() method won't invalidate the PushKit device token. The token is only invalidated by Apple under a handful of scenarios. Please check out the Apple developer documentation.

does Twilio provide an interface to view sent push notifications

Currently only when the delivery requests are unsuccessful (invalid device token, mismatch APN environment and etc.) then Twilio will log an error notification in your developer console with error description and possible solution.

cybex-dev commented 2 years ago

To clarify.

In the scenario of an authenticated user with an access token attached to their device token (pushkit token), calling unregister() will ask Twilio to dissociate the device & access tokens (i.e. all subsequent calls to the attached identity results in 'Temporarily Unavailable').

If that is the case, the deviceToken remains across user sessions.

cybex-dev commented 2 years ago

Oops, got the wrong snipper above. The deviceToken and binding should not be cleared.

This is correct.

    public func pushRegistry(_ registry: PKPushRegistry, didInvalidatePushTokenFor type: PKPushType) {
        self.sendPhoneCallEvents(description: "LOG|pushRegistry:didInvalidatePushTokenForType:", isError: false)

        if (type != .voIP) {
            return
        }

        self.unregister()
    }

    func unregister() {

        guard let deviceToken = deviceToken, let token = accessToken else {
            return
        }

        self.unregisterTokens(token: token, deviceToken: deviceToken)
    }

    func unregisterTokens(token: String, deviceToken: Data) {
        TwilioVoiceSDK.unregister(accessToken: token, deviceToken: deviceToken) { (error) in
            if let error = error {
                self.sendPhoneCallEvents(description: "LOG|An error occurred while unregistering: \(error.localizedDescription)", isError: false)
            } else {
                self.sendPhoneCallEvents(description: "LOG|Successfully unregistered from VoIP push notifications.", isError: false)
            }
        }
        // UserDefaults.standard.removeObject(forKey: kCachedDeviceToken)

        // Remove the cached binding as credentials are invalidated
        // UserDefaults.standard.removeObject(forKey: kCachedBindingDate)
    }

TL;DR Retain binding & cached token.

twilio / voice-quickstart-ios