Big Sur, particularly when it’s running on an M1 Mac, doesn’t make it easy to tackle extension problems. Long gone are the days when the log gave a running commentary on each kernel extension as they were loaded. In Big Sur’s unified log, mum’s the word: you’re unlikely to see any mention of loading of kernel or system extensions or their relatives. So what can you do if you suspect that one of your third-party extensions could be running into trouble, or creating problems for others?

Try Safe mode

In Safe mode, all third-party extensions and some Apple-supplied ones aren’t loaded. As a quick test, there’s nothing to beat starting up in Safe mode. If you’re working with an M1 Mac, remember that these new models enter Safe mode through Recovery Options, as explained here.

Safe mode also does other things, which sometimes magically solve problems, even though Apple is a little unclear as to exactly which caches and other data are cleared or rebuilt. So successful startup in Safe mode doesn’t actually prove that the problem was down to a third-party extension, but it should be a good clue. And if this doesn’t make booting any better, a third-party extension is unlikely to be the cause of the problem. It could, for instance, be a misconfigured network connection or something else which doesn’t change with Safe mode.

Time boot

Slow booting isn’t a specific symptom, but it suggests that something is awry. It’s worth timing each phase of what you see, up to the moment that the login screen appears, and comparing that with what your Mac usually does, assuming that you’ve previously made a record of a ‘healthy’ boot. Unfortunately, this varies according to Mac model, configuration, firmware and macOS version, and sometimes seemingly even the weather.

Locate the delay

Although the unified log may not give details of what takes place during loading of extensions, it does provide valuable clues as to when things are going wrong as it provides precise timings. I’ve been studying the logs of several M1 Macs and Intel models, and offer the following observations. (You’ll also want to note this important bug report affecting the log show command on M1 Macs running macOS 11.1.)

The first two entries in an M1 boot appear fixed, and are distinctive (all times being given in decimal seconds):
03.392395 === system boot: [UUID]
09.939310 kprintf initialized

The first of those is the boot banner, and the second the start of the logged kernel phase. Typically, the time difference between them is 5-7 seconds on the M1 Macs which I have analysed. In this example, it’s around 6.6 seconds.

Further down the log, there’s a point at which boot transitions from the kernel to security phase, at which there’s another substantial time delay in entries. This normally occurs just before a distinctive landmark, system time adjustment, and commonly close to a ‘sandboxing init issue’ with the Wi-Fi firmware loader. For example:
10.309049 RTBuddy(GFX): start(<private>) - (Oct 31 2020@00:25:20)
15.369546 wifiFirmwareLoader Sandboxing init issue, couldn't find profile in default paths, attempting default compiled profile
15.391319 wifiFirmwareLoader Sandboxing init issue resolved: "Success"
08.485687 === system wallclock time adjusted
08.514649 === system wallclock time adjusted

There’s a gap of 5.1 seconds there which occurs just before system time adjustment. That should normally be less than about 8 seconds, and may not appear at all during some boots of M1 Macs. Adjustment of system time complicates observations: as shown, in this case there’s a step back in time by around 7 seconds, occurring over the two entries.

Because there are only three currently available Apple Silicon Macs with almost identical hardware, firmware and software, boot log entries between them are remarkably similar in sequence and timings. This makes it easy to spot differences between systems. Here are similar landmarks for a different M1 model:

15.451904 === system boot: [UUID]
22.369750 kprintf initialized
…
22.740229 AudioDMAController_T8103 setDirectionAndRole: APA2TX::admac-aop-audio::589: TX:Initialized.
22.740246 AudioDMAController_T8103 setDirectionAndRole: APA3TX::admac-aop-audio::589: TX:Initialized.
30.386373 Sandboxing init issue, couldn't find profile in default paths, attempting default compiled profile
30.408469 Sandboxing init issue resolved: "Success"
23.154775 === system wallclock time adjusted
23.182194 === system wallclock time adjusted
23.189528 Starting userland kernel management subsystem (KernelManagement_executables-102.60.20)

The time gap between the boot banner and kprintf is around 6.9 seconds, and the gap before time adjustment is 7.6 seconds.

My M1 MacBook Pro has Little Snitch installed, with its new system extension, which may change the boot entries:
09.342468 === system boot: [UUID]
15.906328 kprintf initialized
…
16.271952 PMRD: PowerChangeDone: ON_STATE->ON_STATE
16.273399 AppleA7IOPNub: withRegistryEntry, 47: allocated nub <private>
16.575393 === system wallclock time adjusted
16.600330 === system wallclock time adjusted
16.603635 CoreFoundation Loading Preferences From System CFPrefsD
16.603991 Sandboxing init issue, couldn't find profile in default paths, attempting default compiled profile
16.607908 Starting userland kernel management subsystem (KernelManagement_executables-102.60.20)

The time gap between boot banner and kprintf is similar at 6.6 seconds, but any gap before time adjustment could only be around 0.3 seconds, and may not occur at all.

Here’s a pathological case, from another M1 MacBook Pro which the user is complaining starts up slowly:
01.415100 === system boot: [UUID]
06.466227 kprintf initialized
…
06.818509 RTBuddy(PMP): start(<private>) - (Dec 2 2020@20:33:54)
34.586085 Sandboxing init issue, couldn't find profile in default paths, attempting default compiled profile
34.604770 Sandboxing init issue resolved: "Success"
29.189798 === system wallclock time adjusted
29.218499 === system wallclock time adjusted

While the time from boot banner to kprintf is only 5 seconds, that before time adjustment is 27.7 seconds, sufficient to make the user complain about a long period of apparent inactivity. That M1 has several system extensions, and a modified /etc/hosts file, but removing the extensions didn’t alter the delay in startup, suggesting it may be a network configuration issue.

Intel Macs are different. With so many different models, firmware versions, and releases of macOS, events during boot are much more variable. However, there is one measure which can be useful on (at least) those models with T2 chips. Here are equivalent landmark log entries from my iMac Pro running 11.1:
25.366424 === system boot: [UUID]
25.366520 kernel mem_actual: 0x800000000 legacy sane_size: 0x7f0000000
…
26.211473 clock_initialize_calendar system has monotonic clock
26.212424 mcache: 16 CPU(s), 64 bytes CPU cache line size
26.214000 kernel Couldn't alloc class "AppleSEPARTService"
26.214036 AppleCredentialManager: handleEventGated: called, event(5).
45.529230 dirhelper started normally
45.529490 dirhelper started with no mach messages queued, cleaning directories
45.529495 dirhelper Cleaning T/ older than 3 days
45.529502 dirhelper Cleaning TemporaryItems older than 3 days
44.981431 === system wallclock time adjusted
45.054129 === system wallclock time adjusted

There is negligible delay between the boot banner and the next log entry, at the start of the kernel phase. However, at the end of the kernel phase and just before system time adjustment is a gap of 19.3 seconds: that’s a long pause in log entries.

Disable third-party extensions

When you suspect that one or more third-party extensions is causing a problem, the best course is to disable or uninstall as many of them as you can. This should now normally be performed within the app which uses them, which for system extensions at least is the most consistent and effective. Once that has been performed, time the boot process using the log and see whether this has made startup more brisk again, and fixed any other ill-effects.

Enable them one by one

Once you’ve eliminated the boot delay and other problems, use the same apps to add back required extensions one at a time, checking boot delays and other ill-effects as you go.

Although painstaking, in the absence of information about extensions in the unified log, this appears to be the best way to resolve extension problems, particularly on M1 Macs. Unless you have a better idea?