Tips on debugging a non-functional NEFilterPacketProvider?

My question is this: what are some tips to systematically debug this issue? If you were me, where would you start looking at this?

I would use the os_log API as much as possible here to try and identify where the breakdown was. I would also try and install the (VPN (Network Extension) for macOS) debug profile and capture the system logs of your device by trying to start the provider to see what is emitted here. This may give you some more detail than what you are seeing currently.

Also, make sure that you are adding overrides for init and stopFiler:

class FilterPacketProvider: NEFilterPacketProvider {
    
    static let log = OSLog(subsystem: "com.apple.test.simplefirewall.extension", category: "packet_provider")
    private let log: OSLog
    
    override init() {
        self.log = Self.log
        os_log(.debug, log: self.log, "init")
        super.init()
    }

    override func startFilter(completionHandler: @escaping (Error?) -> Void) {

    	// ...
    	let errDescription = error.localizedDescription ?? "No Error"
        os_log(.debug, log: self.log, "startFilter %{public}@", errDescription)
        
        completionHandler(nil)
    }
    
    override func stopFilter(with reason: NEProviderStopReason, completionHandler: @escaping () -> Void) {
        os_log(.debug, log: self.log, "stopFilter with reason: %d", reason)
        
        completionHandler()
    }
}

Because if your provider is crashing then init, stopFilter, and startFilter will get hit over and over as the system restarts it.

Regarding:

Are there some command line tools that I can use to inspect the state of the network extension or macOS's state regarding them?

scutil --nc is my go to Terminal utility here

Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com

Thank you!

I have enabled greater logging and still don't see what could be causing this. I am seeing the init and startFilter happening only once and there are no crash logs generated.

scutil --nc list is not showing anything.

I see logs like:

nesessionmanager	Found 1 (1 active) registrations for com.company.name.Agent (com.apple.networkextension.filter-packet)
nesessionmanager	NESMFilterSession[AppName:172E3B4C-7A2C-4371-8355-97B653A32390]: Plugin NEFilterPlugin(com.company.appname.App[inactive]) requested a packet filter channel
nesessionmanager	NESMFilterSession[AppName:172E3B4C-7A2C-4371-8355-97B653A32390] in state NESMFilterSessionStateStarting: plugin NEFilterPlugin(com.company.appname.App[inactive]) status changed to running
nesessionmanager	<NESMServer: 0x7fcd2850a0f0>: Request to install session: NESMFilterSession[AppName:172E3B4C-7A2C-4371-8355-97B653A32390] (exclusive)
nesessionmanager	NESMFilterSession[AppName:172E3B4C-7A2C-4371-8355-97B653A32390]: status changed to connected
nesessionmanager	NESMFilterSession[AppName:172E3B4C-7A2C-4371-8355-97B653A32390]: Updated network agent (active, compulsory, not-user-activiated, not-kernel-activated)

Any other log lines I should look for to identify the cause of this problem? By the way, the VM has macOS 11.5 (20G71) on it.

Any other log lines I should look for to identify the cause of this problem? I am seeing the init and startFilter happening only once and there are no crash logs generated. I am seeing the init and startFilter happening only once and there are no crash logs generated.

Okay, if you see your init and startFilter calls being hit then that is good. What do you get from your packetHandler if you add them in like so:

packetHandler = { (context, interface, direction, packetBytes, packetLength) in
    // Analyze packet
    return .allow
}

Or Objective-C:

self.packetHandler= ^NEFilterPacketProviderVerdict(NEFilterPacketContext * context,
                                                   _Nonnull nw_interface_t interface,
                                                   NETrafficDirection direction,
                                                   const void * packetBytes,
                                                   const size_t packetLength) {
    
    // Analyze packet
    
    return NEFilterPacketProviderVerdictAllow;
};

Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com

So when I use a packetHandler as one you gave, it still doesn't get called. I added a logging statement within it and it never fires.

Is there a known issue with NEFilterPacketProvider and Parallels VMs? Our packet handlers are getting called within VMWare Fusion VMs. It's the only difference I can think of. Same MDM profiles, same build of my app/binaries, and same macOS installations from scratch.

Is there a known issue with NEFilterPacketProvider and Parallels VMs?

Not that I am aware of, but if this is the only environment where this code path does not work then it would be good to get a bug report down for this. Can you open a bug report with a sysdiagnose. Please respond with the Feedback ID.

Matt Eaton
DTS Engineering, CoreOS
meaton3@apple.com

Thanks! Here's the bug report: FB9648977.

I've spent hours on this bug and can't understand what's happening.

Given that, I recommend that you open a DTS tech support incident so that someone (well, that’d be me :-) can help you with this one-on-one.

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