Network Extension – Delayed Startup Time

I've implemented a custom VPN system extension for macOS, utilizing Packet Tunnel Provider.

One of the users reported a problem: he was connected to the VPN, and then his Mac entered sleep mode. Upon waking, the VPN is supposed to connect automatically (because of the on-demand rules). The VPN's status changed to 'connecting', but it remained stuck in this status.

From my extension logs, I can see that the 'startTunnelWithOption()' function was called 2 minutes after the user clicked the 'connect' button.

From the system logs, I noticed some 'suspicious' logs, but I can't be sure if they are related to the problem. Some of them are:

kernel: (Sandbox) Sandbox: nesessionmanager(562) deny(1) system-fsctl (_IO "h" 47)

entitlement com.apple.developer.endpoint-security.client not present or not true (I don't need this entitlement at the extension)

nesessionmanager: [com.apple.networkextension:] NESMVPNSession[Primary Tunnel:XXXXXX(null)]: Skip a start command from YYYYY:session in state connecting

NetworkExtension.com.***: RunningBoard doesn't recognize submitted process - treating as a anonymous process

sysextd: activateDecision found existing entry of same version: state activated_enabled, ID FAE...

Are any of the logs related to the above problem? How can I debug such issues? What info should I get from the user?

Answered by DTS Engineer in 841862022
Written by roee84 in 841784022
Isn't it problematic that the extension is considered as an 'anonymous process'?

Not necessarily. runningboardd is primarily concerned with apps and app extensions. You’re creating a system extension, which isn’t known to runningboardd until it does something that triggers it to check in.

Written by roee84 in 841787022
I'm unable to reproduce it; all the above info is from the user's logs.

Yeah, that makes it hard. You can ask them enable additional logging per the VPN (Network Extension) for macOS instructions on our Bug Reporting > Profiles and Logs page. You can then focus on the com.apple.networkextension subsystem, which is the most likely source of relevant info here.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

At first blush this seems like the most relevant:

nesessionmanager: [com.apple.networkextension:] NESMVPNSession[Primary Tunnel:XXXXXX(null)]: Skip a start command from YYYYY:session in state connecting

That is, the systen thinks that the tunnel is connecting, so it can’t act on the connection immediately. Eventually the first connection attempt times out and then it connects again.

However, that’s really just a guess. Are you able to reproduce this yourself? Or are you just going on logs returned from this user?

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

However, that’s really just a guess. Are you able to reproduce this yourself? Or are you just going on logs returned from this user?

I'm unable to reproduce it; all the above info is from the user's logs.

That is, the systen thinks that the tunnel is connecting, so it can’t act on the connection immediately. Eventually the first connection attempt times out and then it connects again.

It sounds reasonable, but from the logs, the extension isn't running. Is there any way to solve or detect such cases? Is there any data I can ask the user to help understand what happened?

And what about this error: RunningBoard doesn't recognize submitted process - treating as a anonymous process.

Isn't it problematic that the extension is considered as an 'anonymous process'?

Accepted Answer
Written by roee84 in 841784022
Isn't it problematic that the extension is considered as an 'anonymous process'?

Not necessarily. runningboardd is primarily concerned with apps and app extensions. You’re creating a system extension, which isn’t known to runningboardd until it does something that triggers it to check in.

Written by roee84 in 841787022
I'm unable to reproduce it; all the above info is from the user's logs.

Yeah, that makes it hard. You can ask them enable additional logging per the VPN (Network Extension) for macOS instructions on our Bug Reporting > Profiles and Logs page. You can then focus on the com.apple.networkextension subsystem, which is the most likely source of relevant info here.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

Network Extension – Delayed Startup Time
 
 
Q