Time Machine in Sonoma: Rotating backups and NAS

Time Machine’s automatic hourly backups may appear simple and inflexible. To demonstrate a more complex situation, this article shows a combination of rotating backup storage, one of which is a NAS taking its first full backup, using T2M2 version 2.01 for analysis.

Scenario

The T2M2 reports I analyse here were obtained from a Mac Studio M1 Max running Sonoma 14.2.1, with Time Machine backing up hourly. It had previously been backing up to a local Thunderbolt 3 SSD, and was then connected to a brand new Asustor 5402T containing two 2 TB SSDs in RAID 0, with both SMB and AFP enabled and full Mac options, connected over Ethernet 2.5G. In the period shown, Time Machine first made a scheduled hourly backup to the local SSD, then its first full backup to the NAS.

t2m2nas

Backup storage

First the two backups attempted are listed with their destinations:
Backing up 1 volumes to Backups of MacStudio (/dev/disk5s1,TMBackupOptions(rawValue: 16)): /Volumes/Backups of MacStudio
Backing up 1 volumes to OWCenvoyProSX2tb (/dev/disk7s2,TMBackupOptions(rawValue: 257)): /Volumes/OWCenvoyProSX2tb

Then the free space on each volume is given.
Current free space on backup volumes:
✅ /Volumes/Backups of MacStudio = 3.79 TB
✅ /Volumes/OWCenvoyProSX2tb = 1.72 TB

Performance tests

These results are surprising:
Destination IO performance measured:
Wrote 1 50 MB file at 277.95 MB/s to "/Volumes/OWCenvoyProSX2tb" in 0.180 seconds
Concurrently wrote 500 4 KB files at 28.76 MB/s to "/Volumes/OWCenvoyProSX2tb" in 0.071 seconds
Wrote 1 50 MB file at 222.23 MB/s to "/Volumes/Backups of MacStudio" in 0.225 seconds
Concurrently wrote 500 4 KB files at 22.42 MB/s to "/Volumes/Backups of MacStudio" in 0.091 seconds

The first pair are for the local SSD over Thunderbolt 3, followed by those over the network to the NAS, which isn’t that far behind them, despite its 2.5G network connection and SMB.

Backups started and complete

Started 1 auto backup cycles, and 1 manual backups;
completed 2 volume backups successfully,
last backup completed successfully 0.3 minutes ago,
last manual backup started 34.0 minutes ago,
Times taken for each auto backup were 1.2 minutes,

The first full backup to the NAS was scheduled as a manual backup. Because of that, T2M2 doesn’t give the interval between these two backups. Had they both been auto backups, then the interval between them would have been calculated and given.

Backup thinning, snapshot maintenance

There was only one session of thinning backups, on local storage:
Thinned:
Thinning 2 backups using age-based thinning, expected free space: 1.72 TB actual free space: 1.72 TB trigger 50 GB thin 83.33 GB dates: (
"2024-01-14-125010",
"2024-01-14-144540")
Created 2 new snapshots, and deleted 2 old snapshots,

The free space given here matches that at the start of the report.

Determination of backups

The backup to local storage used a deep scan, as it was the first made since starting up. That to the new NAS was of course a first full backup.
Of 2 volume backups:
1 were full first backups,
1 were deep scans,
0 used FSEvents,
0 used snapshot diffs,
0 used consistency scans,
0 used cached events.

Backup results

The first, to the existing backup storage, is less than 1 GB.
Backup results:
Finished copying from volume "Data"
4544 Total Items Added (l: 541.6 MB p: 579.6 MB)
5391 Total Items Propagated (shallow) (l: Zero KB p: Zero KB)
645635 Total Items Propagated (recursive) (l: 160.13 GB p: 155.85 GB)
650179 Total Items in Backup (l: 160.67 GB p: 156.42 GB)
2494 Files Copied (l: 178.6 MB p: 195.6 MB)
1277 Directories Copied (l: Zero KB p: Zero KB)
638 Symlinks Copied (l: 15 KB p: Zero KB)
3216 Files Move Skipped (l: Zero KB p: Zero KB) | 3216 items propagated (l: 1.72 GB p: 1.72 GB)
2175 Directories Move Skipped (l: Zero KB p: Zero KB) | 637028 items propagated (l: 158.41 GB p: 154.12 GB)
85 Files Cloned (l: 1.7 MB p: 1.8 MB)
50 Files Delta Copied (l: 361.4 MB p: 382.1 MB)

That to the NAS was of course a complete backup, with limited exclusions for Xcode and folders containing virtual machines. It required the copying of nearly half a million files, occupying 136 GB.
Finished copying from volume "Data"
644678 Total Items Added (l: 160.66 GB p: 156.37 GB)
0 Total Items Propagated (shallow) (l: Zero KB p: Zero KB)
0 Total Items Propagated (recursive) (l: Zero KB p: Zero KB)
644678 Total Items in Backup (l: 160.66 GB p: 156.37 GB)
491340 Files Copied (l: 136.63 GB p: 132.33 GB)
117511 Directories Copied (l: Zero KB p: Zero KB)
32193 Symlinks Copied (l: 941 KB p: Zero KB)
85 Files Linked (l: 55.1 MB p: 55.3 MB)
3549 Files Cloned (l: 23.98 GB p: 23.99 GB)

That was completed in about 33 minutes (see below), giving an overall file copying rate of just under 15,000 files per minute, and just over 4 GB per minute.

Errors

✅ No error messages found.
I need say no more.

Speed report

This is a lightly edited summary of the first two lines of each of the seven entries in the speed report for the NAS backup.

15:42:55.804984+0000 . . Progress: 0% done, -, - MB/s, avg: 0.00 MB/s, - items/s, avg: 0.00 items/s
15:47:56.302620+0000 . . Progress: 6% done, 63.86%/h, 88.65 MB/s, avg: 88.65 MB/s, 300.34 items/s, avg: 300.34 items/s
15:52:56.339702+0000 .• . Progress: 11% done, 60.25%/h, 174.25 MB/s, avg: 131.45 MB/s, 186.14 items/s, avg: 243.24 items/s
15:57:56.353607+0000 .• . Progress: 15% done, 47.04%/h, 60.98 MB/s, avg: 107.96 MB/s, 276.74 items/s, avg: 254.40 items/s
16:02:56.370295+0000 .• . Progress: 19% done, 52.78%/h, 98.99 MB/s, avg: 105.72 MB/s, 174.23 items/s, avg: 234.36 items/s
16:07:56.387047+0000 .•• . Progress: 26% done, 87.55%/h, 34.98 MB/s, avg: 91.57 MB/s, 479.95 items/s, avg: 283.48 items/s
16:12:56.403433+0000 .••• . Progress: 33% done, 79.48%/h, 31.57 MB/s, avg: 81.57 MB/s, 502.19 items/s, avg: 319.93 items/s

These are written to the log every five minutes while copying to the backup is taking place. The first is normally made soon after the start, and commonly shows 0% progress. If the backup completes within ten minutes, that’s the only progress report made. As this first full backup took over 30 minutes, reports continued, until it completed at 16:15:33.018. The actual time taken for copying was 32.92 minutes.

T2M2 is available from here, and contains a Help book explaining how to interpret its results.