Debugging Time Machine

I upgraded to MacOS Mojave a few weeks ago, and over the last few days I’ve been getting warnings from MacOS that my last successful backup was some time ago. Backups were starting regularly but getting stuck at ‘Preparing Backup’. After several days being stuck at ‘Preparing Backup’, I decided to investigate.

Time Machine logs are stored using MacOS’s Unified Logging mechanism. To view the Time Machine logs live, open a Terminal and run the following command:

log stream —style syslog  —predicate ‘senderImagePath contains[cd] “TimeMachine”’ —info

Then, start a Time Machine backup and you should start to see log output in your terminal window. In my case, I could see that Time Machine had decided to do a ‘Deep Traversal’ which happens when it can’t work out what to backup. That scan was failing because of some underlying disk corruption. A quick run of the Disk Utility First Aid tool sorted that out, and backups started working normally again.

Comparing Time Machine Backups with tmutil on Mojave

So good news, backups are working again - but I now have 23GB to backup. I wasn’t too concerned, I’d just upgraded to Mojave, upgraded Xcode and a few other apps too and so expected a big backup. But, I noticed that subsequent backups were picking up 250-500MB each time.
That seemed like a lot of churn, and so worth some investigation.

Time Machine ships with a command line tool called tmutil that amongst other things lets you compare backups. On pre-Mojave versions of MacOS, you could just fire up the Terminal and run something like:

cd “/Volumes/Backup Disk/Backups.backupdb/macbookpro”
tmutil compare 2018-10-27-101112 2018-10-26-174321

This shows you all of the changes between the two specified backups. This is really helpful to see if files that don’t really need to be backed up are included, e.g. log files, and so can be excluded from the backup. However, if you try to run this command on Mojave then you’ll see something like this:

Added:         0B
Removed:       0B
Changed:       0B

Hmmm…

It’s not obvious at first, but this happens because of a new feature of MacOS Mojave called System Integrity Protection (SIP).
SIP helps to protect your privacy by controlling access to sensitive data, including Time Machine Backups.

To allow tmutil compare to work, you need to temporarily grant the Terminal application Full Disk Access. You can do this in the ‘Security & Privacy’ System Preferences. Once you’ve done that, restart Terminal, try the tmutil compare again and it should work.

When you are finished, be sure to remove Full Disk Access for Terminal.