Observers observe NEVPNStatusDidChange multiple times when loading NEPacketTunnelProvider more than once

I have an app that implements my own Packet Tunnel Provider, and to my knowledge everything I do is working as intended. However, I came across an issue with NEVPNStatusDidChange NotificationCentre observations when calling the following function multiple times:
Code Block 
NETunnelProviderManager:loadAllFromPreferences(completionHandler:)


From the documentation:

You must call loadFromPreferences(completionHandler:): at least once before calling this method the first time after your app launches.

As a result of this note, an early implementation I had took a very conservative approach; calling loadFromPreferences(completionHandler:): every time before operating on my NEPacketTunnelProvider. This was done by a helper function which was run as a precursor to any operation done to the manager, ensuring that the latest manager was being used every time. This looked something like:
Code Block 
func myStartVPN() {
		loadHelper { (manager: NEPacketTunnelProvider, error: Error?) in
				/* handle errors */
				startVPN(withManager: manager)
		}
}

When using this approach, I noticed that observers that look for NEVPNStatusDidChange events got triggered multiple times for these events, with the number of times it being triggered machine the number of times I called loadAllFromPreferences(). Chronologically speaking I was experiencing something along the lines of Appendix 1.

As a result of this issue, my production equivalent of loadHelper(), above, only calls load once the first time a manager is requied, and then subsequent operations on the manager use a cached value - a bit like a standard lazy field.

Obviously this is not a big issue as I have a working solution, however I haven't been able to work out what causes this behaviour - does anyone have any ideas?

  • Could it be a general Swift/Objective C pitfall with KVO that I am not aware of?

  • Could it be some sort of issue with NetworkExtension/my approach? (I'm thinking some references might not be being cleaned up every time I load?)


Appendix 1

  1. Previously set up NEPacketTunnelProvider*

  2. loadAllFromPreferences() followed by saveManager()

  3. Recieve NEVPNStatusDidChange - Disconnected

  4. loadAllFromPreferences() followed by startVPNTunnel()

  5. Recieve NEVPNStatusDidChange - Connecting x2

  6. Recieve NEVPNStatusDidChange - Connected x2

  7. loadAllFromPreferences() followed by stopVPNTunnel()

  8. Recieve NEVPNStatusDidChange - Disconnecting x3

  9. Recieve NEVPNStatusDidChange - Disconnected x3

  10. loadAllFromPreferences() followed by startVPNTunnel()

  11. Recieve NEVPNStatusDidChange - Connecting x4

  12. Recieve NEVPNStatusDidChange - Connected x4

  13. loadAllFromPreferences() followed by stopVPNTunnel()

  14. Recieve NEVPNStatusDidChange - Disconnecting x5

  15. Recieve NEVPNStatusDidChange - Disconnected x5

Up vote post of UltraHorizonAW Down vote post of UltraHorizonAW
1.6k views
Posted by
UltraHorizonAW
Reply
Add a Comment

Replies

I have seen conditions where a case will be called twice, but having a case called 3, 4, and 5 times is odd. How is your observer setup for NEVPNStatusDidChange? Are you adding a new observer every time a certain conditions takes place?


Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com
Posted by
meaton
Up vote reply of meaton Down vote reply of meaton
Add a Comment
I'm running into the extract same issue. Every time loadAllFromPreferences() is called, later there is one more notification on NEVPNStatusDidChange. For example, after 12 calls, the view controller will receive 12 Connecting status notifications followed by 12 Connected notifications, or 12 Disconnecting followed by 12 Disconnected notifications.

To answer @Matt's question, in my case, I've made sure I'm only calling addListener once: put them in viewDidLoad, and with logs showing when the function is called, plus I removeObserver() right before I addObserver(). I can see clearly addObserver is only called once. But the number of notifications keeps increasing for the same VPN status as more calls to loadAllFromPreferences are made.

My experiments seem to indicate that this is a side effect of calling loadAllFromPreferences. Each call to loadAllFromPreferences seems to keep its own copy/reference of the vpnManagers array that keeps sending notifications to the observers.

In my case, in order to get a vpnManager properly, I follow recommendations from this forum in this weird way and it works! Not sure if it has anything to do with this issue.

  1. call loadAllFromPreferences()

  2. call saveToPreferences()

  3. call loadAllFromPreferences() for the 2nd time; vpnManagers[0] is what I need


Posted by
a2zit
Up vote reply of a2zit Down vote reply of a2zit
Add a Comment
After discussing this further internally, there is not one-to-one mapping guarantee between changes and notifications. You should use the notification to look at the state of the system and adjust accordingly and all other redundant notifications I would ignore.

Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com
Posted by
meaton
Up vote reply of meaton Down vote reply of meaton
Add a Comment
@meaton - so it is not considered a bug? In case where NEPacketTunnelProvider fails connection fast, it's easy to get into situation with hundreds of notifications flooding the app.
Posted by
jaroslavqwerty
Post not yet marked as solved Up vote reply of jaroslavqwerty Down vote reply of jaroslavqwerty
Add a Comment

@meaton - so it is not considered a bug?

While you can get into a situation with several redundant notifications I do not think this is a bug because the system is giving your correct information. If the information was incorrect then it would be another story. Having said that, if this is causing you grief then you are welcome to open a bug report.


Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com
Posted by
meaton
Up vote reply of meaton Down vote reply of meaton
Add a Comment

Hello,

I have been trying to resolve this issue for days and luckily came across this post here. This is indeed a bug and should be fixed. This is usually an indication of a memory leak, when NEVPNStatusDidChange still get fired by previous managers that have been reconfigured through loadAllFromPreferences().

Our users are complaining the the app slows down after some time and they have to kill the app from memory. We have observed the logs and there are hundreds of notifications accumulating depending on how many times they the user has connected and disconnected from various vpn servers.

Has anyone raised this bug yet? Or should I do it?

Many Thanks,

Posted by
houmie
Up vote reply of houmie Down vote reply of houmie
Add a Comment

@houmie

Has anyone raised this bug yet? Or should I do it?

If you feel that this is a bug then please open up a bug report.

Regarding:

This is usually an indication of a memory leak Our users are complaining the the app slows down after some time and they have to kill the app from memory.

What you are describing above in the context of a packet tunnel VPN specifically could be an issue with how you are handling flow control. Make sure that you are handling the memory accumulated in your provider so that memory pressure does not build up and terminate you extension. Quinn wrote a post about this topic called Network Extension Provider Memory Strategy.

Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com
Posted by
meaton
Up vote reply of meaton Down vote reply of meaton
Add a Comment