Can't see os_log messages from DriverKit driver

Question

Created Mar ’23

Replies 4

Boosts 0

Views 1.1k

Participants 2

I am new to DriverKit and have been experimenting with the DriverKit sample code as well as my own test driver. My current task is learning how to observe debug messages from the driver's os_log invocations. This has been frustrating because at one point I was able to see my driver's debug messages in the Console app, but now they are not appearing no matter what I try, and I have no idea what changed.

This is happening with both my own driver and Apple's samples, so I suspect the drivers are instantiating correctly -- request:didFinishWithResult: indicates success -- and calling os_log in Start, but I am just not able to see the messages in Console for some reason. I have both "Include Info Messages" and "Include Debug Messages" checked in Console's Action menu.

My problem is very similar to this previous post, but I tried the author's suggested tweak to the os_log macro and it didn't help me.

My specific questions are:

Why does DriverKit have its own log.h that is missing significant functionality? In particular, the os_log_type enum contains only OS_LOG_TYPE_DEFAULT, which means I cannot adjust the severity level of my logs. In particular, I cannot log a message at the error level (OS_LOG_TYPE_ERROR). This would be helpful in eliminating the possibility that my problem is due to some kind of severity level filtering.
Is there anything else I can do to troubleshoot this problem? I have exhausted all my troubleshooting ideas.

Thanks

Answer 1

vocaro OP

Mar ’23

Aaaaand now I can see logs again.

I have no idea why suddenly they're appearing in Console or why they weren't appearing before. Possibly a reboot of my laptop this afternoon (due to an unrelated issue) fixed everything? But I tried that before and it didn't help, so the mystery remains.

Strangely, another DriverKit issue I experienced while testing has gone away. During the time when I could not see the log messages, I also noticed that the drivers were not being successfully unloaded and replaced when relaunching the host app (despite returning .replace in actionForReplacingExtension). I would see two entries for the driver in systemextensionsctl reset (one of them in some sort of zombie "waiting for app to terminate" mode, if I remember right). I had to run systemextensionsctl reset to clear them out, otherwise the second launch of the host app would get a didFailWithError with error code OSSystemExtensionErrorExtensionNotFound (4). But I'm not seeing that any more, no matter how many times I relaunch the host app.

Gremlins...

Answer 2

vocaro OP

Mar ’23

Ok the gremlins are back. I'm not seeing logs anymore, and OSSystemExtensionRequestDelegate is reporting didFailWithError:

Request failed. Error Domain=OSSystemExtensionErrorDomain Code=4 "(null)"

I'm also seeing the extra zombie driver in System Extensions:

$ systemextensionsctl list                                                                          
2 extension(s)
--- com.apple.system_extension.driver_extension
enabled	active	teamID	bundleID (version)	name	[state]
              	UWX5KMH446	com.vocaro.TestApp.driver (1.0&#x2F;1)	com.vocaro.TestApp.driver	[terminating for upgrade via delegate]
*.      *	      UWX5KMH446	com.vocaro.TestApp.driver (1.0&#x2F;1)	com.vocaro.TestApp.driver	[activated enabled]

I can get rid of the error if I do systemextensionsctl reset but that only works for two launches. After the second launch, the zombie driver appears, and on the third one, the error starts happening (due to the zombie driver failing to unload, I assume.) At no time do I see any logs. It is so weird...

Searching through the Console logs reveals some additional errors that appear to be related to code signing:

failed to fetch &#x2F;Users&#x2F;trevor&#x2F;Library&#x2F;Developer&#x2F;Xcode&#x2F;DerivedData&#x2F;TestApp-feebyyqkhutjwcgetajghxeumarp&#x2F;Build&#x2F;Products&#x2F;Debug&#x2F;TestApp.app&#x2F;Contents&#x2F;Library&#x2F;SystemExtensions&#x2F;com.vocaro.TestApp.driver.dext&#x2F;_CodeSignature&#x2F;CodeRequirements-1 error=-10

and

&#x2F;Users&#x2F;trevor&#x2F;Library&#x2F;Developer&#x2F;Xcode&#x2F;DerivedData&#x2F;TestApp-feebyyqkhutjwcgetajghxeumarp&#x2F;Build&#x2F;Products&#x2F;Debug&#x2F;TestApp.app&#x2F;Contents&#x2F;Library&#x2F;SystemExtensions&#x2F;com.vocaro.TestApp.driver.dext: package type not `SYSX`

This issue keeps happening even if I wipe out the Xcode build folder for my project and completely rebuild.

It started happening when I switched from a bare-bones driver inheriting from IOService (nearly identical to the Xcode DriverKit template) to one inheriting from IOUserHIDEventService and specifying a ProductID and VendorID (like Apple's HID sample). Strangely, even if I revert to the original code, delete the build folder, clear the system extensions, and reboot, it keeps happening.

And still.. no... logs...

Answer 3

the bugs killer OP

Mar ’23

I am facing the same issue.

The Driverkit seems quit unstable.

Sometime it can't start. There's no process in "ps -A". Sometime can't see logs in consle.app

The NullDriver example code client call driver method always faild. .. The HIDKeyboard example dext can't start......

...........

Answer 4

the bugs killer OP

Mar ’23

big sur 11.6 xcode 13.1