Time Machine in Sonoma: How to check backing up

While you’re waiting for me to write the next version of The Time Machine Mechanic, T2M2, for Sonoma, you can still check whether your Time Machine backups are being made correctly. This article explains how to do that.

The best tool for doing this is my free utility Mints, which has a convenient button to capture and display log entries for Time Machine.

tmlog0

The APFS button in T2M2 does display some of the same log content, but Mints gives better coverage.

tmlog1

To check the last Time Machine backup, open its menu and read the time reported there as the latest backup, subtract one minute from that, and enter that in the Mints Time Machine log window. Then set the Period there to at least 10 minutes, so it covers the whole period of the backup, and click the Get log button.

After a brief pause the lower text view should fill with log entries in red, green, blue and black/white. These are colour-coded according to the systems responsible for those entries.

tmlog2

At the start, you should see entries mostly in red, blue and green, where the backup is being dispatched by the DAS-CTS system. Once that’s under way, you’ll start seeing more entries from Time Machine, shown in black/white. Once you’re happy that dispatch occurred properly, click on the buttons for DAS, CTS and other to hide those entries, letting you concentrate on Time Machine. You can also save the log extract for browsing outside Mints.

tmlog3

Arm yourself with my diagram showing the stages expected in a backup:

tmbackup14a

Or its PDF tear-out version: tmbackup14b

Here are some waypoints to guide you.

Starting backup with mode "automatic backup"
You might also see this given as a manual backup, or a manual health check.

Backing up 1 volumes to [name] (/dev/disk7s2,TMBackupOptions(rawValue: 257)): /Volumes/[name]
Once the mountpoint of the backup storage has been checked, this entry should make it clear exactly what TM is going to do.

Checking destination IO performance at "/Volumes/[name]"
Note the results of these brief performance tests. Currently, even if one fails, Time Machine doesn’t appear to do anything with the results other than write them to the log.

Age based thinning of Time Machine local snapshots
You’ll see various errors and oddities here, as TM looks in various places to try to locate old local snapshots and delete those older than 24 hours. Those that are deleted should be accompanied by an entry from APFS, shown in green, to confirm the deletion.

Created Time Machine local snapshot with name 'com.apple.TimeMachine.2023-10-30-123653.local' on disk '/System/Volumes/Data'
Declared stable snapshot: com.apple.TimeMachine.2023-10-30-123653.local
Mounted stable snapshot
Mounted reference snapshot

These mark the creation of the latest local snapshot, and mounting that and the previous local snapshot, ready for the backup.

Collecting events on 1 volumes...
Using FSEvents for source: "Data"

Other than when making the first full backup, TM should be able to use FSEvents to determine which files need to be backed up. If it can’t, entries should explain which method it will use instead.

Illegal event path
Could not scan node at

and other errors may be reported here as TM checks through FSEvents. In most cases, they can be ignored, and there isn’t much you can do about them anyway.

EventDatabase: node count: 1448 events processed: 4181 max depth: 47 strategy: FSEvents
This is where TM declares the method it’s using to determine what to back up, normally FSEvents unless it’s a first full backup.

Estimated a total of 1518102 files (273.73 GB) will be in backup of 'Data'
This isn’t how much will copied in this backup, but the resulting size of the whole backup, including all existing files.

Skipping (destination path too long)
You may now see further messages about problem items in the backup, which may correspond to previous error reports.

.••• .
Progress: 33% done, -, - MB/s, avg: 0.00 MB/s, - items/s, avg: 0.00 items/s

During copying, TM will now make periodic reports giving the rate of copying as it progresses. These can highlight items like Xcode that make backups very slow, with very low transfer rates. You can then add them to TM’s exclude list for future backups.

Finished copying from volume "Data"
At the end of copying, this summary should report details of exactly how much was copied to build the new backup.

.•+**___-•••.
This marks the completion of the copying phase.

Marked as reference snapshot
The latest local snapshot is now labelled as the reference for the next backup.

Finished finalizing completed backup
The backup itself is now complete, following which the backup and snapshots are unmounted.

Found incomplete backups ready for deletion
Deleted incomplete backup

These aren’t really ‘incomplete’, but the remains of the previous backup, which is now removed.

Thinning 3 backups using age-based thinning
Old backups are now thinned, removing those no longer required. This includes a statement of how much free space is available on backup storage. It also reports the size of free space used as the trigger to perform space-based thinning. If you show the green log entries, you can see APFS removing each backup snapshot in turn. Old backups are then unmounted.

Analytics send failed.
This appears to be a normal error.

Backup succeeded
All done and ready for the next backup to be made.