OSSystemExtensionRequestDelegate doesn't get a callback; XPC connection cancelled

I'm attempting to install a NetworkExtension as a system extension, using the OSSystemExtensionManager.shared.submitRequest(request) API call. I can see from console logs and systemextensionsctl that my system extension is getting installed, but the OSSystemExtensionRequestDelegate I attach to the request never gets a callback.

In the console logs I see:

com.apple.sx	default	14:13:25.811827+0400	sysextd	activateDecision found entry to replace: com.coder.Coder-Desktop.VPN, BundleVersion(CFBundleShortVersionString: "1.0", CFBundleVersion: "1")
	default	14:13:25.811888+0400	sysextd	initial activation decision: requestAppReplaceAction(<sysextd.Extension: 0xa94030100>)
com.apple.sx	default	14:13:25.811928+0400	sysextd	notifying client of activation conflict
com.apple.xpc	default	14:13:25.812156+0400	Coder Desktop	[0x154f2d5b0] invalidated because the current process cancelled the connection by calling xpc_connection_cancel()
com.apple.xpc	default	14:13:25.813924+0400	sysextd	[0xa941d4280] invalidated because the client process (pid 2599) either cancelled the connection or exited
com.apple.sx	default	14:13:25.814027+0400	sysextd	client connection (pid 2599) invalidated

It appears that something within my app process is cancelling the XPC connection to sysextd, but I'm certainly not calling it from within my code. Presumably something within the OSSystemExtension* APIs are cancelling the connection but I don't know why. It seems to be happening very quickly (within a few hundred ms) after sending the request, and before sysextd can reply.

What could cause this connection to be canceled?

Answered by DTS Engineer in 821856022

I see you create a new instance of the SystemExtensionDelegate type for each request. Are you sure that’s not being deallocated?

If you add a deinitialiser to it and then add a log point to that deinitialiser, when do you see that log entry emitted?

Share and Enjoy

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

Let’s start with something basic: Are you doing this from a GUI app as launched by the Finder [1]?

Share and Enjoy

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

[1] Or from Xcode, with the caveat that it still has to be a GUI that that could be launched by the user from the Finder.

Yes, this is a standard GUI app, the @main is a SwiftUI App struct. I've been launching it from XCode, though.

Written by spikecurtis in 821250022
this is a standard GUI app

Cool.

Written by spikecurtis in 821250022
I've been launching it from [Xcode]

That’s not a problem.

With respect to the log snippet you posted, is Coder Desktop your app?

At this point I think it’d be useful to separate potential problems with your code from potential problems with your system. If you build the Filtering Network Traffic sample and install its sysex, does it have the same problem?

Share and Enjoy

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

The SimpleFirewall application in the Filtering Network Traffic example works fine: I built and ran it on the same system, and I can see the request delegate getting callbacks in the example application.

With respect to the log snippet you posted, is Coder Desktop your app?

Yes, that's correct.

import Foundation
import os
import SystemExtensions

enum SystemExtensionState: Equatable, Sendable {
    case uninstalled
    case needsUserApproval
    case installed
    case failed(String)

    var description: String {
        switch self {
        case .uninstalled:
            return "VPN SystemExtension is waiting to be activated"
        case .needsUserApproval:
            return "VPN SystemExtension needs user approval to activate"
        case .installed:
            return "VPN SystemExtension is installed"
        case let .failed(error):
            return "VPN SystemExtension failed with error: \(error)"
        }
    }
}

protocol SystemExtensionAsyncRecorder: Sendable {
    func recordSystemExtensionState(_ state: SystemExtensionState) async
}

extension CoderVPNService: SystemExtensionAsyncRecorder {
    func recordSystemExtensionState(_ state: SystemExtensionState) async {
        sysExtnState = state
    }

    var extensionBundle: Bundle {
        let extensionsDirectoryURL = URL(
            fileURLWithPath: "Contents/Library/SystemExtensions",
            relativeTo: Bundle.main.bundleURL
        )
        let extensionURLs: [URL]
        do {
            extensionURLs = try FileManager.default.contentsOfDirectory(at: extensionsDirectoryURL,
                                                                        includingPropertiesForKeys: nil,
                                                                        options: .skipsHiddenFiles)
        } catch {
            fatalError("Failed to get the contents of " +
                "\(extensionsDirectoryURL.absoluteString): \(error.localizedDescription)")
        }

        // here we're just going to assume that there is only ever going to be one SystemExtension
        // packaged up in the application bundle. If we ever need to ship multiple versions or have
        // multiple extensions, we'll need to revisit this assumption.
        guard let extensionURL = extensionURLs.first else {
            fatalError("Failed to find any system extensions")
        }

        guard let extensionBundle = Bundle(url: extensionURL) else {
            fatalError("Failed to create a bundle with URL \(extensionURL.absoluteString)")
        }

        return extensionBundle
    }

    func installSystemExtension() {
        logger.info("activating SystemExtension")
        guard let bundleID = extensionBundle.bundleIdentifier else {
            logger.error("Bundle has no identifier")
            return
        }
        let request = OSSystemExtensionRequest.activationRequest(
            forExtensionWithIdentifier: bundleID,
            queue: .main
        )
        let delegate = SystemExtensionDelegate(asyncDelegate: self)
        request.delegate = delegate
        OSSystemExtensionManager.shared.submitRequest(request)
        logger.info("submitted SystemExtension request with bundleID: \(bundleID)")
    }
}

/// A delegate for the OSSystemExtensionRequest that maps the callbacks to async calls on the
/// AsyncDelegate (CoderVPNService in production).
class SystemExtensionDelegate<AsyncDelegate: SystemExtensionAsyncRecorder>:
    NSObject, OSSystemExtensionRequestDelegate
{
    private var logger = Logger(subsystem: "com.coder.Coder-Desktop", category: "vpn-installer")
    private var asyncDelegate: AsyncDelegate

    init(asyncDelegate: AsyncDelegate) {
        self.asyncDelegate = asyncDelegate
        super.init()
        logger.info("SystemExtensionDelegate initialized")
    }

    func request(
        _: OSSystemExtensionRequest,
        didFinishWithResult result: OSSystemExtensionRequest.Result
    ) {
        guard result == .completed else {
            logger.error("Unexpected result \(result.rawValue) for system extension request")
            let state = SystemExtensionState.failed("system extension not installed: \(result.rawValue)")
            Task { [asyncDelegate] in
                await asyncDelegate.recordSystemExtensionState(state)
            }
            return
        }
        logger.info("SystemExtension activated")
        Task { [asyncDelegate] in
            await asyncDelegate.recordSystemExtensionState(SystemExtensionState.installed)
        }
    }

    func request(_: OSSystemExtensionRequest, didFailWithError error: Error) {
        logger.error("System extension request failed: \(error.localizedDescription)")
        Task { [asyncDelegate] in
            await asyncDelegate.recordSystemExtensionState(
                SystemExtensionState.failed(error.localizedDescription))
        }
    }

    func requestNeedsUserApproval(_ request: OSSystemExtensionRequest) {
        logger.error("Extension \(request.identifier) requires user approval")
        Task { [asyncDelegate] in
            await asyncDelegate.recordSystemExtensionState(SystemExtensionState.needsUserApproval)
        }
    }

    func request(
        _ request: OSSystemExtensionRequest,
        actionForReplacingExtension existing: OSSystemExtensionProperties,
        withExtension extension: OSSystemExtensionProperties
    ) -> OSSystemExtensionRequest.ReplacementAction {
        // swiftlint: disable line_length
        logger.info("Replacing \(request.identifier) v\(existing.bundleShortVersion) with v\(`extension`.bundleShortVersion)")
        // swiftlint: enable line_length
        return .replace
    }
}

My CoderVPNService is an @MainActor class, if it matters, and this extension to it and the accompanying delegate handle the system extension request and reporting back status asynchronously.

Accepted Answer

I see you create a new instance of the SystemExtensionDelegate type for each request. Are you sure that’s not being deallocated?

If you add a deinitialiser to it and then add a log point to that deinitialiser, when do you see that log entry emitted?

Share and Enjoy

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

Thank you very much! The delegate was indeed getting deallocated early. I didn't realize the request only makes a weak reference to the delegate.

I wonder if you could pass a bit of feedback to the docs team: from this class-level view, the delegate property contains no hints that the reference is weak. It's only when you drill down to the property that you can see it's a weak ref.

Yay!

Written by spikecurtis in 821971022
I wonder if you could pass a bit of feedback to the docs team

You can do that yourself by filing a bug against the docs.

Please post your bug number, just for the record.

Share and Enjoy

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

Bug report, for posterity: FB16390870

OSSystemExtensionRequestDelegate doesn't get a callback; XPC connection cancelled
 
 
Q