We're seeing some new and odd behavior where our NEPacketTunnelProvider instance is receiving a stopTunnelWithReason:completionHandler: call with reason NEProviderStopReasonInternalError.
Can anyone shed some light into how to diagnose this situation?
Here are some basic details:
Our PacketTunnel has been in use for years and we only started seeing this issue recently.
We're able to reproduce this behavior with some light browsing.
The documentation provides no insight on why/when this might occur. Can anyone shed some light into how to diagnose this situation?
Things we’ve tried so far:
We grabbed a sysdiagnose and looked through the logs:
a. Right before the stopTunnel, we see log items referring to a "nesessionmanager" (PID 2038) getting killed. Presumably, this is due to hitting a highwater threshold. (See sysdiagnose items listing below)
b. Thinking these were due to memory pressure, we added logging of available/used memory.
c. We confirmed that the PacketTunnel was only using 11,808.73 KB.
d. Since, there is plenty of memory available the PacketTunnel was not killed for using too much memeory.
We wondered if this could be due to our UI's usage of objects like: NETunnelProviderManager and NETunnelProviderSession
a. We ran an experiment where we swiped closed the UI to ensure these manager/session objects are not used.
b. Without the UI, we still saw the random stopTunnel with NEProviderStopReasonInternalError.
We wondered if our routes were the problem, but they seem correct.
a. See the NEPacketTunnelNetworkSettings listing below
LISTING: From the system_logs.logarchive, the nesessionmanager log items:
2025-01-23 15:07:59.176146 -0800 0x278 memorystatus com.apple.xnu memorystatus: killing process 2038 [nesessionmanager] in high band ? (140) - memorystatus_available_pages: 18932 default kernel
2025-01-23 15:07:59.179641 -0800 0x278 memorystatus com.apple.xnu memorystatus: killing_highwater_process pid 2038 [nesessionmanager] (highwater 140) 7056KB - memorystatus_available_pages: 19161 compressor_size:69593 default kernel
2025-01-23 15:07:59.179888 -0800 0x278 memorystatus com.apple.xnu memorystatus: failed to kill a process and no memory was reclaimed default kernel
2025-01-23 15:07:59.185695 -0800 1 0x45e0c user/501/com.apple.nesessionmanager [2038] exited with exit reason (namespace: 1 code: 0x2) - JETSAM_REASON_MEMORY_HIGHWATER, ran for 266329ms default launchd
2025-01-23 15:07:59.231188 -0800 31 0x45bf2 com.apple.networkextension nesessionmanager(2038) exited default UserEventAgent
2025-01-23 15:07:59.253371 -0800 31 0x45bf2 com.apple.networkextension nesessionmanager exited with active sessions, re-launching nesessionmanager to clear agent status default UserEventAgent
LISTING: From the system_logs.logarchive, the stopTunnel from PID 2046
2025-01-23 15:07:59.201581 -0800 SamplePacketTunnel [Extension com.REDACTED.PacketTunnel]: Calling stopTunnelWithReason because: None
2025-01-23 15:08:20.783112 -0800 SamplePacketTunnel 2025-01-23 15:08:20,786 2046 ERROR REDACTED (285805) - Exiting after waiting for stopTunnelWithReason
LISTING: routes from NEPacketTunnelNetworkSettings
{
tunnelRemoteAddress = fd12:3456:789a:1::1
DNSSettings = {
protocol = cleartext
server = (
2606:4700:4700::1234,
2606:4700:4700::2345,
)
matchDomains = (
,
)
matchDomainsNoSearch = NO
}
IPv6Settings = {
configMethod = manual
addresses = (
fd12:3456:789a:1::1,
)
networkPrefixLengths = (
64,
)
includedRoutes = (
{
destinationAddress = 2606:4700:4700::2345
destinationNetworkPrefixLength = 128
},
{
destinationAddress = 2606:4700:4700::1234
destinationNetworkPrefixLength = 128
},
)
excludedRoutes = (
{
destinationAddress = REDACTED
destinationNetworkPrefixLength = 128
},
{
destinationAddress = REDACTED
destinationNetworkPrefixLength = 128
},
)
}
MTU = 3072
}
Thanks for taking a look, any help or suggestions would be greatly appreciated
Selecting any option will automatically load the page
Post
Replies
Boosts
Views
Activity
The documentation explains that the NEPacketTunnelProvider's sleepWithCompletionHandler: and wake methods are called when the device is going to sleep or waking up. The expectation is that the device will enter and remain in a sleep state for some extended period of time.
On iOS 17 we're seeing the PacketTunnelProvider receive wake calls almost immediately. Is there a known issue where the PacketTunnelProvider does Not remain in a sleep state?
In our logging, we see the PacketTunnelProvider is constantly alternating between sleep/wake states.
On iOS 16, these methods are called on an average of 42 seconds apart from each other.
In some cases, we do see the device in a sleep state for 2 to 3 minutes.
On iOS 17, these methods are called on an average of 6 seconds apart from each other.
The device only sleeps for a few seconds and Not for minutes.
This will drain the battery. Will the app be charged for battery usage if the OS decides Not to remain in sleep mode?
Is there a bug where the an iOS 17 device running a VPN will not stay in sleep mode?
Also, we do Not modify the NEVPNProtocol's disconnectOnSleep field. ie Should be defaulting to NO
On a device running iOS 16.3.1, with the screen locked and un-plugged from a power source
PID 4574: across 9.6 minutes (576 seconds)
Connected to Wi-Fi.
10 calls (5 sleep / 5 wake)
Avg frequency of 57.6 seconds apart.
PID 4581: across 10.3 minutes (616 seconds)
Wi-Fi disabled, Connected to Cellular.
22 calls (11 sleep / 11 wake)
Avg frequency of 28 seconds apart.
PID 4600: across 10.6 minutes (635 seconds)
Connected to Wi-Fi.
12 calls (6 sleep / 6 wake)
Avg frequency of 52.92 seconds apart.
(576 + 616 + 635) = 1827 seconds.
(10 + 22 + 12) = 44 calls.
1827 / 44 = 41.52 seconds.
On a device running iOS 17.0 (Build 21A5326a), connected to Wi-Fi:
PID 14357: across 94.7 minutes (5682 seconds)
1034 calls (517 sleep / 517 wake)
Avg frequency of 5.5 seconds apart.
PID 14412: across 92.5 minutes (5547 seconds)
508 calls (254 sleep / 254 wake)
Avg frequency of 10.9 seconds apart.
PID 14721: across 92.5 minutes (5547 seconds)
1248 calls (624 sleep / 624 wake)
Avg frequency of 4.4 seconds apart.
(5682 + 5547 + 5547) = 16776 seconds.
(1034 + 508 + 1248) = 2790 calls.
16776 / 2790 = 6.01 seconds.