I have a typical content filter implemented using NEFilterDataProvider and I'm observing that sometimes handleNewFlow will not obey the returned verdict. More specifically, drop verdict is sometimes ignored and an error message is logged. The impact on my app is that my content filter may not drop flows when it was supposed to.
I narrowed the issue down to being triggered by using my content filter alongside a VPN (Tailscale VPN, haven't tested others).
To reproduce the issue:
Open reddit.com on Google Chrome
Activate the content filter set to drop traffic (in my case configured for reddit)
Run a VPN
Refresh the reddit browser tab
Observe reddit being loaded just fine, despite traffic being dropped
Below you may find a sample log that may be related to when the issue is triggered.
Near the end of the log below, I found this particular line interesting: "No current verdict available, cannot report flow closed". I wonder if it means that something else raced in front of my extension and gave an allow verdict. My extension only takes 621us to make a decision.
com.apple.networkextension debug 17:19:41.714581-0300 Handling new flow:
identifier = D89B5B5D-793C-4940-777A-6BB703E80900
sourceAppIdentifier = EQHXZ8M8AV.com.google.Chrome.helper
sourceAppVersion = 138.0.7204.50
sourceAppUniqueIdentifier = {length = 20, bytes = 0x57df24110a3dd3fbd954082915f8f19f6d365053}
procPID = 15492
eprocPID = 15492
rprocPID = 15481
direction = outbound
inBytes = 0
outBytes = 0
signature = {length = 32, bytes = 0x2e387b1f a214703d 62f17624 4aec86f4 ... 91d91bbd d97b6c90 }
socketID = 9e803b76b7a77
localEndpoint = 0.0.0.0:0
remoteEndpoint = 52.6.64.124:443
remoteHostname = gql-realtime.reddit.com
protocol = 6
family = 2
type = 1
procUUID = 4C4C44ED-5555-3144-A13B-2281E1056F00
eprocUUID = 4C4C44ED-5555-3144-A13B-2281E1056F00
rprocUUID = 4C4C4485-5555-3144-A122-165F9195A675
myContentFilter.ContentFilterNetworkExtension debug 17:19:41.714638-0300 Flow D89B5B5D-793C-4940-777A-6BB703E80900: handling new flow
myContentFilter.ContentFilterNetworkExtension debug 17:19:41.715446-0300 Flow D89B5B5D-793C-4940-777A-6BB703E80900: drop (1 gql-realtime.reddit.com) ( 621.0803985595703 µs)
com.apple.networkextension debug 17:19:41.715606-0300 New flow verdict for D89B5B5D-793C-4940-777A-6BB703E80900:
drop = YES
remediate = NO
needRules = NO
shouldReport = NO
pause = NO
urlAppendString = NO
filterInbound = NO
peekInboundBytes = 0
filterOutbound = NO
peekOutboundBytes = 0
statisticsReportFrequency = none
com.apple.networkextension debug 17:19:41.715775-0300 Dropping new flow 9e803b76b7a77
com.apple.networkextension error 17:19:41.715883-0300 No current verdict available, cannot report flow closed
com.apple.networkextension debug 17:19:41.715976-0300 Outbound disconnect message rejected, no flow found for sockid 2788377450216055
com.apple.networkextension debug 17:19:41.716727-0300 Inbound disconnect message rejected, no flow found for sockid 2788377450216055
Also good to note that this can only be reliably reproduced if there was a browser tab recently opened and kept open in that website. Here I'm also guessing that the browser is caching connections.
I was able to reproduce on macOS 15.6 Beta (24G5065c), Google Chrome 138 (apparently doesn't happen on Firefox), and the user has seen the issue on macOS 15.5.
My alternative theory is that this log doesn't have anything to do with the behavior and instead it's just Chrome caching the connection, and further traffic in that connection simply flows through because it was previously allowed. Could that be the case?
Thanks!
Selecting any option will automatically load the page
Post
Replies
Boosts
Views
Activity
Whenever I'm working on my content filter for macOS, I usually keep SIP disabled and with developer mode on (systemextensionsctl) as a convenience.
The issue: content filter stopped receiving any kind of traffic when SIP is disabled. I don't see any log lines in Console for new flows, and the filter can't block anything, since it doesn't get any flows. Issue started yesterday.
I tried several things and did some investigation, here are some findings:
Reboot: rebooting did not fix the issue (while keeping SIP disabled).
Reenabling SIP fixes the issue for both App Store and Xcode builds.
Code: latest published version also stopped working with SIP disabled. This version is stable and confirmed to work as reported by users.
Clean Xcode + rebuild did not fix the issue.
Lastly, I inspected the logs and did not see any errors standing out. I noticed the filter does get started (startFilter is called) and registered, but after that there are no errors/new flows or anything, just silence (logs below).
com.apple.networkextension default 15:22:22.270746-0300 : Calling startFilterWithCompletionHandler
com.extension.MyExtension info 15:22:22.270998-0300 Success applying filter settings
com.apple.networkextension debug 15:22:22.272705-0300 NESMFilterSession[My Extension:B9F3F30E-E0E0-4E53-8B32-EFC285E3CF6A]: Checking providerBundleIdentifier com.extension.MyExtension for pluginClass 4
com.apple.networkextension debug 15:22:22.272717-0300 Checking for com.extension.MyExtension - com.apple.networkextension.filter-data
com.apple.networkextension default 15:22:22.272728-0300 Found 1 registrations for com.extension.MyExtension (com.apple.networkextension.filter-data)
com.apple.networkextension debug 15:22:22.272778-0300 NESMFilterSession[My Extension:B9F3F30E-E0E0-4E53-8B32-EFC285E3CF6A]: com.extension.MyExtension is registered for pluginClass 4
Here are some additional info about my system:
macOS 15.1
Between yesterday and today, the only new Installation is XProtectPlistConfigData at 12:10AM
Thanks!
Starting on macOS Sequoia, flows originated in Firefox have an empty sourceAppAuditToken. Other apps contain a valid token.
Background: in order to fetch process info for a certain NEFilterFlow, my content filter extension uses sourceAppAuditToken, audit_token_to_pid() and proc_* (as recommended in #126820). When that fails, we use SecCodeCopyGuestWithAttributes, recommended in some other thread as a better alternative. Both approaches break when the sourceAppAuditToken is empty since they need the pid.
Debugging:
My logging shows audit token is empty for Firefox
Typical logs from com.apple.networkextension also indicate it fails to fetch the same info I'm looking for:
com.apple.networkextension debug 11:22:07.024588-0300 Fetching appInfo from cache for pid: 948 uuid: 5C40B765-C6C9-3641-A822-2BC44D264361 bundle id: (null)
com.apple.networkextension debug 11:22:07.024657-0300 Calling delegate lookup handler with pid: 948, uuid: 5C40B765-C6C9-3641-A822-2BC44D264361, bundleID: (null)
com.apple.networkextension debug 11:22:07.025856-0300 Could not look up appInfo for pid: 948 bundle id: (null) uuid: 5C40B765-C6C9-3641-A822-2BC44D264361
com.apple.networkextension error 11:22:07.025897-0300 Could not find app info, return the original flow without filling in app info
Handling new flow:
identifier = D89B5B5D-793C-4940-D992-4E90F2AD1900
procPID = 953
eprocPID = 948
direction = outbound
inBytes = 0
outBytes = 0
signature = {length = 32, bytes = 0x4afeafde b484aa0c c5cb8698 0567343d ... 7cdee33e 135666dd }
socketID = 19adf2904e92d9
localEndpoint = 0.0.0.0:0
remoteEndpoint = 17.33.202.170:443
protocol = 6
family = 2
type = 1
procUUID = 0C68E603-967E-3643-B225-378BD2A655F7
eprocUUID = 5C40B765-C6C9-3641-A822-2BC44D264361
Perhaps there's a bug when generating the audit token or could it be something with the Firefox signature?
I double-checked Firefox and it seems fine:
$ codesign --verify --verbose /Applications/Firefox.app
/Applications/Firefox.app: valid on disk
/Applications/Firefox.app: satisfies its Designated Requirement
Not sure if relevant, but codesign with -dv showed different flags in CodeDirectory when compared to chrome:
codesign -dv /Applications/Firefox.app
...
CodeDirectory v=20500 size=863 flags=0x10000(runtime) hashes=18+5
...
Versus chrome
CodeDirectory v=20500 size=1821 flags=0x12a00(kill,restrict,library-validation,runtime) hashes=46+7 location=embedded