UTM: Cannot load 3rd party kexts

Describe the issue 3rd party kexts, like macFUSE or the kext I am working on personally, won’t load. After reboot I get a pop-up message that says “System Extension Error”, “An error occurred with your system extensions during startup and they need to be rebuilt before they can be used. Please go to Security & Privacy System Preferences to re-enable them.”

If I go to Preferences and do as it asks, after reboot the same message appears.

SIP is disabled, developer mode is on, etc.

The same kexts work fine on bare metal.

Configuration

  • UTM Version: 3.2.3 (57)
  • Host OS Version: macOS 12.3.1
  • Intel or Apple Silicon? Apple M1 Max

Logs Output of log show --debug | grep -i macfuse:

2022-05-16 10:36:20.878345-0700 0x263      Default     0x0                  100    0    kernelmanagerd: validating extension at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:36:20.889780-0700 0x263      Default     0x0                  100    0    kernelmanagerd: [com.apple.kernelmanagerd.logging:LoadRequestResolution] checking bundle path /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext for Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:36:20.889807-0700 0x263      Default     0x0                  100    0    kernelmanagerd: [com.apple.kernelmanagerd.logging:LoadRequestResolution] checking unstaged bundle path /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext for Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
	Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext 
2022-05-16 10:36:20.961129-0700 0x54c      Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] canLoadKernelExtension - direct, evaluate, Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:36:20.962087-0700 0x54c      Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] Kernel Extension ALLOWED: Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
	Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext 
	/Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
	Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext (new)
		/Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:36:21.282160-0700 0x54c      Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] canLoadKernelExtension - direct, evaluate, Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:36:21.282557-0700 0x54c      Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] Kernel Extension ALLOWED: Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:36:21.282857-0700 0x54c      Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] Triggered kext upgrade: Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:36:21.282978-0700 0x54c      Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] Blocking upgrade dialog for kext that is already pending upgrade: Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:36:22.559237-0700 0x2e5      Default     0x0                  100    0    kernelmanagerd: validating extension at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:36:22.560082-0700 0x2e5      Default     0x0                  100    0    kernelmanagerd: [com.apple.kernelmanagerd.logging:LoadRequestResolution] checking bundle path /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext for Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:36:22.560102-0700 0x2e5      Default     0x0                  100    0    kernelmanagerd: [com.apple.kernelmanagerd.logging:LoadRequestResolution] checking unstaged bundle path /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext for Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:42:44.432792-0700 0x184f     Default     0x0                  100    0    kernelmanagerd: [com.apple.kernelmanagerd.logging:LoadRequestResolution] loadExtensions(withPaths:withIdentifiers:withPersonalityNames:withDependencyAndFolderPaths:options:withReply:): Loading paths: ["/Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext"], identifiers: [], personalityNames: []
2022-05-16 10:42:44.493065-0700 0x184f     Default     0x0                  100    0    kernelmanagerd: validating extension at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:42:44.493840-0700 0x184f     Default     0x0                  100    0    kernelmanagerd: [com.apple.kernelmanagerd.logging:LoadRequestResolution] checking bundle path /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext for Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:42:44.493858-0700 0x184f     Default     0x0                  100    0    kernelmanagerd: [com.apple.kernelmanagerd.logging:LoadRequestResolution] checking unstaged bundle path /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext for Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:42:44.509628-0700 0x184f     Default     0x0                  100    0    kernelmanagerd: validating extension at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:42:44.510237-0700 0x184f     Default     0x0                  100    0    kernelmanagerd: [com.apple.kernelmanagerd.logging:LoadRequestResolution] At least one of the request extensions / bundled extensions io.macfuse.filesystems.macfuse are NOT in the exclude list. Will do full resolution of load request
	Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:42:44.520349-0700 0x184f     Default     0x0                  100    0    kernelmanagerd: validating extension at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
	Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext 
2022-05-16 10:42:44.531168-0700 0x1953     Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] canLoadKernelExtension - direct, evaluate, Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:42:44.531854-0700 0x1953     Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] Kernel Extension ALLOWED: Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
	Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext 
	/Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
	Kext io.macfuse.filesystems.macfuse v2085.20 in executable kext bundle io.macfuse.filesystems.macfuse at /Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext (new)
		/Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
	/Library/Filesystems/macfuse.fs/Contents/Extensions/12/macfuse.kext
2022-05-16 10:42:44.994916-0700 0x184d     Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] canLoadKernelExtension - direct, evaluate, Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:42:44.995262-0700 0x184d     Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] Kernel Extension ALLOWED: Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:42:44.995521-0700 0x184d     Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] Triggered kext upgrade: Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:42:44.995636-0700 0x184d     Default     0x0                  180    0    syspolicyd: [com.apple.syspolicy.kext:default] Blocking upgrade dialog for kext that is already pending upgrade: Kext (3T5GSNBU6W, io.macfuse.filesystems.macfuse) version: 25d8ea0d2b621051e8900f62f6613c904076c8f9
2022-05-16 10:42:44.995862-0700 0x184f     Error       0x0                  100    0    kernelmanagerd: failed to load/rebuild extensions: Extension with identifiers io.macfuse.filesystems.macfuse not approved to load. Please approve using System Preferences.
2022-05-16 10:42:45.006380-0700 0x1961     Error       0x0                  644    0    load_macfuse: (KernelManagement) Remote encountered error: Error Domain=KMErrorDomain Code=27 "Extension with identifiers io.macfuse.filesystems.macfuse not approved to load. Please approve using System Preferences." UserInfo={NSLocalizedDescription=Extension with identifiers io.macfuse.filesystems.macfuse not approved to load. Please approve using System Preferences.}
2022-05-16 10:42:45.006466-0700 0x1961     Error       0x0                  644    0    load_macfuse: (KernelManagement) Extension load failed: <private>

About this issue

  • Original URL
  • State: open
  • Created 2 years ago
  • Reactions: 2
  • Comments: 42 (4 by maintainers)

Most upvoted comments

I doubt that kernelmanagerd hardcodes allowed kernels (though kmutil create (which works through kernelmanagerd) does insist (on macOS 13) that you have a KDK installed that matches the currently running kernel). Though if it does, it shouldn’t be hard to find the code that implements this restriction.

kernelmanagerd doesn’t create kernels. It works with whatever kernel is “installed” – the one that the boot kext collection is linked to. And as best I can tell it also doesn’t create boot kext collections. Apple makes those in some other way, then puts them in the “right” location (which you can see by running kmutil inspect). Once installed in this way, a boot kext collection is immutable, at least by the “normal” activity of macOS. What can be changed is the auxiliary kext collection. But, as we’ve discovered, this doesn’t work in a Virtualization framework VM. And (on physical hardware) the boot kext collection can also be (temporarily) replaced by a custom kext collection.

From kernelmanagerd’s man page and from what I’ve been able to discover, kernelmanagerd manages the kernel-specific part of rebooting – from making requested (staged) changes to the auxiliary kext collection to triggering a kernel’s reloading. As we’ve seen, it can abort this process and log the (misleading) error message kernelmanagerd: Kernel requested shutdown. Then it gives you the choice of trying again or booting into the recovery partition.

Over the next few days (and possibly weeks), I’m going to dig into kernelmanagerd and its friends, to find as much as I can about why they behave differently on physical hardware and in a Virtualization framework VM.

Above I talked about custom kext caches not working in macOS guest VMs. My workaround for third-party kexts doesn’t directly address this problem. But if Stage 2 iBoot (iBoot.img4) no longer checks the kernel cache’s “digest”, you can substitute any kernel cache you want, including a custom kernel cache built using kmutil create. Some will make your VM unbootable, or have other undesirable effects. But you can make whatever changes you please to the kernel cache.

I used kmutil create to create a custom kext cache modeled exactly on the original (with exactly the same kernel extensions). That worked fine, not surprisingly. Then I tried adding AppleARMWatchdogTimer.kext, to test out my theory that the _validate_acm_context() failures are caused by timing problems. It made my VM unbootable 😦 This doesn’t disprove my theory. But it does show that Apple had a reason not to include AppleARMWatchdogTimer.kext in its VMs’ kernel cache.

I’m still working on this, but very slowly. I’ve now ruled out kernelmanagerd from involvement in the problem of custom kernels not working in Virtualization framework macOS guest VMs – just as I previously ruled out the custom kernel itself. I re-ran my test of loading my custom kernel, this time timing it carefully so I’d know exactly where to look in the logs displayed (on the macOS guest VM) by log show. I found nothing at all – not a single line.

On a hunch that interesting logs might be found on the host (instead of the guest), I looked there too, for entries matching --predicate='process == "com.apple.Virtualization.VirtualMachine"'. There were some log entries, but (as best I can tell) all related to the Virtualization process’s interaction with the host machine. There wasn’t anything at all about its interaction with the guest.

My next direction will be using HookCase to debug the Virtualization framework on Intel Macs. It can’t virtualize macOS, but it can virtualize Linux and Windows. The work is likely to be very involved, and will probably take a long time.

I’ve already spent a lot of time using HookCase to debug kernelmanagerd on Intel Macs. I learned quite a lot. But this, too, turned out to be a red herring. Among other things, I found that the kernelmanagerd: Kernel requested shutdown. Goodbye! log message is displayed every time you shutdown or restart macOS. This really is a request from the kernel (kernelmanagerd periodically uses kext_request() to fetch all current “kext requests” from the kernel). But, of course, the kernel makes that “request” in response to a signal from userland (I haven’t yet worked out exactly what kind).

I’ve discovered some information about why _validate_acm_context() fails. But it’s very cryptic, and I can’t really interpret it:

kcgend: (libbootpolicy.dylib) [com.apple.BootPolicy:Library] BootPolicy: bootpolicy_create_linked_manifest: entry
kernel: (AppleVPBootPolicy) BootPolicy: creating linked manifest
kernel: (AppleVPBootPolicy) BootPolicy: loading misc storage
kernel: (AppleVPCredentialManager) ACM: verifyPolicy: Verifying BootPolicy (V) on CS[100] (preflight=NO, secure=YES, checkKeybagUUID=NO).
kernel: (AppleVPCredentialManager) ACM: dumpVerificationStatus: BootPolicy (V) on CS[100] *NOT* SATISFIED: 01R -> R.
kcgend: (libbootpolicy.dylib) [com.apple.BootPolicy:Library] BootPolicy: SEP command 33 (v7) returned 7: bpbc 4177, 0, 0, 0
kcgend: (libbootpolicy.dylib) [com.apple.BootPolicy:Library] BootPolicy: assert: bpe == 0  (/AppleInternal/Library/BuildRoots/d23df31a-1fa6-11ed-91f3-e2c7c6032f02/Library/Caches/com.apple.xbs/Sources/BootPolicy/dylib/dylib.c:2558)
kcgend: (libbootpolicy.dylib) [com.apple.BootPolicy:Library] BootPolicy: bootpolicy_create_linked_manifest: exit: ACM (7)

There are many other cases where _validate_acm_context() succeeds, even in a VM, even while booting. Compare this, picked more or less at random:

syspolicyd: (libbootpolicy.dylib) [com.apple.BootPolicy:Library] BootPolicy: reading blessed macOS local policy /System/Volumes/iSCPreboot/BE2ACA7D-8B5E-4E89-88F2-EE05D5354D88/LocalPolicy/1A59E46C2D579AD45C6282DE32E7B3989AD35CB73D301FD7FFE22D9F11454C59683535F41C9822598EE74081553DC5BA.img4
kernel: (AppleVPBootPolicy) BootPolicy: updating local policy User Authorised Kext List
kernel: (AppleVPBootPolicy) BootPolicy: loading misc storage
kernel: (AppleVPCredentialManager) ACM: verifyPolicy: Verifying BootPolicy (V) on CS[118] (preflight=NO, secure=YES, checkKeybagUUID=NO).
kernel: (AppleVPCredentialManager) ACM: dumpVerificationStatus: BootPolicy (V) on CS[118] SATISFIED: 01S -> S.
kernel: (AppleVPBootPolicy) BootPolicy: Local policy signing
kernel: (AppleVPBootPolicy) BootPolicy: AP hacktivation signing
syspolicyd: (libbootpolicy.dylib) [com.apple.BootPolicy:Library] BootPolicy: SEP command 23 (v7) returned 0

For what it’s worth, all the failures happen when the call to _validate_acm_context() is made (ultimately) from kcgend. Calls from syspolicyd, for example, work just fine. I noted above that I had to play a hackish trick to get kcgend to run at startup on a Virtualization framework VM. Maybe it’s not working entirely correctly. I’ll keep playing with it. But at this point I’m not very optimistic I’ll be able to do anything about its problems.

“SEP command 23” is _command_update_local_policy_uakl() in AppleVPBootPolicy.kext.

Above I theorized that these failures are the result of a deliberate policy decision by someone at Apple. I still think that. But now I believe I focused too much on the “SEP command 33” failures themselves. They may be just accidental. Now I suspect that the crucial decision was to not allow kcgend to run in Virtualization framework VMs. I found a way to make it run. But (it seems) I haven’t yet been able to make it run correctly.

My logs above came from the output (on a VM) of log show --predicate 'eventMessage contains "BootPolicy"'. A lot of the lines are missing from the output of kmutil log show. I’m discovering how much more useful log show is than the Console app’s GUI. Previously I thought most of the output you see when you start streaming in the Console app is simply lost if you’re not streaming. I couldn’t have been more wrong.

Interestingly, I get no output from running log show --predicate 'eventMessage contains "hacktivation"' on my macOS host. I’m not entirely sure what to think about that.

Apple still hasn’t fixed this bug, but I’ve discovered a sign they might be working on it.

Since there was “Ask Apple” this week, I did. Quinn confirmed it’s not going to work yet, and i’d consider that definitive.

I’ve found out what “SEP command 33” is – _command_create_linked_manifest() in AppleVPBootPolicy.kext. There’s an array named _command_functions[], and a pointer to _command_create_linked_manifest() exists in it at offset 33 X 8.

I’ve also found where _command_create_linked_manifest() fails, I think. My command of ARM64 assembler is a bit wobbly. But as best I can tell, _command_create_linked_manifest() only returns 7 (== BOOTPOLICY_ERROR_ACM) if its call to _validate_acm_context() fails.

So next I need to figure out why the call to _validate_acm_context() fails.