Reconnect short after first connect: "Socket has a better path"

[joosth9n]

@efef reported earlier in #307 (comment):

On 10.15.4. I successfully connected the eduVPN app (2.1.7) to nl.eduvnp.org. The icon became 'green'. I did not yet see ipaddress. Next icon become yellow and reconnect happened spontaneously.

The following logging came with this comment:

connection_log.connect_disconnect_connect.txt
console_log.connect_disconnect_connect.txt

And logging for the same symptom again later:

disconnect2_console.txt
disconnect2.txt

@efef reported to me this symptom comes back every now and then, but it isn't clear when yet. There is no method known yet to reproduce this issue.

I had this exact same symptom before, but only one time, with both the eduVPN app and the Let's Connect app. In both cases the connection was restored after ~30 seconds. In logging I saw the same as in the logging provided by @efef :

2020-06-05 10:20:48.117 DEBUG NEUDPSocket.observeValueInTunnelQueue():179 - Socket has a better path
2020-06-05 10:20:48.117 DEBUG OpenVPNTunnelProvider.socketHasBetterPath():506 - Stopping tunnel due to a new better path
2020-06-05 10:20:48.117 DEBUG OpenVPNTunnelProvider.logCurrentSSID():826 - Current SSID: none (disconnected from WiFi)
2020-06-05 10:20:48.125 ERROR OpenVPNSession.doReconnect():1290 - Trigger reconnection (error: networkChanged)
2020-06-05 10:20:48.125 ERROR OpenVPNTunnelProvider.sessionDidStop():584 - Session did stop with error: networkChanged

I didn't find a way yet to reproduce it (including a reboot for example), every subsequent Connect runs fine.

This symptom and logging "Socket has a better path" should happen in case "For example, if the session is established over a cellular data network and Wi-Fi is now available, then the session has a better path available" and will cause a reconnect. ( https://developer.apple.com/documentation/networkextension/nwudpsession/1406231-hasbetterpath )
It's not clear to me yet why this would happen in for example my case when I wasn't switching networks and upon a first connect.

[efef]

I can quite trivial reproduce the issue in a 'clean' macOS VM. When I install the eduVPN app, next login to vpn.spoor.nu, the VPN connects and quickly disconnects.

In the App-log I read:
2020-06-22 14:21:25.022 DEBUG NEUDPSocket.observeValueInTunnelQueue():179 - Socket has a better path
2020-06-22 14:21:25.022 DEBUG OpenVPNTunnelProvider.socketHasBetterPath():506 - Stopping tunnel due to a new better path

Included are both the applog as console log. The console log was obtained by searching for "process eduVPN". This is the full log file including minutes before the event happened.

In console log is visible:
info 14:21:25.016728 +0200 EduVPNTunnelExtension-macOS nw_endpoint_handler_get_alternate_path_state [C1 IPv4#42722e29:1194 ready socket-flow (satisfied)] better path satisfied (Path is satisfied), interface: utun1, scoped, ipv4, ipv6 preferred to path satisfied (Path is satisfied), interface: en0, scoped, ipv4, dns

Get the impression, when the VPN turned ON, a new NIC (utun1) became available and the client thinks this utun1 is a better path than the native interface (en0).

connect_disconnect_21jun_applog.txt
connect_disconnect_21jun.txt