Logging in Kernel Extensions (KEXTs) on macOS

4 min readApr 5, 2021

Some quick scribbles that will hopefully save somebody else from a lot of rebooting and cursing.

Hardware: MacMini M1

OS: Big Sur 11.3

os_log has been the “default” logging system on macOS since 10.12 (AKA Sierra). Almost all of the system routines go through os_log except when they don’t ( I’m looking at you NSLog).

Because I’m masochistic, I’m doing some work on a KEXT that we need on ARM64. It had a pile of #ifdef and some other weird and wonderful logging code that I decided should be moved over to os_log. Sadly this led to a rathole. Here’s the bit I wish were in the man pages:

Best practices in user space, will bite you in kernel space.

The os_log docs go into some detail about privacy and redaction. Turns out that if you attempt:

os_log(OS_DEFAULT_LOG, “%{public}s”, myPassword);

from the kernel that you will never see the log anywhere. In fact it seems that any %{<value>} in a format string is a sure way to never see them in a console. Interestingly, a plain old

os_log(OS_DEFAULT_LOG, “%s”, myPassword);

works just fine, and will display the unredacted string for you (contrary to what you expect from the docs).

Unfortunately this rule doesn’t apply to all types.

os_log(OS_DEFAULT_LOG, “Pointer: %p”, aPtr);

will probably give you:

kernel: (subsystem) Pointer: <private>

in your logs.

Trying to be tricky and do:

os_log(OS_DEFAULT_LOG, “Pointer: %{public}p”, aPtr);

will prevent anything from showing.

Being ornery I tried:

os_log(OS_DEFAULT_LOG, “Pointer: %#llX”, (unsigned long long)aPtr);

and still got:

kernel: (subsystem) Pointer: <private>

This piqued my interest, so I tried:

void *aPtr = 0x25;

os_log(OS_DEFAULT_LOG, “Pointer: %#llX”, (unsigned long long)aPtr);

and lo and behold I got:

kernel: (subsystem) Pointer: 0x25

At this point I headed to the sources to see what was up. It turns out that os_log is considerably different in the kernel.

os_log does not support the following modifiers:

Privacy: {

Pointer Data: P

Floating Point Types: L, a, A, e, E, f, F, g, G

Wide characters or strings: C, S

Objective-C: @

and will abort with a blank log if you try to use any of them.

Furthermore any scalar value (int, pointer, etc) that has a size ≥ sizeof(void*) is checked, and if it falls between VM_MIN_KERNEL_AND_KEXT_ADDRESS and VM_MAX_KERNEL_ADDRESS, it will be marked as <private> (unless you happen to be running against a debug or development kernel).

So this means no printing of pointers unless you get tricky. If you do need a pointer value for some reason, might I suggest a format of: 0x%x%x passing your pointer in two parts: (uint32_t)(((uint64_t)value) >> 32), (uint32_t)(((uint64_t)value) & 0xFFFF)).

For what it’s worth printf style precision using . is supported, but several other features like left-align, force-sign, group by thousands etc. are ignored (but at least you get values).

Custom Logs

Custom logs created using os_log_create appear to work initially until you discover that os_log_create always returns the same value no matter what you pass in. So there is only “one” log without any ability to filter on subsystem or category. The only thing you can filter on is sender which appears to be the name of the KEXT executable. Note that for reasons I cannot explain it is sender when filtering with the log command, but isLibrary when using the Console application.

Log Types

The log types are recorded (debug, info, error etc.), so using os_log_debug vs os_log does give you something to filter on. Note though thatos_log_info_enabled and os_log_debug_enabled both always return true, so if you are using them to gate some performance sensitive code, you will need to fall back on preprocessor macros or an internal flag.

Some fun side notes:

IOLog

IOLog which used require a newline printf style, now goes through os_log which adds a newline by default, so you will often get blank lines in your logs from older KEXTs.