In the previous article, I stepped through what should appear in the log during a single backup, and should give you valuable clues as to what’s going wrong when a backup – typically the first – doesn’t complete. This article turns to look at problems which can occur in automatic backups once they’re running regularly.

If you enjoy browsing the log, there’s nothing to stop you from studying each automatic backup using Consolation. But the free utility which I have developed to perform this task more efficiently is T2M2, which works with Time Machine (TM) in all versions of macOS from Sierra to Catalina. For El Capitan and earlier, you should still be good using Console, as TM there writes fewer and simpler entries in the log, and those older versions of Console can view entries in existing logs, unlike their successor in Sierra and later.

As with Consolation, you need to run T2M2 when logged in as an admin user. This is because it uses the command tool log to fetch log entries, and Apple has decided that, in the unified log from Sierra onwards, only admin users can have access to it. If you normally run as a ‘regular’ user, switch to an admin account before opening T2M2.

T2M2 is designed to analyse backups which have been made in the past, that’s over the last 1-48 hours, using the normal despatching mechanism. If you use a third party tool to control when backups are made, and particularly if you have set them to occur infrequently, then it’s going to be of very limited value. Those third party tools can’t reschedule backups using the default DAS-CTS system, which alters the log entries substantially as a result.

If you run T2M2 while a backup is in progress, it will find a mixture of old, completed backup entries and the start of the current backup, which can be difficult to interpret. So in general, you should wait until any backup in progress has completed before clicking on its Check Time Machine button.

There’s only one control in T2M2: how long a period to analyse, in hours. Although you can edit the figure directly, if you do so you must press the Tab or Enter key after changing the number for the app to recognise that change. It’s usually simplest to use the stepper control to adjust the period.

Health indicators

T2M2 now has three health indicators: its ‘traffic light’ at the top of the window, which gives an overall guide to how its results look, a separate emoji in the report which warns when free space on the backup volume is getting low, and additional emojis to highlight individual errors which have been found. If any of these is not green, or a green tick, then you should study its detailed report carefully. If any are red, or a red No Entry sign, then you need to pay particular attention.

Failure of automatic backups

The main driver for my development of T2M2 was a bug in Sierra which leads to the failure of the scheduling system DAS and CTS to run automatic backups at regular intervals. Unless your backup drive is noisy, and you pay careful attention to its hourly rattling, the only way of knowing that backups are being made regularly is to keep checking the TM item in your menu bar. macOS doesn’t monitor backups and warn you when they stop occurring or become irregular.

When this does happen, T2M2 performs additional analysis of the log to check on the state of the scheduling processes DAS and CTS, and reports those. Here’s an example from a failure in Sierra.

Key sections from the report read:
Analysis for 2 hours from 2017-05-28 11:23:08 +0000 to 2017-05-28 13:23:08 +0000:
…
Started 1 auto backups, and 0 manual backups; completed 1 backups successfully,
last backup completed successfully 111.0 minutes ago,
…
Running check on scheduling system (CTS and DAS).
DAS appears to have stopped rescoring activities over the last 90 minutes.
Running CTS check next.
CTS has not been told to run a backup in the last 90 minutes. Scheduling may have stopped.
Consider restarting your Mac.

That should be self-explanatory: the scheduling system has failed, and automatic backups are now irregular and infrequent. The only solution is to restart that Mac.

When you run T2M2 on a Mac which has spent periods asleep, during which it hasn’t made any automatic backups, you can see a similar picture and warnings. Currently the app doesn’t analyse sleep patterns, so you’ll need to know what that Mac has been doing by way of sleep before coming to any firm conclusion.

Cancelled backups

Another good reason for automatic backups not taking place regularly is when a backup takes so long that it extends past the time of the next scheduled backup. What happens then is that the scheduling system tries to call the next backup, which is promptly cancelled when the system recognises that one is still in progress. The normal rule in macOS is that no new backup will be started until the previous backup had completed at least ten minutes ago.

The number (if any) of cancelled backups is usually shown in the report, and is obvious from the time intervals given between each backup performed, and the total number completed over the period.

Two common reasons for backups being cancelled because the previous backup is still in progress are first backups, particularly to networked storage, and deep scans.

Normal results

Information provided in a normal set of results varies slightly according to the version of macOS running.

In addition to the green traffic light at the top, you should see a green tickbox emoji next to the amount of free space remaining on the backup volume. The rules for deciding which emoji to show for the free space measurement are:

• A red No Entry sign ⛔️ indicates there’s less than 10 GB free.
• A yellow Warning Triangle ⚠️ indicates there’s 10-50 GB free.
• A green Tick ✅ indicates there’s 50 GB or more of free space.

The latest version (1.9) of T2M2 adds information about Catalina’s chosen strategies for determining what needs to be backed up. Previous versions of macOS don’t have this luxury, as I explained in the first article in this series.

When making a backup, Catalina’s TM considers different strategies for determining what needs to be backed up. The rules are as follows:

• If that volume hasn’t been backed up before, it performs a first run backup, in which the entire contents are copied.
• If backing up the Recovery volume, a ‘deep scan’ is performed on every subsequent occasion.
• For other APFS volumes, it chooses whether to use the hidden FSEvents database, or if that isn’t suitable, it may calculate the differences between two snapshots instead.
• For HFS+ volumes, only the FSEvents database is available.
• When other methods fail, or aren’t available, a deep scan is performed.

Strategies are reported on a volume total basis. For a Mac which is just backing up its internal storage, which has System, Data and Recovery volumes to be backed up, that represents three volumes each hour. After two hours of backups, you’d therefore expect T2M2 to report that 6 volume backups were made, of which 2 were deep scans (the Recovery volume), and 4 used FSEvents (the System and Data volumes). Should the FSEvents option not be available on any given volume, then T2M2 should report the number of volume backups affected in total.

Errors

T2M2 reports any TM errors which it encounters in the log. Minor errors include an inability to copy a file which needs to be backed up, something that I have encountered when certain App Store apps are open at the time that a backup is made. In those cases, the App Store receipt for an open app may not copy into the backup, returning an error of -5000. That vanishes when the app is closed.

When errors are found during a TM backup, they are reported with a red No Entry sign ⛔️ to draw attention to them.

Time

One of the thorniest problems in designing and using T2M2 is deciding which timezone to use. Although local time is attractive and most convenient for users, it unfortunately isn’t unique: for example, when adjusting from summer time to normal time, there are two moments in one night when it is exactly 0130, and travelling between time zones also causes great confusion.

As a result, wherever possible T2M2 gives times which are standardised, either to UTC (GMT), or with a stated timezone correction. For example, the first line might read
Analysis from 2019-12-02 05:09:39 +0000 to 2019-12-02 09:09:39 +0000 for 4 hours
to indicate that those times are given in UTC/GMT.

Should T2M2 report any errors, it quotes time in those standardised according to log conventions, which also gives any timezone correction. Although these aren’t the most convenient for many users, they are unambiguous.

T2M2 reports give a lot of additional detail which is helpful in monitoring backup performance, and more. The app’s Help book steps through each entry in the report with explanations of how they should be interpreted.

In the next article in this series, I will turn to consider the problems which can arise in TM backups, and what you can do about them.

This series is dedicated to James Pond (1943-2013), who really did know everything about Time Machine.