In previous episodes, I had reached the point where the Mac is loading its pre-linked kernel, containing an optimised version of the kernel and all its extensions, from /System/Library/PrelinkedKernels/prelinkedkernel. From this point on, we have the great benefit of being able to read what happens in the unified log.
The log extracts which follow show, at the left in blue, the clock time in hours, minutes, and decimal seconds, then any subsystem identifier in red, and in black the eventMessage posted to the log.
For the sake of simplicity, this is analysed on a MacBook Pro 2017 (so no T2 chip or Secure Boot) booting from the internal SSD in APFS without any encryption.
The first log entry after boot may, as here, be out of time sequence. What seems to be happening here is that the log system is recording that it is continuing to write to an existing log file, which will expire within 1 day, and writing that to the log file on disk before it has written out those entries collected in memory during the boot process. That gives insight into the size of its in-memory cache, as sufficient to store over 5 minutes of quite busy log entries.
After that comes the boot marker of
=== system boot:
followed by the UUID not of that Mac, but probably of the event. The log items which follow were then held initially in memory, hence the log class given. The kernel version and its date follow, with information about virtual memory.
Inevitably, much of the early part of startup is devoted to hardware initialisation, even though many systems have already gone through basic setup during preceding phases in the boot process. Clocks and keys are also high on the list of priorities, with file integrity and fundamental security services making their appearance here as well.
On a laptop model, previous battery data are cleared early too, and smart management started.
It takes quite a while for this next important waypoint entry to appear: the
Previous shutdown cause. Code 5 means that it was clean and user-initiated, and you can find a summary of other codes here.
Hardware setup continues, with Thunderbolt 3 next; you’ll also sometimes see this referred to in the log by the codename of
Thor. System security policy is loaded at about this time too.
Another important group of hardware-related entries are those concerning disks and their file systems. This still includes the traditional entry for
BSD root, and even in Mojave proceeds to try mounting HFS+ volumes next, before mounting the APFS startup volume as seen here. That is followed by mounting /dev/disk1. Any file system problems are likely to surface here, where HFS+ journal replays should be recorded if they were required.
System time is adjusted, and this leads to the first log entries from named subsystems, concerned with security, and OpenDirectory. A lot of com.apple.opendirectory entries then follow.
Then, about 4.2 seconds after the first entry, the login window is prepared.
Until now, the new privacy system TCC hasn’t written to the log. What follows with respect to TCC is fascinating, and worth an article all of its own: I will describe it in detail in the near future.
When starting up from a prelinked kernel, there are no log entries recording the loading of kernel extensions, which used to be a help when trying to diagnose extension problems and conflicts.
Shutting down is a quicker process, taking around half a second, but filled with copious complaints from com.apple.xpc.remote. First indications of an imminent shutdown include farewells from various systems.
Then for a period of about 0.4 seconds, the log is filled with identical pairs of messages from com.apple.xpc.remote reporting that it is starting browsing, then is unable to. The final sign-off is a clock adjustment, in
=== system wallclock time adjusted
followed by log silence.
If you want to compare these with what used to happen in macOS Sierra, you’ll find a full account of the latter here.