I am maintaining a project, and I just started, so I don't know the codebase very well. My first task was to update the Wireguard library that the project makes use of to the latest version. After I did so, the application refuses to connect through wireguard. I am pretty certain that the part of the app that does not work is the entry in network preferences that my app creates. In the version that works, the installed entry is capable of connecting without the app running, in the version that does not connect, the entry does not work. I tried to log in console:
For the version that works, the log was:
default 01:34:22.934533+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Adding a connection for client com.apple.preference.network.re[2011]
default 01:34:35.530616+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Received a start command from com.apple.preference.network.re[2011]
default 01:34:35.530683+0100 nesessionmanager Registering session NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]
default 01:34:35.531061+0100 nesessionmanager <NESMServer: 0x7fb9a35040a0>: Register Enterprise VPN Session: NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]
default 01:34:35.531107+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Successfully registered
default 01:34:35.531142+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Changing pause level 1 -> 0
default 01:34:35.532532+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: status changed to connecting
default 01:34:35.532738+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)] in state NESMVPNSessionStateIdle: received start message
default 01:34:35.532783+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Leaving state NESMVPNSessionStateIdle
default 01:34:35.532807+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Entering state NESMVPNSessionStatePreparingNetwork
default 01:34:35.534507+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Leaving state NESMVPNSessionStatePreparingNetwork
default 01:34:35.534537+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Entering state NESMVPNSessionStateStarting
default 01:34:35.592272+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Plugin NEVPNTunnelPlugin(com.VPN.osx.VPNBackend[inactive]) initialized with Mach-O UUIDs (
"ECA8D451-66ED-3748-A76D-0C6FA6ACC5E5"
)
default 01:34:35.595024+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)] in state NESMVPNSessionStateStarting: plugin NEVPNTunnelPlugin(com.VPN.osx.VPNBackend[inactive]) started with PID 2013 error (null)
default 01:34:35.702611+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)] in state NESMVPNSessionStateStarting: set configuration started
default 01:34:35.702672+0100 nesessionmanager <NESMServer: 0x7fb9a35040a0>: Request to install session: NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)] (exclusive)
default 01:34:35.702697+0100 nesessionmanager <NESMServer: 0x7fb9a35040a0>: Request to install Session NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)] is Enterprise - Exclusive
default 01:34:35.793277+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)] in state NESMVPNSessionStateStarting: set configuration completed with result 1
default 01:34:35.794877+0100 configd nw_path_evaluator_start [3BD8B408-C2CB-4EB7-8C1C-8B931B2B61B5 IPv4#17f94fd3:0 generic, indefinite]
path: unsatisfied (Network Agent [domain: NetworkExtension, type: VPN, description: VPN: VPN WireGuard, uuid: D52281C5-4B04-4E55-A906-A0825158EE45, flags: 1] is unsatisfied), interface: utun2, ipv4, dns
default 01:34:35.818440+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)] in state NESMVPNSessionStateStarting: plugin NEVPNTunnelPlugin(com.VPN.osx.VPNBackend[inactive]) status changed to connected
default 01:34:35.818486+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Leaving state NESMVPNSessionStateStarting
default 01:34:35.818514+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Entering state NESMVPNSessionStateRunning
default 01:34:35.818561+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: status changed to connected
default 01:34:35.818624+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:40F11705-1D5E-460C-AB50-E16CD86E289F:(null)]: Updated network agent (active, compulsory, not-user-activiated, not-kernel-activated)
For the version that does not work, the log was:
default 01:40:42.706804+0100 VPN Service Saving configuration VPN WireGuard with existing signature (null)
default 01:40:42.749663+0100 WireGuard Received a com.apple.neconfigurationchanged notification with token 42
default 01:40:42.750127+0100 VPN Service Successfully saved configuration VPN WireGuard
default 01:40:42.752069+0100 nesessionmanager Creating session with type 1, id D7354992-B57D-40FE-A881-0085FA025B7E (VPN WireGuard)
default 01:40:42.752249+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Registered network agent (inactive)
default 01:40:42.752693+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Resetting VPN On Demand
default 01:40:42.752710+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Entering state NESMVPNSessionStateIdle
default 01:40:42.753165+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Plugin is registered with provider manager
default 01:40:42.753360+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Plugin is installed
default 01:40:42.753679+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Adding a connection for client com.apple.preference.network.re[2011]
default 01:40:42.754223+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Adding a connection for client SystemUIServer[452]
default 01:40:42.769361+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Adding a connection for client VPN Service[3072]
default 01:40:42.770910+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Received a start command from VPN Service[3072]
default 01:40:42.770946+0100 nesessionmanager Registering session NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]
default 01:40:42.771264+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Resetting VPN On Demand
default 01:40:42.771323+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Plugin is registered with provider manager
default 01:40:42.771342+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Plugin is installed
default 01:40:42.771368+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)] in state NESMVPNSessionStateIdle: update configuration
default 01:40:42.771842+0100 nesessionmanager <NESMServer: 0x7fb9a35040a0>: Register Enterprise VPN Session: NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]
default 01:40:42.771965+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Successfully registered
default 01:40:42.773427+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: status changed to connecting
default 01:40:42.773664+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)] in state NESMVPNSessionStateIdle: received start message
default 01:40:42.773716+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Leaving state NESMVPNSessionStateIdle
default 01:40:42.773741+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Entering state NESMVPNSessionStatePreparingNetwork
default 01:40:42.774647+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Leaving state NESMVPNSessionStatePreparingNetwork
default 01:40:42.774732+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Entering state NESMVPNSessionStateStarting
default 01:40:42.859883+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)] in state NESMVPNSessionStateStarting: plugin NEVPNTunnelPlugin(com.VPN.osx.VPNBackend[inactive]) started with PID 0 error (null)
default 01:40:42.860681+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Leaving state NESMVPNSessionStateStarting
default 01:40:42.860713+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Entering state NESMVPNSessionStateStopping, timeout 20 seconds
default 01:40:42.860769+0100 nesessionmanager <NESMServer: 0x7fb9a35040a0>: Request to uninstall session: NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]
default 01:40:42.860791+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: status changed to disconnecting
default 01:40:42.860851+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Updated network agent (inactive, compulsory, not-user-activiated, not-kernel-activated)
default 01:40:42.861054+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Leaving state NESMVPNSessionStateStopping
default 01:40:42.861095+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Entering state NESMVPNSessionStateDisposing, timeout 5 seconds
default 01:40:42.861510+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)] in state NESMVPNSessionStateDisposing: plugin NEVPNTunnelPlugin(com.VPN.osx.VPNBackend[inactive]) dispose complete
default 01:40:42.861536+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)] in state NESMVPNSessionStateDisposing: all plugins have disposed
default 01:40:42.861685+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Leaving state NESMVPNSessionStateDisposing
default 01:40:42.861793+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: Entering state NESMVPNSessionStateIdle
default 01:40:42.862178+0100 nesessionmanager NESMVPNSession[Primary Tunnel:VPN WireGuard:D7354992-B57D-40FE-A881-0085FA025B7E:(null)]: status changed to disconnected, last stop reason Plugin failed
default 01:40:43.055916+0100 VPN Service Last disconnect error for VPN WireGuard changed from "none" to "The VPN session failed because an internal error occurred."
The thing that brings my attention is that the plugin has its pid = 0 in the second log, and that could be the reason why the plugin is not loaded according to the logs, but I would like to know if there is something smarter to do to debug the issue than reading this log that is not very detailed. Is there something like a verbose option ? Many thanks for your help.
