iOS doesn't handle incoming call of Local PUSH when receiving a Local PUSH after receiving an APNs PUSH

I am developing an application that uses NetworkExtension (Local PUSH function) And VoIP(APNs) PUSH. Nowadays, I found a problem on this app doesn't handle incoming call of Local PUSH when receiving a Local PUSH after receiving an APNs PUSH.

My confimation result of my app and server log is below.

11:00 AM:

my server(PBX) requests a VoIP(APNs) PUSH notification to the APNs. But my app does not receive the VoIP(APNs) PUSH. At this time, my app is running on LAN (Wi-Fi without internet connection), as a result, NetworkExtension was running. so I think this is normal behaviour.

14:55:11 PM:

There is an incoming call from the my server(PBX) via local net, and NetworkExtension calls iOS API(API name is reportIncomingCall). However, iOS does not call the delegate didReceiveIncomingCallWithUserInfo for the reportIncomingCall.

14:55:11 PM:

At almost the same time, iOS calls the delegate cdidReceiveIncomingPushWithPayload of VoIP PUSH. (instead of call the delegate didReceiveIncomingCallWithUserInfo for the reportIncomingCall?) And the content of this VoIP(APNs) PUSH was the incoming call at "11:00 AM".

In other words, the VoIP(APNs) PUSH at 11:00 AM is stuck inside iOS, and at 14:55:11 PM, from NetworkExtension reports it.

I feel there is a problem on iOS doesn't handle incoming call of Local PUSH when receiving a Local PUSH after receiving an VoIP(APNs) PUSH. Would you tell me Apple's opioion about this?

If this is known problem, Please tell me about it.

Answered by DTS Engineer in 822533022

my server(PBX) requests a VoIP(APNs) PUSH notification to the APNs. But my app does not receive the VoIP(APNs) PUSH. At this time, my app is running on LAN (Wi-Fi without internet connection), as a result, NetworkExtension was running. so I think this is normal behaviour.

Just to clarify here, the system doesn't differentiate or attempt any kind of de-duplication or arbitration between VOIP pushes and the network extension. The voip push can fail to reach your device because the device is on an isolated network, but that's no different than any other failed voip push.

14:55:11 PM: There is an incoming call from the my server(PBX) via local net, and NetworkExtension calls iOS API(API name is reportIncomingCall). However, iOS does not call the delegate didReceiveIncomingCallWithUserInfo for the reportIncomingCall.

14:55:11 PM: At almost the same time, iOS calls the delegate cdidReceiveIncomingPushWithPayload of VoIP PUSH. (instead of call the delegate didReceiveIncomingCallWithUserInfo for the reportIncomingCall?) And the content of this VoIP(APNs) PUSH was the incoming call at "11:00 AM".

Looking at the flow above, my big question is exactly how you "know" what you "know" here. That is, you're describing a chain of behavior above, but how exactly did you determine that flow?

Notably, while callservicesd handles the final delivery for both of these APIs, the paths than handle that delivery are separated in a way that should make it impossible for messages to be delivered to the "wrong" path.

One question on this point:

At this time, my app is running on LAN (Wi-Fi without internet connection), as a result, NetworkExtension was running. so I think this is normal behaviour.

Did your local push connectivity receive this case? If not, why not?

Similarly, is there any way you could have been wrong about exactly what delegates got called a what point in time? What you're describing doesn't make sense, but there is a slightly different failure I have seen in that past which looks somewhat similar.

The issue here is that NEAppPushManager has a MUCH shorter "wake window" PKPushRegistry. For historical reason, PKPushRegistry can actually keep the app awake for a fairly long period of time (several seconds), enough time that a sequence like this can happen:

  1. PKPushRegistry wakes app up and delivers push.
  2. App reports call to CallKit (as required) and returns from the delegate.
  3. PKPushRegistry keeps the app awake.
  4. CallKit call finishes starts and initialization, keeping the app awake.

The critical point her is that CallKit call creation is inherently asynchronous, so new call doesn't actually "keep the app awake" until a short time AFTER it's created. PKPushRegistry ends up "covering up" that time gap, by keeping the app awake on it's own.

However, (arguably, correctly) NEAppPushManager does NOT do this. In the EXACT same sequence above, what can happen is the following:

  1. NEAppPushManager wakes app up and delivers push.
  2. App reports call to CallKit (as required) and returns from the delegate.
  3. Call initialization starts (enough to prevent app termination).
  4. App suspends (because nothing is keeping it awake).
  5. ...time passes...
  6. "something else" wakes the app up (for example, a voip push), and the app the proceeds with it's "normal" call logic, generally not realizing that #5 has occurred.

In any case, the solution here is that voip apps should start their own background task inside the call delegate and end that background task at some later point, after the call has started. Note that this approach should be used for BOTH PKPushRegistry and NEAppPushManager, as it ensures the app has a reliable lifetime regardless of system behavior.

In other words, the VoIP(APNs) PUSH at 11:00 AM is stuck inside iOS, and at 14:55:11 PM, from NetworkExtension reports it.

Have you captured a sysdiagnose of the issue and what does the console log from that sysdiagnose show? Bug number?

__
Kevin Elliott
DTS Engineer, CoreOS/Hardware

my server(PBX) requests a VoIP(APNs) PUSH notification to the APNs. But my app does not receive the VoIP(APNs) PUSH. At this time, my app is running on LAN (Wi-Fi without internet connection), as a result, NetworkExtension was running. so I think this is normal behaviour.

Just to clarify here, the system doesn't differentiate or attempt any kind of de-duplication or arbitration between VOIP pushes and the network extension. The voip push can fail to reach your device because the device is on an isolated network, but that's no different than any other failed voip push.

14:55:11 PM: There is an incoming call from the my server(PBX) via local net, and NetworkExtension calls iOS API(API name is reportIncomingCall). However, iOS does not call the delegate didReceiveIncomingCallWithUserInfo for the reportIncomingCall.

14:55:11 PM: At almost the same time, iOS calls the delegate cdidReceiveIncomingPushWithPayload of VoIP PUSH. (instead of call the delegate didReceiveIncomingCallWithUserInfo for the reportIncomingCall?) And the content of this VoIP(APNs) PUSH was the incoming call at "11:00 AM".

Looking at the flow above, my big question is exactly how you "know" what you "know" here. That is, you're describing a chain of behavior above, but how exactly did you determine that flow?

Notably, while callservicesd handles the final delivery for both of these APIs, the paths than handle that delivery are separated in a way that should make it impossible for messages to be delivered to the "wrong" path.

One question on this point:

At this time, my app is running on LAN (Wi-Fi without internet connection), as a result, NetworkExtension was running. so I think this is normal behaviour.

Did your local push connectivity receive this case? If not, why not?

Similarly, is there any way you could have been wrong about exactly what delegates got called a what point in time? What you're describing doesn't make sense, but there is a slightly different failure I have seen in that past which looks somewhat similar.

The issue here is that NEAppPushManager has a MUCH shorter "wake window" PKPushRegistry. For historical reason, PKPushRegistry can actually keep the app awake for a fairly long period of time (several seconds), enough time that a sequence like this can happen:

  1. PKPushRegistry wakes app up and delivers push.
  2. App reports call to CallKit (as required) and returns from the delegate.
  3. PKPushRegistry keeps the app awake.
  4. CallKit call finishes starts and initialization, keeping the app awake.

The critical point her is that CallKit call creation is inherently asynchronous, so new call doesn't actually "keep the app awake" until a short time AFTER it's created. PKPushRegistry ends up "covering up" that time gap, by keeping the app awake on it's own.

However, (arguably, correctly) NEAppPushManager does NOT do this. In the EXACT same sequence above, what can happen is the following:

  1. NEAppPushManager wakes app up and delivers push.
  2. App reports call to CallKit (as required) and returns from the delegate.
  3. Call initialization starts (enough to prevent app termination).
  4. App suspends (because nothing is keeping it awake).
  5. ...time passes...
  6. "something else" wakes the app up (for example, a voip push), and the app the proceeds with it's "normal" call logic, generally not realizing that #5 has occurred.

In any case, the solution here is that voip apps should start their own background task inside the call delegate and end that background task at some later point, after the call has started. Note that this approach should be used for BOTH PKPushRegistry and NEAppPushManager, as it ensures the app has a reliable lifetime regardless of system behavior.

In other words, the VoIP(APNs) PUSH at 11:00 AM is stuck inside iOS, and at 14:55:11 PM, from NetworkExtension reports it.

Have you captured a sysdiagnose of the issue and what does the console log from that sysdiagnose show? Bug number?

__
Kevin Elliott
DTS Engineer, CoreOS/Hardware

Just to clarify here, the system doesn't differentiate or attempt any kind of de-duplication or arbitration between VOIP pushes and the network extension. The voip push can fail to reach your device because the device is on an isolated network, but that's no different than any other failed voip push.

You mean, the composition of iOS internal components, it is difficult to imagine that Local Push will be replaced by VoIP Push. Correct?

The "11:00 AM:, 14:55:11 PM:, 14:55:11 PM:" events in my report are facts obtained from the logs of My App and our PUSH server. But I haven't looked at the iOS logs, so I may be misunderstanding something. Would a sysdiagnose be necessary to perform a more detailed analysis?

However, at this time, I couldn't be collected sysdiagnose.

**Do you need sysdiagnose? **

If the problem that occurs infrequently, it may be difficult to collect a sysdiagnose, but if you need it, I will try to collect it.

In any case, the solution here is that voip apps should start their own background task inside the call delegate and end that background task at some later point, after the call has started. Note that this approach should be used for BOTH PKPushRegistry and NEAppPushManager, as it ensures the app has a reliable lifetime regardless of system behavior.

Thank you for your advice. Don't worry about them. We already do.

You mean, the composition of iOS internal components, it is difficult to imagine that Local Push will be replaced by VoIP Push. Correct?

Correct. More specifically, while callservicesd handles the delivery of both events, they're both received (meaning, how they reach callservicesd) and sent (meaning, how callservicesd send them to your app) through totally different paths.

__
Kevin Elliott
DTS Engineer, CoreOS/Hardware

Hi Kevin

Thank you for your kind reply. There was a mistake in my initial inquiry. I apologize.

I will correct the mistake, so could you please check again?

11:00 AM:

The PBX server requests a VoIP PUSH notification from APNs. The app was connected to the Internet, but did not receive VoIP PUSH.

** There was an error in the explanation here last time. ** It is unclear whether the iPhone was within the range of a network that could connect to the Internet or outside of it.

It is certain that it is not connected to the LAN (Wi-Fi) at least. The extension is not working.

The following are hypotheses.

  1. The APNs server was unable to send the VoIP PUSH to the iPhone. Or...,

  2. The VoIP PUSH reached the iPhone, but the delegate (didReceiveIncomingPushWithPayload) was not called.

14:31 PM:

The iPhone connected to the LAN (Wi-Fi). The extension started working.

14:55:11 PM:

A call comes in from my server (PBX) via the local network, and NetworkExtension calls the iOS API (API name is reportIncomingCall).

However, iOS does not call the delegate didReceiveIncomingCallWithUserInfo for reportIncomingCall.

14:55:11 PM:

At almost the same time, iOS calls the VoIP PUSH delegate didReceiveIncomingPushWithPayload.

(Instead of calling the delegate didReceiveIncomingCallWithUserInfo for reportIncomingCall?)

The content of this VoIP (APNs) PUSH was the 11:00 AM call.

This is just my guess.

It is unlikely that APNs notified the VoIP PUSH that occurred at 11:00 AM at 14:55:11 PM (due to processing delay). The 11:00 VoIP PUSH reached the iPhone, but got stuck inside iOS. At 14:55:11 PM, the extension called reportIncomingCall, which triggered the VoIP PUSH delegate didReceiveIncomingPushWithPayload to be called.

We apologize for the confusion.

Unfortunately, we were unable to obtain diagnostic logs and have not issued a bugreport.

Could you please let us know if there is a known issue? Is there a possibility that this can be avoided by implementing it on the application side?

Best Regards,

Since then, I have repeated the test, but the same problem has not recurred, and I have not been able to take a diagnostic log. I don't think we can investigate without the log, but could you let me know there was a similar reports or not before?

Best Regards,

It is unlikely that APNs notified the VoIP PUSH that occurred at 11:00 AM at 14:55:11 PM (due to processing delay).

Unfortunately, that's not entirely correct. There is a longstanding issue with APNS which can cause it to deliver a push WELL outside that pushes expiration time. Making that explicit, it is ENTIRELY possible for this sequence to occur:

  1. Your server sends voip push at 11:00 AM with "apns-expiration=0" (immediately).

  2. The push is (incorrectly) queued for later delivery.

  3. The device is able to connect to APNS again at ~14:55:11

  4. The voip push is delivered to your aps ~2 hours after it expired.

I'd strongly encourage you to file bugs on this and, if you do so, please post the bug number back here. A few clarifying notes on this:

  • This issue requires very specific timing, which which why it isn't move obvious/visible.

  • Using a apns-expiration > 0 will GREATLY increase the likelihood that this occurs. This is the main reason voip apps should use "apns-expiration=0".

  • This is NOT a new/recent issues. This has ALWAYS been possible in "general" APNS and it has been happening for PushKit's entire history.

The 11:00 VoIP PUSH reached the iPhone, but got stuck inside iOS.

No, I do not believe this happened. More specifically:

  • Having spent significant time in callservicesd's code, its design just doesn't really leave "space" for this kind of failure.

  • Anecdotally, I have never seen ANY case where the system delayed push delivery in any meaningful way. I've never seen the time between apnsd receiving a push and callservicesd initiating delivering to then app take more than ~0.5s and the normal latency is even lower. Indeed, the VAST majority of app launches take FAR longer than the push processing pipeline.

Making this as clear as possible, many developers believe that there are cases where iOS receives a push and then delays delivery to the app for some significant period of time. I have never seen ANY evidence of that occurring and, at this point, do not believe it happens. In EVERY case I've investigated, these delays/issues were in fact caused by either (or both):

  • Network/APNS issues delaying delivery to the device.

OR

  • Issues in the app itself causing the failure.

At 14:55:11 PM, the extension called reportIncomingCall, which triggered the VoIP PUSH delegate didReceiveIncomingPushWithPayload to be called.

I'm skeptical that this occurred*, but would need to see a sysdiagnose log to be sure of that point.

*I do have one theory of how this could occur. That sequence would look something like this:

  1. App launch and registers it's the extension delegate but does NOT register it's PushKit delegate. Note that this is a SERIOUS bug in the app.

  2. An incoming call report is sent through both local push and PushKit.

  3. The PushKit push is queued for delivery but NOT delivered (because the PushKit delegate is NOT registered).

  4. The local push delegate receives the report and calls reportNewIncomingCall. This will prevent the app from crashing, even though it has not actually received the PushKit callback.

  5. Time passes...

  6. At some point, the app finally creates a PKPushRegistry object and register a delegate.

  7. The delegate will be called and the push from #3 will be called.

Again, note that #1 means that the app already has a very serious bug and the particular case above is simply an odd edge case of how this can play out.

__
Kevin Elliott
DTS Engineer, CoreOS/Hardware

iOS doesn't handle incoming call of Local PUSH when receiving a Local PUSH after receiving an APNs PUSH
 
 
Q