Time Machine in Sonoma: detection and diagnosis with T2M2

Unlike other backup utilities, Time Machine (TM) doesn’t provide its own log to detail what has happened during its backups. Instead it writes entries to the main Unified log, where they’re inaccessible to most users. This article explains how to use my free utility The Time Machine Mechanic, T2M2, version 2 to check for and diagnose problems with TM automatic backups in Sonoma.

As entries made in the log are different in each major version of macOS, T2M2 version 2 may not prove ideal for earlier macOS, which may yield more informative results with the previous version, T2M2 1.19. T2M2 version 2 is also designed to work with TM backing up to a destination volume in APFS format; if your Mac is still using HFS+, then T2M2 1.19 is likely to be more helpful. I am trying to improve the performance of version 2 with older macOS, back as far as Big Sur, so this may improve with future updates.

Potential problems

TM backups are more complicated than those made by other apps, as each includes making a local snapshot on each volume being backed up, then creating a backup in the form of a snapshot on the backup destination storage. This creates the illusion that each backup contains the whole volume, but is even more space-efficient than it was previously when backing up to HFS+.

Basic questions T2M2 attempts to answer include:

Are backups occurring automatically and regularly?
Are the right volumes and folders being backed up?
Are multiple backup destinations rotating correctly?
Is there sufficient free space on backup storage?
Are local snapshots being maintained correctly?
Are backups being thinned correctly?
Are backups completing successfully?
Are there any errors occurring?
How long do backups take?

One important issue that neither TM nor T2M2 can address is whether each backup is faithful, or contains errors in the files being backed up. That requires some form of data integrity checking, as provided by my family of apps Dintch, Fintch and cintch.

T2M2 has an extensive Help book. To read its guidance on interpreting its results, from its Start page click on Contents, then Interpret Results.

T2M2 provides three simple indicators for problems: the traffic light at the top of its window gives an overall result. If that’s green, then the only other result you should check is whether there’s sufficient free space on backup storage. The other basic indicator is that for errors: if no errors are reported, that’s the third green you’re looking for.

If the traffic light is amber (orange) rather than green, that means you need to read the report carefully to discover whether there’s a problem. The most common reason for that now is with the timing and regularity of automatic backups.

Automatic and regular

Automatic backups are scheduled and dispatched by the macOS subsystem that manages its background tasks, DAS-CTS. Although this is elaborate, since High Sierra it has been generally reliable. Results in the second section of T2M2 should report something like:
Started 5 auto backup cycles, and 0 manual backups;
completed 5 volume backups successfully,
last backup completed successfully 6.7 minutes ago,
Times taken for each auto backup were 0.2, 0.2, 0.2, 0.2, 0.3 minutes,
intervals between the start of each auto backup were 60.3, 60.1, 60.2, 52.0 minutes.

Over the period you’re analysing, if your Mac has been running and awake, there should be hourly backups at intervals of roughly 60 minutes. Sometimes a backup is delayed or skipped, extending the interval to 120 minutes or so. That’s most likely when other activities have supervened. Failure of scheduling is now very unlikely, but can occur. If in doubt, check back in an hour’s time to confirm that another backup has been made.

If you use an alternative method for making TM backups, that’s more likely to use launchd with an exact timer, and those backups are unlikely to be reported as normal automatic backups. T2M2’s Back up now button runs an automatic rather than manual backup, as it works through the same dispatch system as timed backups.

Correct backup volumes

The volumes used as sources for TM backups are listed in the results section, as
Backup results:
Finished copying from volume “External1”
If those aren’t correct, check TM’s list of exclusions in its settings.

Rotation of backup destinations

If you’re using more than one destination for TM backups, it will rotate between those available, something you should see confirmed in the start of the report:
Backing up 1 volumes to ThunderBay2 (/dev/disk9s2,TMBackupOptions(rawValue: 257)): /Volumes/ThunderBay2
The rawValue given here is TM’s internal code for its options.

Free space on backup destinations

These are given early in the report as
Current free space on backup volumes:
✅ /Volumes/ThunderBay2 = 82.64 GB
and confirmed in any thinning reports further down as:
Thinning 1 backups using age-based thinning, expected free space: 82.64 GB actual free space: 82.64 GB trigger 50 GB thin 83.33 GB dates: (“2024-01-07-024113”)

The amount of free space that triggers T2M2’s warnings uses the same threshold as TM, warning you when it has fallen below 50 GB.

Snapshot maintenance

Local snapshots, those made and kept on volumes being backed up, should be retained for a period of 24 hours, then automatically deleted, although TM should always retain the latest of those snapshots, as that’s used when making the next backup.

A simple statement tells you how many new local snapshots have been made, and how many were deleted:
Created 5 new snapshots, and deleted 4 old snapshots,
Those will vary on Macs that spend significant periods asleep or shut down, when local snapshots won’t be made each hour.

Backup thinning

TM has two reasons for removing or thinning the backup snapshots it makes to backup storage: age and space. Its rule for age is that it keeps hourly backups for the previous 24 hours (in addition to the hourly local snapshots on volumes being backed up), then daily backups over the last month, and weekly back to the start of that backup series. Its rule for space is to allow a minimum of 50 GB free space on the backup destination, but when free space falls below that it should thin older backups to free up space. Thinning is reported for each backup in which it’s undertaken:
Thinning 1 backups using age-based thinning, expected free space: 82.64 GB actual free space: 82.64 GB trigger 50 GB thin 83.33 GB dates: (
“2024-01-07-034204”)

Some users have encountered situations where age-based thinning doesn’t happen, resulting in every hourly backup being retained. While you can thin backups manually, they need to be thinned automatically.

Backup completion

Backing up may fail to complete successfully as a result of errors occurring during that backup. Recently the most common reason for that happening is that iCloud is in the midst of syncing following upgrading to Sonoma. That failure is normally reported at the time, although others may not be. Failures should be apparent in a discrepancy between the number of backups started and those completed successfully:
Started 5 auto backup cycles, and 0 manual backups;
completed 5 volume backups successfully,
last backup completed successfully 6.7 minutes ago,

Of course, if T2M2 has compiled its report while a backup is taking place, that will lead to a difference. In that case, repeating the analysis a few minutes after that backup has completed should give the expected result.

Errors

Normally the final section of T2M2 report should read:
✅ No error messages found.

T2M2 version 2.01 has an option to list only the first ten errors found, or to show them all. Unless TM regularly returns many errors that aren’t significant, you should run checks with List all errors ticked.

When errors are returned, the difficulty is interpreting them, and deciding whether they’re significant or not. T2M2 normally over-reports errors, in case they are something you do need to know. While under-reporting might seem attractive, it could put your backups at risk.

Backup speed

T2M2 reports the results of TM’s internal speed tests in the first section, where you’ll see something like
Destination IO performance measured:
Wrote 1 50 MB file at 437.58 MB/s to “/Volumes/ThunderBay2” in 0.114 seconds
Concurrently wrote 500 4 KB files at 45.83 MB/s to “/Volumes/ThunderBay2” in 0.045 seconds

Slow transfer rates there, much below 5 MB/s, should alert you to a problem. TM’s transfer rates are controlled by a system setting so that its data transfer doesn’t compromise user activity. While you can turn that off, that affects all other background activities, and may bring its own problems.

To get better insight into what might be causing TM’s backups to complete very slowly, set the period to include the last backup completed, and click on the Speed button. This replaces the last analysis with a series of progress reports that are rich in detail.

If you don’t see any progress reports, then it’s most probable that backup didn’t take long enough for any to be written (although at present, speed reports aren’t available in T2M2 2 for Big Sur). Each entry has the form:
23-12-14 13:06:20.357 .••••••• .
Progress: 77% done, 203.37%/h, 247.24 MB/s, avg: 129.00 MB/s, 241.35 items/s, avg: 153.05 items/s
ByPhysicalSize:69% (CV:312.74 GB/450.53 GB (D: Zero KB),T:450.53 GB,D:Zero KB(-),LA:Zero KB(-))Y
ByItemCount:85% (CV:367936/431566 (D: 0),T:431566,D:0(-),LA:0(-))Y
ByEventPath:- ()N
Copied: 368194 (l:309.53 GB p:310.19 GB) Propagated: 0 (l:Zero KB p:Zero KB) Propagated (shallow): 0 (l:Zero KB p:Zero KB)
Tracker: FlCp:330789DrCp:35810SmCp:258FlLn:55FlCl:1282
Lookups: DrtLkpSkp:144722,LnAltChk:88,ClnAltChk:80
Comparisons: Mtch:144722 Operations: KnwnUnchgd:72361,NoStlKnwnUnchgd:72361
Backup Projected Stats: 848130 items (p:912.79 GB)
Sized: l:459.89 GB p:462.26 GB c:416563, Outstanding:0/873, Finished Volumes:0
Current: 3.02 GB/(l:3.09 GB,p:10 GB) – /Volumes/ThunderBay2/2023-12-14-122555.inprogress/External1/Documents/0newDownloads/0tenGigTest.tiff

This starts with the time of that entry in the log 23-12-14 13:06:20.357, followed by a text progress indicator .••••••• .

The Progress line tells you how much of the backup has been completed at that point, percentage progress per hour, current transfer rate in MB/s, average transfer rate in MB/s, the number of items currently being copied per second, and its average. The last line, headed Current, gives the path to the item currently being copied on the backup storage. Here that’s
/Volumes/ThunderBay2/2023-12-14-122555.inprogress/External1/Documents/0newDownloads/0tenGigTest.tiff
which is the backup copy of the original file
External1/Documents/0newDownloads/0tenGigTest.tiff

This enables you to identify the source of files that are taking disproportionately long time to back up, for instance the contents of the Xcode app, which often accounts for much of backup time, unless you exclude Xcode from backups.

Those entries in T2M2’s reports should thus provide answers to each of your original questions.