Kernel DriverKit log subsystem

I'm debugging a USB DriverKit driver, and noticed the os_log messages during the kernel verification checks do not have a subsystem (not my driver's logging):

{
  "traceID" : 44303244788367364,
  "eventMessage" : "DK: G600Driver-0x1002dd073: family entitlements check failed",
  "eventType" : "logEvent",
  "source" : null,
  "formatString" : "DK: %s-0x%qx: family entitlements check failed\n",
  "activityIdentifier" : 0,
  "subsystem" : "",
  "category" : "",
  "threadID" : 2655768,
  "senderImageUUID" : "198748B0-2858-345A-957A-45C9ACB4C2F2",
  "backtrace" : {
    "frames" : [
      {
        "imageOffset" : 9007231,
        "imageUUID" : "198748B0-2858-345A-957A-45C9ACB4C2F2"
      }
    ]
  },
  "bootUUID" : "",
  "processImagePath" : "\/kernel",
  "timestamp" : "2022-06-14 01:57:51.171906-0700",
  "senderImagePath" : "\/kernel",
  "machTimestamp" : 281599031530198,
  "messageType" : "Default",
  "processImageUUID" : "198748B0-2858-345A-957A-45C9ACB4C2F2",
  "processID" : 0,
  "senderProgramCounter" : 9007231,
  "parentActivityIdentifier" : 0,
  "timezoneName" : ""
}

Is there a recommended way (other than substring matching on the driver name) to create a predicate for filtering the log to messages relevant to my driver? Thanks.

Accepted Reply

These are log messages being generated by the kernel itself, right? If so, the absence of a subsystem and category is normal, albeit annoying, behaviour. You’ll have to come up with a more creative way to filter, at least in the short term.

If you’d like to see the kernel do a better job of this, I encourage you file an enhancement request describing your requirements. Please post your bug number, just for the record.

Just to set expectations here, adding subsystem and category values to the kernel logging would be a challenge. However, that doesn’t preclude better logging. Lemme give you an example from an area I’m more familiar with, networking. In the networking stack we assign unique IDs to each connection and then log those IDs with every event associated with that connection. That allows us to easily find all the activity for a specific connection. It seems like it’d be reasonable for the kernel to do something similar for its driver matching and loading.

Share and Enjoy

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

Replies

These are log messages being generated by the kernel itself, right? If so, the absence of a subsystem and category is normal, albeit annoying, behaviour. You’ll have to come up with a more creative way to filter, at least in the short term.

If you’d like to see the kernel do a better job of this, I encourage you file an enhancement request describing your requirements. Please post your bug number, just for the record.

Just to set expectations here, adding subsystem and category values to the kernel logging would be a challenge. However, that doesn’t preclude better logging. Lemme give you an example from an area I’m more familiar with, networking. In the networking stack we assign unique IDs to each connection and then log those IDs with every event associated with that connection. That allows us to easily find all the activity for a specific connection. It seems like it’d be reasonable for the kernel to do something similar for its driver matching and loading.

Share and Enjoy

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

Yeah, they do come from the kernel, at least as far as I can tell. Thank you, Quinn, I appreciate the information. Actually, having a predicate on "DK:" at the beginning would also seem to work well enough. Maybe after I get some more experience, I'll file that enhancement request, but as this is my first time writing a driver I'm not sure if what I need, or think I need, would be useful to others.