I’d like to run High Sierra on my iMac, just not all the time, yet. It has a 2 TB Fusion Drive, which I am not prepared to replace with an equivalent SSD, unless Apple will foot the bill. I also have several hundred apps, many of which are older, and likely to run into problems. Some cannot be updated to be compatible, others cannot yet.
One long-established method of accommodating this is to create a dual-boot system: to install High Sierra on an external SSD, and keep Sierra on the Fusion Drive. I could then switch between them whenever I needed to. However, I rely on Time Machine backups made from Sierra, and when I tried to set this iMac up as a dual-boot system with the release of High Sierra, those backups proved a serious problem.
Each time that I restarted back into Sierra, Time Machine apparently lost track of its previous backups, and started to make a full, initial backup of over 1 TB. This forced me to wipe my five years of backups in order to recover my backup storage, and I have not tried restarting this iMac in High Sierra since.
Now that 10.13.1 is out, the bugs in High Sierra are being fixed, and there are prospects of it delivering some of its features, I am re-evaluating what to do. I therefore needed to understand what went wrong with Time Machine when I was running the dual-boot system. Although that was seven weeks ago, I have kept a logarchive which includes logs from the time, and am analysing them using Woodpile.
The most striking thing when first looking at Time Machine entries in the log for the period after restarting in Sierra is their odd pattern: in this period of five hours, there’s an initial burst of log activity as backups start up again (I had turned them off in High Sierra), then single messages posted every hour, rather than the regular hourly backup pattern.
The reason for this is obvious from looking at Time Machine’s log entries for this period. They start with
14:12:56.461871 [com.apple.TimeMachine.TMLogInfo] com.apple.backupd-auto launchd job enabled
14:13:26.371229 [com.apple.TimeMachine.TMLogInfo] Starting automatic backup
14:13:27.083504 [com.apple.TimeMachine.TMLogInfo] Backing up to /dev/disk3s2: /Volumes/PROMISE PEGASUS/Backups.backupdb
14:14:19.878432 [com.apple.TimeMachine.TMLogInfo] Forcing deep traversal on source: "Macintosh HD" (device: /dev/disk2 mount: '/' fsUUID: BE50387F-1302-31FB-B567-68F50F8ADE7A eventDBUUID: 462834AF-AFB9-4E80-8FB9-0775D28F05B3)
14:14:19.884777 [com.apple.TimeMachine.TMLogInfo] Deep event scan at path:/ reason:must scan subdirs|require scan|
14:14:19.884864 [com.apple.TimeMachine.TMLogInfo] Running event scan
So that first backup has not been possible. Instead, a deep event scan took place. This is because Time Machine normally relies on the hidden FSEvents information on the volume which it is to back up, for information about what has changed since the last backup.
14:14:19.884961 [com.apple.TimeMachine.TMLogInfo] Finished scan
14:14:19.885216 [com.apple.TimeMachine.TMLogInfo] Saved event cache at /Volumes/PROMISE PEGASUS/Backups.backupdb/Howard’s iMac/2017-09-26-141419.inProgress/684B2CB0-B97C-430A-88F6-7CBCD5FE8699/.BE50387F-1302-31FB-B567-68F50F8ADE7A.eventdb
14:14:19.903916 [com.apple.TimeMachine.TMLogInfo] Not using file event preflight for Macintosh HD
14:23:37.547569 [com.apple.TimeMachine.TMLogInfo] Will copy (1.01 TB) from Macintosh HD
Worse, Time Machine has decided that it cannot do a scan, and will just make a complete and fresh backup of everything, just over 1 TB. Five hours later, it decides that is good.
19:09:20.105740 [com.apple.TimeMachine.TMLogInfo] Copied 5019362 items (1 TB) from volume Macintosh HD. Linked 0.
19:09:41.256164 [com.apple.TimeMachine.TMLogInfo] Created new backup: 2017-09-26-190940
19:09:42.328562 [com.apple.TimeMachine.TMLogInfo] Copying OS X Recovery set
19:09:48.441375 [com.apple.TimeMachine.TMLogInfo] Starting post-backup thinning
19:14:26.980364 [com.apple.TimeMachine.TMLogInfo] Deleted /Volumes/PROMISE PEGASUS/Backups.backupdb/Howard’s iMac/2017-09-25-131208 (91.3 MB)
19:14:26.980379 [com.apple.TimeMachine.TMLogInfo] Post-backup thinning complete: 1 expired backups removed
19:14:35.114703 [com.apple.TimeMachine.TMLogInfo] Backup completed successfully.
There are no clues from other processes as to what might have gone wrong here. Messages from the kernel look good, including:
14:12:29.001981 kernel: Darwin Kernel Version 16.7.0: Thu Jun 15 17:36:27 PDT 2017; root:xnu-3789.70.16~2/RELEASE_X86_64
14:12:39.298715 kernel: (AppleSMC) Previous shutdown cause: 5
14:12:42.262900 kernel: (PromiseSTEX) STEX : Thunderbolt device vendor ID : Promise , device model : Pegasus R4
showing the kernel started up fine, giving a cause code for a clean shutdown, and starting up my external RAID system fine.
The pattern of kernel messages for the first six minutes or so after starting up looks fairly normal too.
Looking at the previous startup in High Sierra, though, is more worrying. Time Machine fired up straightaway:
13:42:11.018718 [com.apple.TimeMachine.TMLogInfo] Inheriting root volume 'ExternalSSD1' (previous UUID: BE50387F-1302-31FB-B567-68F50F8ADE7A)
13:42:11.043617 [com.apple.TimeMachine.TMLogInfo] Reassociated snapshot volume '/Volumes/PROMISE PEGASUS/Backups.backupdb/Howard’s iMac/2012-09-26-203803/Macintosh HD' (remapped UUID from BE50387F-1302-31FB-B567-68F50F8ADE7A to A60C2C27-E17F-3FAF-8B5C-53981AF9C70D)
and then ran another couple of hundred of those UUID remappings.
High Sierra’s Time Machine also decided to perform a deep event scan, but not on its own startup volume, on the Sierra startup volume instead:
13:42:18.404357 [com.apple.TimeMachine.TMLogInfo] Forcing deep traversal on source: "Macintosh HD"
So it was no small wonder that, when starting back in Sierra, Time Machine found that FSEvents was unable to assist, tried its own deep event scan, and ended up making a full backup.
My conclusion is that running Time Machine in either of the versions of macOS being run in a dual-boot system would be likely to result in problems backing up, such as repeated deep event scans, and frequent full backups.
Would it be feasible then to use a dual-boot system without Time Machine backups?
The answer lay a little further down in Sierra’s kernel messages:
12:39:25.893660 (apfs) fs_get_inode_with_hint:7115:
12:39:25.893663 (apfs) failed to load inode 547414 ret 22
12:39:25.902628 (apfs) fs_get_inode_with_hint:7115:
12:39:25.902631 (apfs) failed to load inode 547418 ret 22
12:43:21.456723 (IOStorageFamily) disk5s1: device is not readable.
12:43:21.546687 (apfs) apfs_vfsop_unmount:931:
12:43:21.546689 (apfs) unmounting devvp <private>
12:43:21.546698 (apfs) apfs_vfsop_unmount:956:
12:43:21.546699 (apfs) waiting for purgatory cleaner to finish.
12:43:21.558712 (apfs) apfs_vfsop_unmount:1045:
12:43:21.558713 (apfs) flushed all txn's!
12:43:21.558825 (apfs) sanity_check_alloced_blocks:124:
12:43:21.558828 (apfs) fs_alloc_count mismatch: fs root nodes 38660 extent 2898 omap 517 snap_meta 1 udata: 2562483 fs_alloc_count 2637328
12:43:21.563051 (apfs) apfs: total mem allocated: 0 (0 mb);
12:43:21.563053 (apfs) apfs_vfsop_unmount:1120:
12:43:21.563054 (apfs) all done. going home. (numMountedAPFSVolumes 0)
There are repeated problems when trying to keep any of High Sierra’s APFS disks mounted under Sierra, almost certainly because Sierra’s early pre-release support for APFS is now long out of date with High Sierra’s latest version.
All the indications are that I could only use a dual-boot Sierra and High Sierra system for my iMac if I turned Time Machine off on both systems, and didn’t use any APFS disks. I’ll take that as a no, then.
If you have had greater success making a dual-boot system, I’de love to hear from you.