Network Extension loads, then exits before entry point is called

We have a Network Extension app (packet_tunnel), and the development profile has multiple hardware IDs, certs etc.

If I build the app on one system and try to run it on a different macOS system which is in the profile I get an initial Gatekeeper error (as expected). I then approve the app to run anyway.

It runs, and when I connect to a VPN from that system the VPN extension is loaded, but then exits without calling the entry point.

My understanding is that signature verification is done *before* the binary is loaded, so if I'm seeing code in VPN extension writing to a log file, I know the signing as been checked & passed.

  • The class initializer for PacketTunnelProvider runs.

  • There's log output from the class initializer, so we know that the VPN extension has been loaded successfully

  • The entry point (startTunnelWithOptions:completionHandler:) is never called

  • The VPN extension exits

  • There's no crash log

On some systems it works fine, and the VPN is fine

We initially thought it was a signing problem, but since the binary is loading and running that's really looking like a red herring at the moment.





Up vote post of kjbrock Down vote post of kjbrock
870 views
Posted by
kjbrock
Reply
Add a Comment

Replies

For example, with debug & info logging on we see a lot of activity related to the VPN extension (1,2,3,5 for example), but in this case the log entry on line 21 at 00:05:05.631066+0530 is the last reference we see to the VPN extension. No further information in the log, and it's apparently unloaded. We see that it's written to our log file, and that it's been doing things on the network, then it's just... gone. No crash, no other messages.

Code Block 
info	00:05:05.625658+0530	VPNExtension	nw_endpoint_flow_setup_protocols [C1.1 IPv4#56bf189d:443 in_progress socket-flow (satisfied (Path is satisfied), interface: en0, ipv4, dns)] setup flow id FA94FBB5-6CF0-4974-854F-D52073CD57DB\
debug	00:05:05.625719+0530	VPNExtension	nw_endpoint_flow_attach_protocols [C1.1 IPv4#56bf189d:443 in_progress socket-flow (satisfied (Path is satisfied), interface: en0, ipv4, dns)]\
debug	00:05:05.625817+0530	VPNExtension	nw_endpoint_flow_attach_protocols_block_invoke [C1.1 IPv4#56bf189d:443 in_progress socket-flow (satisfied (Path is satisfied), interface: en0, ipv4, dns)] Attached application protocol: CFNetworkConnection-3468823992\
debug	00:05:05.628068+0530	syspolicyd	choosing ^.* (1,0x0)\
debug	00:05:05.626591+0530	VPNExtension	nw_endpoint_flow_attach_protocols_block_invoke [C1.1 IPv4#56bf189d:443 in_progress socket-flow (satisfied (Path is satisfied), interface: en0, ipv4, dns)] Attached application protocol: tls\
debug	00:05:05.628211+0530	syspolicyd	open(/Applications/Linphone.app/Contents/Resources/lib/pango/1.8.0/modules/pango-indic-lang.so,0x0,0x1b6) = 21\
default	00:05:05.626090+0530	mDNSResponder	[R1747->Q12734] AnswerQuestionByFollowingCNAME: 0x7f8581022c60 <mask.hash: 'Tye7PNEDcRS8vCdYY7aIwQ=='> (HTTPS) following CNAME referral 0 for <mask.hash: 'xOOjGbd0MZFsgiiKyCIgGg=='>\
debug	00:05:05.628257+0530	syspolicyd	21 fcntl(48,0x1) = 0\
default	00:05:05.626158+0530	mDNSResponder	[R1747->Q48033] Question for <mask.hash: 'wPu924/4LYJ1WNVfDCsVAQ=='> (HTTPS) assigned DNS service 5\
default	00:05:05.626240+0530	mDNSResponder	[R1747->Q26989] AnswerQuestionByFollowingCNAME: 0x7f858100d800 <mask.hash: 'Tye7PNEDcRS8vCdYY7aIwQ=='> (Addr) following CNAME referral 0 for <mask.hash: 'xOOjGbd0MZFsgiiKyCIgGg=='>\
default	00:05:05.626291+0530	mDNSResponder	[Q26989] Keeping orphaned querier for up to 5 seconds\
default	00:05:05.626410+0530	mDNSResponder	[Q26989] Received acceptable 138-byte response from <IPv4:BBJscklP> over UDP via en0/4 -- id: 0x297C (10620), flags: 0x8180 (R/Query, RD, RA, NoError), counts: 1/2/0/0, BBpqXFvf IN A?, 13 IN CNAME BBHoWxpi, 9 IN A BBLOAuUq\
default	00:05:05.626619+0530	mDNSResponder	[R1747->Q12298] Question for <mask.hash: 'wPu924/4LYJ1WNVfDCsVAQ=='> (Addr) assigned DNS service 5\
debug	00:05:05.629787+0530	syspolicyd	21 end of data\
debug	00:05:05.630037+0530	syspolicyd	close(21) err: 0\
debug	00:05:05.630111+0530	syspolicyd	Resources/lib/pango/1.8.0/modules/pango-indic-lang.so added simple (rule 0x7ff149432610)\
debug	00:05:05.630162+0530	syspolicyd	file /Applications/Linphone.app/Contents/Resources/lib/pango/1.8.0/modules/pango-basic-fc.so\
debug	00:05:05.630208+0530	syspolicyd	test Resources/lib/pango/1.8.0/modules/pango-basic-fc.so\
default	00:05:05.630497+0530	mDNSResponder	[R1747->Q48033] getaddrinfo result -- event: add, ifindex: 0, name: <mask.hash: 'wPu924/4LYJ1WNVfDCsVAQ=='>, type: HTTPS, rdata: <none> (mortal)\
debug	00:05:05.630250+0530	syspolicyd	try ^MacOS/Linphone$
default	00:05:05.631066+0530	kernel	memorystatus: assertion priority 14 overrides priority 0 for VPNExtension:11870\
debug	00:05:05.632297+0530	powerd	Global levels set to 0x1\
info	00:05:05.628648+0530	mDNSResponder	[Q26989] Querier concluded -- reason: response\
debug	00:05:05.632371+0530	powerd	getUserInactiveDuration: rdActive:1 hidActive:1 assertionActivityValid:1 now:0x55a4a  hid_ts:0x559e4 assertion_ts:0x55a4a\


Posted by
kjbrock
Up vote reply of kjbrock Down vote reply of kjbrock
Add a Comment
If you have done the following:

  1. With SIP enabled, build your container app that includes your extension.

  2. Navigate in Xcode and right click on the .app in the Products group and click "Show in Finder." From there, drag that .app into the /Application directory on your machine.

  3. Double click to run. Allow the installation of your Network System Extension.

  4. Configure your VPN Network Configuration and allow your Network Configuration to be installed on your machine. Double check the installation of this configuration in the System Preferences panel.

  5. Connect the VPN and call into your provider by calling: startTunnelWithOptions.

  6. Configure your tunnel and call setTunnelNetworkSettings.

And you have at a minumum these entitlements in your container app:

Code Block xml
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>com.apple.developer.networking.networkextension</key>
	<array>
		<string>packet-tunnel-provider</string>
	</array>
	<key>com.apple.developer.system-extension.install</key>
	<true/>
	<key>com.apple.security.app-sandbox</key>
	<true/>
	<key>com.apple.security.files.user-selected.read-write</key>
	<true/>
	<key>com.apple.security.network.client</key>
	<true/>
</dict>
</plist>


And these entitlements on your Network System Extension:

Code Block xml
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>com.apple.developer.networking.networkextension</key>
	<array>
		<string>packet-tunnel-provider</string>
	</array>
	<key>com.apple.security.app-sandbox</key>
	<true/>
	<key>com.apple.security.application-groups</key>
	<array>
		<string>$(TeamIdentifierPrefix)com.example.app-group</string>
	</array>
	<key>com.apple.security.files.user-selected.read-write</key>
	<true/>
	<key>com.apple.security.network.client</key>
	<true/>
</dict>
</plist>


And your Info.plist for your Network System Extension contains:

Code Block xml
<key>NetworkExtension</key>
<dict>
	<key>NEMachServiceName</key>
	<string>x.x.x.x</string>
	<key>NEProviderClasses</key>
	<dict>
		<key>com.apple.networkextension.packet-tunnel</key>
		<string>PacketTunnelProvider</string>
	</dict>
</dict>


Then you could have a code level issue when startTunnelWithOptions is being called that is preventing the logs from being generated from this context. Sometimes when I am debugging Network System Extension crashes, I will see erratic logs coming from these methods and that means my System Extension is starting over. I do not see anything in syspolicyd that is rejecting your app from running.


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