The Time Machine Mechanic, T2M2, gives you two indicators about your recent Time Machine backups: the simpler is a summary traffic light, which will be green for an apparently healthy series of backups, amber if there are potentially worrying results, and red if you need to check errors or other issues in its text report. This article explains details of what is included in the text report, what it means, and what you should consider to fix any problems.

Normal backup log

The following is an example of a normal automatic backup as recorded in the log viewed in Consolation, edited to remove irrelevant information:
19:13:47.026207+0100 Starting automatic backup
19:13:47.071651+0100 Backing up to /dev/disk3s2: /Volumes/PROMISE PEGASUS/Backups.backupdb
19:13:48.334003+0100 Will copy (16.1 MB) from Macintosh HD
19:13:48.334374+0100 Found 313 files (16.1 MB) needing backup
19:13:48.371357+0100 15.59 GB required (including padding), 2.9 TB available
19:18:33.114927+0100 Copied 377 items (15.9 MB) from volume Macintosh HD. Linked 10698.
19:18:40.540289+0100 Created new backup: 2017-05-22-191840
19:18:41.005831+0100 Starting post-backup thinning
19:20:52.789795+0100 Deleted /Volumes/PROMISE PEGASUS/Backups.backupdb/Howard’s iMac/2017-05-21-181134 (62.1 MB)
19:20:52.789812+0100 Post-backup thinning complete: 1 expired backups removed
19:20:58.596470+0100 Backup completed successfully.

This is the information which T2M2 uses to analyse each backup performed within the chosen period. In the event that backups appear to have been made infrequently or at irregular intervals, T2M2 now also performs some basic analysis on the scheduling systems responsible (DAS and CTS).

T2M2 output

1. The duration and timestamps for the analysis. The first line of text states the number of hours which have been analysed, and the dates and times of the start and end of that period, for example
Analysis from 2017-06-01 10:36:51 +0000 to 2017-06-01 12:36:51 +0000 for 2 hours:

2. The backup destinations. The next lines of text should state the backup destination being used, in my example reading
Backing up to /dev/disk3s2: /Volumes/PROMISE PEGASUS/Backups.backupdb

If you have multiple backup destinations in use, then each should be identified individually in a separate line.

If that line doesn’t appear in the log, this is probably a serious issue, and you should see the line
No backup folder was selected.
instead. The first thing to do is ensure that the Time Machine pane is properly configured, and is trying to back up to a volume which is mounted on your Mac. If you are backing up to a NAS, then the message here should give details about that NAS, although I’m not sure what format that takes.

3. Free disk space on the backup volume(s). This should be a list of the amounts of disk space free on that backup volume at the start of each backup, giving that for the oldest backup first,
on which there were 2.9 TB, 2.9 TB, 2.9 TB, 2.9 TB, 2.9 TB, 2.9 TB, 2.9 TB available.

If you have multiple backup volumes active, then these will reflect the free space on each, as they are rotated for each backup. So you might see something more like
on which there were 2.9 TB, 1.8 TB, 2.9 TB, 1.8 TB, 2.9 TB, 1.8 TB, 2.9 TB available.
when rotating between two volumes with 2.9 and 1.8 TB free, for example.

At the moment, T2M2 does not warn or advise if free space is getting low. You will need to look at the results and decide for yourself.

4. Backups started and completed successfully. T2M2 counts the number of log entries reporting that an automatic backup is starting, those for any manual backups, and the number reporting the backup has been completed successfully. These numbers are given here as
Started 6 auto backups, and 1 manual backups, completed 7 backups successfully,

Provided that there is no backup being made at the moment, these numbers should be equal, or occasionally you may see more completed than started. Any unexplained inequality – particularly when the number completed successfully is less than the number started – should alert you to a potential problem. This could mean that some of those backups failed.

If no automatic backups are logged during the period, you will see instead the message
No auto backups started in the period, completed 1 backups successfully,
for example. Try increasing the period to capture more backups if that is the case. If none are started or completed, this makes it likely that backups have become very irregular: again, increase the period to over 3 hours to investigate further.

5. Time in minutes since the completion of the last successful backup. When run automatically, backups should occur roughly every hour. However, they are scheduled flexibly and this may rise to 70 minutes or so. It should never exceed 90 minutes, and if it does, T2M2 will give you a red light in warning. This should appear as
last backup completed successfully 60.0 minutes ago,
but if no backup has completed successfully in the period, you will instead see
no backup has been completed successfully in the period,

Note that this period is given for the last successfully completed backup, whether automatic or manual. If the period since completion of the last successful backup is more than 90 minutes, T2M2 should automatically run checks of the systems which schedule backups.

6. Backups still in progress. If a backup is still apparently in progress, you will see
currently still making an auto backup,
or
currently still making a manual backup,
as appropriate, which will give you an amber warning, as T2M2 cannot be sure whether this is going to end happily, or with problems. If you can, wait until the current backup completes, and run the check again.

Of course the current backup could have hung or got into other difficulties: you should then see error messages at the end of the report, and a red light.

7. Time since start of last manual backup. If any of the backups started during the period analysed was a manual backup, then you will see the time from the start of that backup:
last manual backup started 9.0 minutes ago,
If all backups were automatic, then this is not displayed.

8. Number of files backed up. T2M2 analyses the number of files which each backup is reported to have backed up. These vary widely, so the figures reported here give a total number across all the backups in the period, together with a range, minimum to maximum, for each backup, as
backed up a total of 444 files, range 191 to 253 in each backup,
or a simpler message if only one backup has completed in the period examined.

Very large or very small numbers should alert you to potential problems. The total gives you an idea of overall backup activity in the period.

9. Amount of data backed up. T2M2 presents a different analysis of the quantities of files reported as being backed up, listing each in order. Again very low or high figures should raise your suspicions. These are reported as
total data for each backup was 8.5 MB, 63.3 MB.
and are given in time order, the oldest backup first. A simpler version is used if only one backup has been completed.

10. Time in minutes taken for each auto backup. A similar sequence of times, in whole minutes (ignore the decimal), is given for completed automatic backups, which you can compare with the amounts of data backed up. There is only a loose correlation between larger backups taking longer times, but this can again alert your suspicions. Time taken is a fair indicator of the performance of the whole backup system, and can be used to assess, for example, the penalty of backing up over WiFi or to a slower external disk. This is reported as
Times taken for each auto backup were 4.0, 2.0 minutes,

11. Intervals between auto backups. T2M2 calculates the time periods between the start of each consecutive automatic backup during the period of analysis. If only one auto backup has been started, no figure is given. There will be one less interval than the number of auto backups started. These should be around 60 minutes, and are again reported in whole minutes (ignoring the decimal). If they range widely, with some less than 50 and others more than 70 minutes, suspect a scheduling problem, which is usually fixed by restarting your Mac. The result might read
intervals between the start of each auto backup were 57.0 minutes.

If the last of these intervals is longer than 90 minutes, T2M2 should automatically run checks of the systems which schedule backups. They should also be run if

• no backup has been started during the period of analysis, and
• no backup has been completed during the period of analysis, and
• no auto or manual backup is still in progress, and
• the period of the analysis is 2 hours or more.

12. Backups created and deleted. This gives a summary total for all the new backups created over the period, and old ones deleted. The former should of course match the number in 4 above. If it doesn’t, then you need to look for a reason. This is given simply as
Created 2 new backups, and deleted 2 old backups,

13. Deep traversal scans. Normally, Time Machine uses the FSEvents file to save it having to scan your entire disk to discover what has changed since its last backup. Sometimes it cannot do that, and performs a deep traversal scan on the backup source. This is explained here.

If T2M2 detects that one or more deep traversal scans have taken place, the following will be reported:
started 1 deep traversal scans,
completed 1 deep traversal scans,

These are not necessarily a bad sign – they do occur periodically anyway – but should alert you to potential problems. Repeatedly performing deep traversal scans is a bad sign, and should be followed up as explained.

14. Backup compactions. Time Machine may compact its files on the backup volume, which should recover free space and provide sufficient for it to continue to make backups. T2M2 will detect this, and in the following two entries tells you how many times it has started these compactions, and how many have completed:
started 1 compactions to recover free space,
completed 1 compactions,

If no compaction is started or completed, no mention is made of compactions in the output. Compaction tends to be triggered when free disk space on the backup volume is becoming low. Check the figures given for free space, and consider deleting old backups or backing up to a larger volume.

15. Cancelled backups. The most common reason for a scheduled backup being cancelled is when it tries to start too soon (less than ten minutes) after the last backup. However, there can be other reasons, and any cancelled backups are reported:
cancelled 1 backups.

If no backups are cancelled, no message is produced.

16. Error messages. Normally, no errors should result, and this is stated clearly as
No error messages found.

If any errors are found, they are listed individually after
2 errors reported:
and given as, for example,
2017-05-24 10:13:13.555672+0100 Error: (-8084) SrcErr:YES Copying /Users/hoakley/Library/Preferences/com.apple.dt.Xcode.plist to (null)

Errors are given simply as the timestamp of that log entry, followed by the error message. Those which are unimportant are not included here, but not all error messages will necessarily be of significance. If you’re in doubt, open Consolation, set it to retrieve Time Machine log entries, and enter the same time period as used for T2M2. You will then be able to see the full details for those errors.

Any error message automatically sets the traffic light to red.

17. Checks on the scheduling systems. When T2M2 suspects that the DAS and CTS systems which are responsible for scheduling automatic backups (and much more besides) may not be working correctly, it will automatically run additional checks covering those systems. These are introduced by the message
Running check on scheduling system (CTS and DAS).

If that message does not appear, those additional checks will not be run. It is still possible that automatic scheduling has stopped working properly: if you are suspicious of that, run T2M2 again in an hour or so.

The first of these additional checks runs another log analysis, at the end of which either of the following messages will appear:
DAS appears to have stopped rescoring activities over the last 90 minutes.
DAS appears to be rescoring normally over the last 90 minutes.

The next message indicates that checks on CTS are being run:
Running CTS check next.

Those results are given in either of the following messages:
CTS has not been told to run a backup in the last 90 minutes. Scheduling may have stopped.
CTS has been told to run a backup in the last 90 minutes but failed to do so.

You will then be advised to
Consider restarting your Mac.

If you wish to investigate this further, my free tool DispatchView (from Downloads above) provides much deeper insight into DAS and CTS. These scheduling systems are complex, and in this beta release their analysis is still limited.

I will maintain this document as T2M2 develops, and have add its contents to T2M2’s extensive Help book. Further articles on troubleshooting Time Machine are listed in the Mac probs item above.

(Last updated 9 June 2017 for T2M2 1.0, available later from Downloads)