I'm attempting to implement a PacketTunnelProvider into a macOS application, however when I start it it just simply doesn't work.
I'm using code from an iOS application I wrote, so that may be a part of the problem. I'm unsure.
I have the proper entitlements, everything is configured properly, and I'm not getting any direct errors within my application.
Some of the weird stuff I'm experiencing:
- Even though in my provider I have it print a message in the beginning of `startTunnel` and the sleep for 15 seconds, the interface in System Preferences seems to only come alive for a split second and then go back to "Not Connected". I also cannot find that log message anywhere in Console.
- If I change the provider bundle identifier in the NETunnelProviderProtocol I still experience the same thing. No errors are output. I would think an error would be output telling me that the bundle identifier is incorrect?
This is what I'm seeing in Console (which is incredibly difficult to use when debugging this)
13:31:27.602507 -0600 nesessionmanager <NESMServer: 0x7fb864200000>: Register Enterprise VPN Session: NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]
13:31:27.602602 -0600 MyVPN MyVPN-Logi : allowConnection StoredPreferences.swift:60 :: [[[[ func allowConnection (Optional(true)) ]]]]
13:31:27.602541 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a start command from MyVPN[76415]
13:31:27.602698 -0600 MyVPN CFPrefsPlistSource<0x6000014d8150> (Domain: group.com.MyVPN.vpn.osx, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) skipping setting already-present value for key MyVPN_allow_connection
13:31:27.604297 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505] starting with configuration: {
name = MyVPN VPN
identifier = CB946E5C-EDE5-41E9-B582-9C9E33BF8505
applicationName = MyVPN VPN
application = com.MyVPN.vpn.osx
grade = 1
VPN = {
enabled = YES
onDemandEnabled = NO
disconnectOnDemandEnabled = NO
protocol = {
type = plugin
identifier = 6AD41CF5-FB38-4FD6-9217-27E29CE585F1
serverAddress = 0.0.0.0
username = MyVPNVPN
password = {
identifier = CB946E5C-EDE5-41E9-B582-9C9E33BF8505
domain = user
}
identityDataImported = NO
disconnectOnSleep = NO
disconnectOnIdle = NO
disconnectOnIdleTimeout = 0
disconnectOnWake = NO
disconnectOnWakeTimeout = 0
disconnectOnUserSwitch = NO
disconnectOnLogout = NO
pluginType = com.MyVPN.vpn.osx
authenticationMethod = 0
reassertTimeout = 0
providerConfiguration = {
}
providerBundleIdentifier = com.MyVPN.vpn.osx.provider
}
}
}
13:31:27.604350 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505] is no longer idle, beginning transaction
13:31:27.604451 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: status changed to connecting
13:31:27.604740 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505] in state NESMVPNSessionStateIdle: received start message
13:31:27.604809 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Leaving state NESMVPNSessionStateIdle
13:31:27.604855 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Entering state NESMVPNSessionStatePreparingNetwork
13:31:27.605109 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Network available via interface en0
13:31:27.605190 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a info fetch request with type "extended status" from MyVPN[76415]
13:31:27.605357 -0600 MyVPN Last disconnect error for MyVPN VPN changed from "The VPN session failed because an internal error occurred." to "none"
13:31:27.605376 -0600 nesessionmanager Found plugins: (
{
"DRIVER_CLASS_NAME" = NEAgentPacketTunnelExtension;
"PLUGIN_PRIMARY_PLUGIN_TYPE" = "com.MyVPN.vpn.osx.provider";
"PLUGIN_TYPE" = "com.MyVPN.vpn.osx.provider";
"PLUGIN_VERSION" = 1;
}
)
13:31:27.605443 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505] in state NESMVPNSessionStatePreparingNetwork: plugin initialization succeeded
13:31:27.605476 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Leaving state NESMVPNSessionStatePreparingNetwork
13:31:27.605510 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Entering state NESMVPNSessionStateStarting
13:31:27.605540 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Default prepareConfigurationForStart
13:31:27.605985 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a status query from SystemUIServer[1000]
13:31:27.606061 -0600 nesessionmanager Using UUIDs for com.MyVPN.vpn.osx.provider - (null)
13:31:27.606151 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a status query from MyVPN[76415]
13:31:27.606221 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a status query from com.apple.preference.network.re[74291]
13:31:27.606286 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a info fetch request with type "extended status" from SystemUIServer[1000]
13:31:27.611651 -0600 pkd vNode for /Applications/MyVPN.app/Contents/PlugIns/VPN Provider.appex is 8612824454
13:31:27.613477 -0600 pkd vNode for /Users/nathanf/Library/Developer/Xcode/DerivedData/MyVPN-dzzccnlkrymeqjegdlgrizpwgcad/Build/Products/Debug/MyVPN.app/Contents/PlugIns/VPN Provider.appex is 8612822167
13:31:27.614580 -0600 neagent Failed to create an NSExtension with type com.MyVPN.vpn.osx.provider: (null)
13:31:27.614970 -0600 nesessionmanager com.MyVPN.vpn.osx.provider[53373]: XPC connection went away: Connection invalid
13:31:27.615215 -0600 nesessionmanager com.MyVPN.vpn.osx.provider[53373]: dropping a message because the current state is not "started" (0)
13:31:27.616644 -0600 nesessionmanager com.MyVPN.vpn.osx.provider[53373]: dropping a message because the current state is not "started" (0)
13:31:27.616825 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505] in state NESMVPNSessionStateStarting: plugin NEVPNTunnelPlugin(com.MyVPN.vpn.osx.provider[53373]) started with PID 0
13:31:27.617519 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Leaving state NESMVPNSessionStateStarting
13:31:27.617571 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Entering state NESMVPNSessionStateStopping, timeout 20 seconds
13:31:27.617629 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: config request: pushing handler [(null)] (null)
13:31:27.617692 -0600 nesessionmanager <NESMServer: 0x7fb864200000>: Request to uninstall session: NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]
13:31:27.617858 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: status changed to disconnecting
13:31:27.618046 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Updated network agent (inactive)
13:31:27.618433 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Leaving state NESMVPNSessionStateStopping
13:31:27.618709 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Entering state NESMVPNSessionStateDisposing, timeout 5 seconds
13:31:27.618892 -0600 nesessionmanager com.MyVPN.vpn.osx.provider[53373]: disposing while in the idle state
13:31:27.619217 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Request to clear network agent from all interfaces
13:31:27.619544 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: config request: popping handler [(null)] (null)
13:31:27.619737 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a status query from com.apple.preference.network.re[74291]
13:31:27.619882 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505] in state NESMVPNSessionStateDisposing: plugin NEVPNTunnelPlugin(com.MyVPN.vpn.osx.provider[53373]) dispose complete
13:31:27.619974 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505] in state NESMVPNSessionStateDisposing: all plugins have disposed
13:31:27.620251 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Leaving state NESMVPNSessionStateDisposing
13:31:27.620320 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Entering state NESMVPNSessionStateIdle
13:31:27.620380 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505] is now idle, ending transaction
13:31:27.620676 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: status changed to disconnected, last stop reason Plugin failed
13:31:27.621069 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a status query from SystemUIServer[1000]
13:31:27.621321 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a status query from MyVPN[76415]
13:31:27.621550 -0600 nesessionmanager NESMVPNSession[MyVPN VPN:CB946E5C-EDE5-41E9-B582-9C9E33BF8505]: Received a status query from SystemUIServer[1000]
13:31:27.623337 -0600 MyVPN Last disconnect error for MyVPN VPN changed from "none" to "The VPN session failed because an internal error occurred."Code
My "Connect" button calls this code:
VPNInitializer.initializeTunnel(force: force, withConfig: config as [String : NSObject]) { (stop: Bool, error: NSError?) in
if (stop) {
info(message: "Stop set to true")
if (error != nil) {
info(message: (error?.localizedDescription)!);
//self.showAccessAlert()
info(message: "No access permission")
}
} else {
if (error != nil) {
erro(message: String.localizedStringWithFormat("Error on init tun: %@", (error?.localizedDescription)!))
} else {
// THIS MEANS WE ARE CONNECTED, START THE STATUS WATCHER HERE
_ = StoredPreferences.Global.vpnAccessGranted(true)
_ = StoredPreferences.Global.allowConnection(true)
//self.startWatchingStatus();
}
}
}Which is using this class:
//
// VPNInitializer.swift
// MyVPN
import Foundation
import NetworkExtension
import Cocoa
class VPNInitializer {
public static let Global:VPNInitializer = VPNInitializer();
var proto : NETunnelProviderProtocol?
var manager : NETunnelProviderManager?
private func initializeProvider(withConfig ptp_config: [String : NSObject]?) -> NSError? {
var err : NSError? = nil
if (manager?.connection.status == .disconnected) {
info(message: "Manager is disconnected, attempting a connection.")
_ = StoredPreferences.Global.vpnStatus(VPN_STATUS_CONNECTING);
_ = StoredPreferences.Global.sessionTime(transitional: true, 0);
_ = StoredPreferences.Global.sessionTime(transitional: false, 0);
do { try manager!.connection.startVPNTunnel(options: ptp_config) } catch let nserror {
erro(message: "Error while running startVPNTunnel")
err = errorWithMessage(message: String(format: "Error while running startVpnTunnel: %@", nserror.localizedDescription))
}
}
return err
}
public func isConnected() -> Bool {
return self.manager != nil && self.manager?.connection.status != .disconnected && self.manager?.connection.status != .disconnecting;
}
public func sendAppMessage(message: String) -> String? {
logi(message: "sendAppMessage")
var result : String? = nil;
let started : time_t = time(nil);
self.sendAppMessage(message: message) { (response: String) in
result = response;
}
while (result == nil && (time(nil) - started) < 1) {
usleep(100_000);
}
return result;
}
public func sendAppMessage(message: String, _ responseHandler: @escaping (String) -> Void) {
do {
try (
VPNInitializer.Global.manager?.connection as! NETunnelProviderSession
).sendProviderMessage(
message.data(using: .utf8)!
) { (response: Data?) in
if let response = response {
if let responseStr = String(data: response, encoding: .utf8) {
info(message: "Message from Provider: \(responseStr)");
responseHandler(responseStr);
return;
}
}
warn(message: "AppMessage empty response for message: \(message)")
responseHandler("");
return;
}
} catch {
warn(message: "An error occured while sending a message to the provider. Error: \(error)")
responseHandler("");
}
}
public func disconnect(vc: NSViewController!, completion: @escaping (Bool) -> Void) {
// TODO: Implement Disconnect
}
static func getManager(create: Bool?, completed: @escaping (NETunnelProviderManager?, NSError?) -> Void) {
info(message: "getManager: Searching for configured managers.")
NETunnelProviderManager.loadAllFromPreferences { (managers: [NETunnelProviderManager]?, error: Error?) in
if let managers = managers {
if (managers.count > 0) {
for manager in managers {
if (
(manager.protocolConfiguration as! NETunnelProviderProtocol).providerBundleIdentifier == "com.MyVPN.vpn.osx.provider"
) {
info(message: "getManager: Found existing manager already configured.")
VPNInitializer.Global.manager = manager
VPNInitializer.Global.manager?.isEnabled = true
completed(manager, nil)
return
}
}
}
}
if (create!) {
info(message: "getManager: No configured managers found, creating new.")
VPNInitializer.Global.proto = NETunnelProviderProtocol()
VPNInitializer.Global.proto?.providerBundleIdentifier = "com.MyVPN.vpn.osx.provider"
VPNInitializer.Global.proto?.providerConfiguration = [String : Any]()
VPNInitializer.Global.proto?.serverAddress = "0.0.0.0"
VPNInitializer.Global.proto?.username = "MyVPNVPN"
VPNInitializer.Global.proto?.identityDataPassword = "MyVPNVPN"
VPNInitializer.Global.manager = NETunnelProviderManager()
VPNInitializer.Global.manager?.protocolConfiguration = VPNInitializer.Global.proto
VPNInitializer.Global.manager?.isEnabled = true
VPNInitializer.Global.manager!.saveToPreferences(completionHandler: { (error: Error?) in
if (error != nil) {
erro(message: String.localizedStringWithFormat("Error while saving VPN to preferences: %@", (error?.localizedDescription)!))
_ = StoredPreferences.Global.vpnAccessGranted(false)
completed(nil, error as NSError?)
} else {
VPNInitializer.Global.manager!.loadFromPreferences(completionHandler: { (error: Error?) in
if (error != nil) {
erro(message: String.localizedStringWithFormat("Error while reading VPN from preferences: %@", (error?.localizedDescription)!))
_ = StoredPreferences.Global.vpnAccessGranted(false)
completed(nil, error as NSError?)
} else {
completed(VPNInitializer.Global.manager!, nil)
}
})
}
})
} else {
completed(nil, nil)
}
}
}
static func initializeTunnel(force: Bool, withConfig ptp_config: [String : NSObject]?, completed: @escaping (_ stop: Bool, _ error: NSError?) -> Void) {
if (!force) {
if (!StoredPreferences.Global.allowConnection()) {
completed(true, nil)
return
}
}
getManager (create: true) { (manager: NETunnelProviderManager?, error: NSError?) in
if (manager != nil) {
completed(false, VPNInitializer.Global.initializeProvider(withConfig: ptp_config))
} else {
completed(true, error)
}
}
}
}