User Profile

Hello!I have been working on a Per-App VPN (AppProxy) extension.Things have been working well, and I receive UDP and TCP flows from the apps the MDM enabled App Tunneling on.However, while beta testing, I have noticed a bug that I can reproduce 100%: If my Per-App VPN is currently running, and the MDM pushes a new app to the phone, and that app is expected to be tunneled through my proxy, then that app does not have internet connection, and the app proxy receives no TCP or UDP flow until it is disconnected and reconnected.I have noticed that this reproduces 100% for apps that were not installed when they are pushed by the MDM. If the app was already installed and the MDM takes over management of the app, then this bug does sometime reproduce, but not easily.Steps to reproduceHave a device enroled with MDM + Per-App VPN setup on the MDMHave Connect On Demand enabled on the Per-App VPNStart an app (eg. Slack) that is expected to be tunneled through the Per-App VPN The VPN logo in the status bar should show, and the VPN should start connectingThe app should have connection through the VPNOn the MDM, assign a new app to the device (eg. Expensify) The app must not already be installed on the deviceThe app should have App Tunneling to the Per-App VPN enabledOn the device, accept installation of the app being pushedOnce installed, start the new app (eg. Expensify in our case)What should happenThe VPN logo shows in the status bar.The new app (Expensify) should have its traffic tunneled through the Per-App VPN.What actually happensThe VPN logo actually shows in the status bar; but...The new app (Expensify) is unable to access the network, and the Per-App VPN does not receive any TCP or UDP flow from it.Alternative scenarioIf the VPN is not connected when the app is pushed to the device, then everything works as expected: the VPN is started when the newly installed app makes a network connection (or any other tunnelled app for that matter).WorkaroundToggling "Connect On Demand" off and then on again fixes the issue.Basically, it feels like if the app is installed while the VPN is running, the tunneling won't work until the VPN restarts.More infoI had a look at sysdiagnose with mDNSResponder and VPN profiles installed. I compared both a working scenario and a failing scenario, and could not find any major differences. In all cases, the app profile was received, so the system was able to assign the VPN UUID to the app (as evidenced by the presence of the VPN logo in status bar in the failing case).The main difference in logs is when the app makes the first connection.In the working cases, it either starts the VPN, or connects to the already started VPN:2019-05-08 14:30:01.029292+0100 0x733 Info 0x0 111 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] 13: DNSServiceCreateConnection START PID[221](Expensify) 2019-05-08 14:30:01.029341+0100 0x733 Info 0x0 111 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] 13: DNSServiceGetAddrInfo(4000D000, 0, 3, ssl.google-analytics.com.) START PID[221](Expensify) [...] 2019-05-08 14:30:01.029418+0100 0xef0 Info 0x0 221 0 Expensify: (libnetwork.dylib) [com.apple.network:] nw_resolver_create_dns_service_locked Starting host resolution Hostname#125d7adf:0, flags 0x4000d000 proto 0 2019-05-08 14:30:01.029853+0100 0xd7e Default 0x0 22 0 UserEventAgent: (com.apple.networkextension) [com.apple.networkextension:] File Handle Maintainer got a readable event on Network Agent Registration socket (10) 74E9117E-DB87-447D-85FB-C7979F560B3B 5C412BF9-E740-4C4E-8515-EDA573C71651 2, launching owner 2019-05-08 14:30:01.030252+0100 0xe88 Default 0x0 150 0 nesessionmanager: [com.apple.networkextension:] NESMFlowDivertSession[MyPerAppVPN:74E9117E-DB87-447D-85FB-C7979F560B3B]: got On Demand start message from pid 111 2019-05-08 14:30:01.030547+0100 0x907 Info 0x0 150 0 nesessionmanager: (NetworkExtension) [com.apple.networkextension:] Handling a com.apple.networkextension.file-descriptor-maintainer event 2019-05-08 14:30:01.031631+0100 0xead Info 0x0 150 0 nesessionmanager: [com.apple.networkextension:] Registering session NESMFlowDivertSession[MyPerAppVPN:74E9117E-DB87-447D-85FB-C7979F560B3B] 2019-05-08 14:30:01.031751+0100 0xe88 Info 0x0 150 0 nesessionmanager: [com.apple.networkextension:] NESMFlowDivertSession[MyPerAppVPN:74E9117E-DB87-447D-85FB-C7979F560B3B]: enabled = 1 2019-05-08 14:30:01.031879+0100 0xe88 Default 0x0 150 0 nesessionmanager: [com.apple.networkextension:] NESMFlowDivertSession[MyPerAppVPN:74E9117E-DB87-447D-85FB-C7979F560B3B]: Received a start command from mDNSResponder[111] 2019-05-08 14:30:01.035844+0100 0xe88 Info 0x0 150 0 nesessionmanager: [com.apple.networkextension:Large] NESMFlowDivertSession[MyPerAppVPN:74E9117E-DB87-447D-85FB-C7979F560B3B] starting with configuration: { ... } 2019-05-08 14:30:01.035992+0100 0xe88 Info 0x0 150 0 nesessionmanager: [com.apple.networkextension:] NESMFlowDivertSession[MyPerAppVPN:74E9117E-DB87-447D-85FB-C7979F560B3B] is no longer idle, beginning transaction 2019-05-08 14:30:01.035999+0100 0xe88 Info 0x0 150 0 nesessionmanager: [com.apple.networkextension:] Active session count is greater than 0, setting hasActiveSessions flag 2019-05-08 14:30:01.036042+0100 0xe88 Default 0x0 150 0 nesessionmanager: [com.apple.networkextension:] NESMFlowDivertSession[MyPerAppVPN:74E9117E-DB87-447D-85FB-C7979F560B3B]: status changed to connectingIn the failing case, the system complains that the connecting app "did not match" (whatever that means):2019-05-08 15:31:35.689370+0100 0x730 Info 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] 14: DNSServiceCreateConnection START PID[280](Expensify) 2019-05-08 15:31:35.689431+0100 0x730 Info 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] DNSServiceGetAddrInfo: kDNSServiceFlagsServiceIndex is SET by the client 2019-05-08 15:31:35.689435+0100 0x730 Info 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] 14: DNSServiceGetAddrInfo(5000D000, 0, 3, ssl.google-analytics.com.) START PID[280](Expensify) 2019-05-08 15:31:35.689441+0100 0x730 Info 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] InitCommonState: Query for ssl.google-analytics.com. (AAAA), PID[280], EUID[501], ServiceID[2] is already set by client 2019-05-08 15:31:35.689446+0100 0x730 Info 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] GetServerForQuestion: 000000015A00F960 DNS server (0000000159D209E0) 1.1.1.1:53 (Penalty Time Left 0) (Scope None:0000000000000000:2) for ssl.google-analytics.com. (AAAA) 2019-05-08 15:31:35.689451+0100 0x730 Info 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] InitCommonState: Query for ssl.google-analytics.com. (Addr), PID[280], EUID[501], ServiceID[2] is already set by client 2019-05-08 15:31:35.689453+0100 0x730 Info 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] GetServerForQuestion: 000000015A00F4C8 DNS server (0000000159D209E0) 1.1.1.1:53 (Penalty Time Left 0) (Scope None:0000000000000000:2) for ssl.google-analytics.com. (Addr) 2019-05-08 15:31:35.689497+0100 0x230d Info 0x0 280 0 Expensify: (libnetwork.dylib) [com.apple.network:] nw_resolver_create_dns_service_locked Scoping resolution to ServiceIndex [2] 2019-05-08 15:31:35.689525+0100 0x230d Info 0x0 280 0 Expensify: (libnetwork.dylib) [com.apple.network:] nw_resolver_create_dns_service_locked Starting host resolution Hostname#4287c414:0, flags 0x5000d000 proto 0 2019-05-08 15:31:35.689645+0100 0x730 Info 0x0 0 0 kernel: (1444299557): Created 2019-05-08 15:31:35.689647+0100 0x730 Info 0x0 0 0 kernel: (1444299557): implicit connect 2019-05-08 15:31:35.689649+0100 0x730 Info 0x0 0 0 kernel: (1444299557): Connecting 2019-05-08 15:31:35.689652+0100 0x730 Default 0x0 0 0 kernel: (1444299557): com.expensify.expensifylite did not match 2019-05-08 15:31:35.689657+0100 0x730 Info 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] mDNSPlatformSendUDP -> sendto(15) failed to send packet on InterfaceID 0000000000000000 unicast/4 to 1.1.1.1:53 skt 15 error -1 errno 1 (Operation not permitted) 973609381 2019-05-08 15:31:35.689659+0100 0x730 Default 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] mDNSPlatformSendUDP: sendto(15) failed to send packet on InterfaceID 0000000000000000 unicast/4 to 1.1.1.1:53 skt 15 error -1 errno 1 (Operation not permitted) 973609381 MessageCount is 1 2019-05-08 15:31:35.689661+0100 0x730 Info 0x0 121 0 mDNSResponder: [com.apple.mDNSResponder:AllINFO] ERROR -65537 Sending UDP DNS Message 42 bytes from port 59922 to 1.1.1.1:53I know this looks pretty much like a bug report, but I do not know whether this is an Apple bug, or whether I am not doing things right.For info:Connect On Demand is enabled (on demand rules are "action = connect" and "interface type match = any")My proxy sets a few settings (namely NEDNSSettings) before calling the callback given in startProxyIt does not set any disconnect rulesThis happens on 12.0.1 as well as 12.2TL;DRWhen a Per-App VPN is running, and an app configured to be tunneled is pushed by the MDM, that app's network traffic is not sent to the VPN until VPN is restarted.The question is: am I missing something? Is there some configuration I am expected to set, or is there a callback I can set, to be able to support that case?Or is this a bug I should report?