Fails while establishing a VPN tunnel

I'm working on a network extension that provides a VPN tunnel. The logic behind the tunnel provider requires me to connect the backend to pull recent configuration and then configure the routing. It works in general but fails with some circumstances. I have 100% reproducible fails if I run OpenVPN tunnel in parallel. When it happens it looks like the network extension cannot connect the backend (any internet resource actually). Requests fail by timeout.

To troubleshoot this situations I've added NWPathMonitor at my NEPacketTunnelProvider subclass:

pathMonitor?.pathUpdateHandler = { path in

    logger.info("Path update: \(path)")
    logger.info("           : \(path.availableInterfaces)")
}

On successful scenarios I observed logs:

14:53:19:829  Starting VPN tunnel...
14:53:19:895  Path update: satisfied (Path is satisfied), interface: en0[802.11], scoped, ipv4, ipv6, dns, uses wifi 
14:53:19:899             : [en0] 
14:53:22:237  Path update: satisfied (Path is satisfied), interface: en0[802.11], scoped, ipv4, ipv6, dns, uses wifi 
14:53:22:253             : [en0, utun12] 
14:53:22:325  VPN tunnel is started. 

But if I start another tunnel first using OpenVPN (it's our corporate VPN) I observe failures with such log messages:

14:54:26:113  Starting VPN tunnel... 
14:54:26:140  Path update: satisfied (Path is satisfied), interface: en0[802.11], scoped, ipv4, ipv6, dns, uses wifi 
14:54:26:141             : [en0] 
14:55:28:259  Failed to start VPN tunnel.

utun12 that was used by the extension in case of success is now occupied by the OpenVPN tunnel. The system creates utun13 for me but it feels like its misconfigured:

> ifconfig
(omitted most of the output)
utun12: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> mtu 1500
	inet 172.28.11.236 --> 172.28.10.1 netmask 0xfffffe00
	nd6 options=201<PERFORMNUD,DAD>
utun13: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> mtu 1500
	options=6460<TSO4,TSO6,CHANNEL_IO,PARTIAL_CSUM,ZEROINVERT_CSUM>

Is it a system bug and what else can I do to diagnose the root cause of these failures?

So this is macOS, right?

Share and Enjoy

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

Yes, this is macOS

Some more information on the topic.

Here are the logs from the Console app for a successful sequence:

default	12:17:49.259885+0200	kernel	if_updown: utun12 is not attached
default	12:17:49.259927+0200	kernel	utun12: attached with 0 suspended link-layer multicast membership(s)
default	12:17:49.259933+0200	kernel	ifnet_attach: Waiting for all kernel threads created for interface utun12 to get scheduled at least once.
default	12:17:49.259941+0200	kernel	ifnet_attach: All kernel threads created for interface utun12 have been scheduled at least once. Proceeding.
default	12:17:49.260128+0200	nesessionmanager	getsockopt(UTUN_OPT_IFNAME) returned virtual interface name utun12
default	12:17:49.260163+0200	airportd	Driver Discovery: <airport[1189]> _interfaceAdded: utun12 added.
default	12:17:49.260186+0200	nesessionmanager	Created a new NEVirtualInterface "utun12" (7A0B6CE9-D92F-49F7-B9B7-2B4713D78034)
default	12:17:49.261063+0200	kernel	utun12: is now delegating en0 (type 0x6, family 2, sub-family 3)
default	12:17:49.261166+0200	com.my.cool.network.extension	Using interface name utun12
default	12:17:49.261219+0200	com.my.cool.network.extension	Created a new NEVirtualInterface "utun12" from socket
default	12:17:49.306250+0200	airportd	Driver Discovery: <airport[1189]> _interfaceAdded: utun12 is not an AirPort interface.
default	12:17:49.936284+0200	nesessionmanager	utun12: removing DNS
default	12:17:49.936371+0200	nesessionmanager	utun12: removing IPv4
default	12:17:49.936440+0200	nesessionmanager	utun12: removing IPv6
default	12:17:49.936542+0200	nesessionmanager	utun12: removing proxies
default	12:17:49.936568+0200	nesessionmanager	utun12: removing service dictionary
default	12:17:49.936976+0200	nesessionmanager	utun12: setting DNS to dictionary with keys: (
    ServerAddresses,
    SupplementalMatchDomains,
    SearchDomains
)
default	12:17:49.937052+0200	nesessionmanager	utun12: removing IPv4
default	12:17:49.937133+0200	nesessionmanager	utun12: removing IPv6
default	12:17:49.937211+0200	nesessionmanager	utun12: setting proxies to dictionary with keys: (
    FTPPassive
)
default	12:17:49.937241+0200	nesessionmanager	utun12: removing service dictionary
default	12:17:50.003511+0200	kernel	_dlil_attach_flowswitch_nexus: not attaching flowswitch to utun12
default	12:17:50.003520+0200	kernel	_dlil_attach_flowswitch_nexus: not attaching flowswitch to utun12
default	12:17:50.007412+0200	kernel	_dlil_attach_flowswitch_nexus: not attaching flowswitch to utun12
default	12:17:50.007422+0200	kernel	_dlil_attach_flowswitch_nexus: not attaching flowswitch to utun12
default	12:17:50.012506+0200	nesessionmanager	utun12: setting DNS to dictionary with keys: (
    ConfirmedServiceID,
    ServerAddresses,
    SearchDomains,
    SupplementalMatchDomains
)
default	12:17:50.013268+0200	nesessionmanager	utun12: setting IPv4 to dictionary with keys: (
    Router,
    AdditionalRoutes,
    ServerAddress,
    InterfaceName,
    Addresses
)
default	12:17:50.025320+0200	mDNSResponder	*** Network Configuration Change *** SC key: State:/Network/Interface/utun12/IPv4
default	12:17:50.033711+0200	mDNSResponder	*** Network Configuration Change *** SC key: State:/Network/Interface/utun12/IPv6
default	12:17:50.049101+0200	nesessionmanager	utun12: setting IPv6 to dictionary with keys: (
    PrefixLength,
    AdditionalRoutes,
    Router,
    ServerAddress,
    InterfaceName,
    Addresses
)
default	12:17:50.094795+0200	mDNSResponder	Interface not represented in list; marking active and retriggering queries - ifid: 31, ifname: utun12, ifaddr: <mask.hash: '8a4YjRU426n4aoobHYIE+Q=='>
default	12:17:50.094837+0200	mDNSResponder	SetupActiveInterfaces: Registered utun12 (31) BSSID <mask.hash: 'kJtfT6erwO/YvBLN2AXs/Q=='> Struct addr 0x156024c00, primary 0x156024c00, <mask.hash: '8a4YjRU426n4aoobHYIE+Q=='>/64 (Primary)
default	12:17:50.094852+0200	mDNSResponder	Interface already represented in list - ifid: 31, ifname: utun12, ifaddr: <mask.hash: 'LXjHHzNKtevmjyvB+o2I2w=='>
default	12:17:50.094878+0200	mDNSResponder	SetupActiveInterfaces: Registered utun12 (31) BSSID <mask.hash: 'kJtfT6erwO/YvBLN2AXs/Q=='> Struct addr 0x15681aa00, primary 0x156024c00, <mask.hash: 'LXjHHzNKtevmjyvB+o2I2w=='>/120
default	12:17:50.095516+0200	nesessionmanager	utun12: setting proxies to dictionary with keys: (
    FTPPassive
)
default	12:17:50.095675+0200	nesessionmanager	utun12: setting primary service dictionary to {
    PrimaryRank = First;
}
default	12:17:50.129605+0200	configd	effective_ifindex_get: utun12 (31): effective en0 (13)
default	12:17:50.133021+0200	configd	Host 10.64.5.7 Gate 10.64.5.7 Ifp utun12 Ifa 10.64.5.7 [first] [force]
default	12:17:50.133399+0200	configd	Host fc00:bbbb:bbbb:bb01::a40:507 Gate fc00:bbbb:bbbb:bb01::a40:507 Ifp utun12 Ifa fc00:bbbb:bbbb:bb01::a40:507 [first] [force]
default	12:17:50.175750+0200	configd	network changed: v4(utun12+:10.64.5.7, en0) v6(utun12+:fc00:bbbb:bbbb:bb01::a40:507, en0) DNS! Proxy+ SMB
default	12:17:50.196686+0200	sharingd	PrimaryIPv6 changed: fe80::82a9:97ff:fe2d:3990%utun12
default	12:17:50.196775+0200	sharingd	PrimaryIP changed: IPv4 10.64.5.7, IPv6 fe80::82a9:97ff:fe2d:3990%utun12
default	12:17:50.196815+0200	rapportd	PrimaryIPv6 changed: fe80::82a9:97ff:fe2d:3990%utun12
default	12:17:50.196908+0200	rapportd	PrimaryIP changed: IPv4 10.64.5.7, IPv6 fe80::82a9:97ff:fe2d:3990%utun12
default	12:17:50.198332+0200	AirPlayXPCHelper	PrimaryIPv6 changed: fe80::82a9:97ff:fe2d:3990%utun12
default	12:17:50.198395+0200	AirPlayXPCHelper	PrimaryIP changed: IPv4 10.64.5.7, IPv6 fe80::82a9:97ff:fe2d:3990%utun12
default	12:17:50.258420+0200	nesessionmanager	Changing primary physical interface: en0 => utun12

And this is the logs for a failure:

default	11:21:42.260263+0200	kernel	if_updown: utun15 is not attached
default	11:21:42.260356+0200	kernel	ifnet_attach: Waiting for all kernel threads created for interface utun15 to get scheduled at least once.
default	11:21:42.260365+0200	kernel	ifnet_attach: All kernel threads created for interface utun15 have been scheduled at least once. Proceeding.
default	11:21:42.260591+0200	nesessionmanager	getsockopt(UTUN_OPT_IFNAME) returned virtual interface name utun15
default	11:21:42.260653+0200	nesessionmanager	Created a new NEVirtualInterface "utun15" (D8510BB8-5EA6-48DC-A597-CC69E3580118)
default	11:21:42.261913+0200	airportd	Driver Discovery: <airport[1189]> _interfaceAdded: utun15 added.
default	11:21:42.262898+0200	kernel	utun15: is now delegating en0 (type 0x6, family 2, sub-family 3)
default	11:21:42.263102+0200	com.my.cool.network.extension	Using interface name utun15
default	11:21:42.263186+0200	com.my.cool.network.extension	Created a new NEVirtualInterface "utun15" from socket
default	11:21:42.319041+0200	airportd	Driver Discovery: <airport[1189]> _interfaceAdded: utun15 is not an AirPort interface.
default	11:22:12.378941+0200	nesessionmanager	utun15: removing DNS
default	11:22:12.379537+0200	nesessionmanager	utun15: removing IPv4
default	11:22:12.379745+0200	nesessionmanager	utun15: removing IPv6
default	11:22:12.380048+0200	nesessionmanager	utun15: removing proxies
default	11:22:12.380099+0200	nesessionmanager	utun15: removing service dictionary
default	11:22:12.380584+0200	nesessionmanager	Tearing down utun15
default	11:22:12.380740+0200	nesessionmanager	Tearing down utun15
default	11:22:12.381736+0200	com.my.cool.network.extension	Tearing down utun15
default	11:22:12.386054+0200	kernel	ifnet_detach_final: Waiting for IO references on utun15 interface to be released
default	11:22:12.389328+0200	com.my.cool.network.extension	Tearing down utun15

NESessionManager creates the virtual interface from the utun but doesn't configure it.

Fails while establishing a VPN tunnel
 
 
Q