Resolved Time Machine Bizarre Behavior

[Buadhai]

This on a 2017 iMac running 10.15.7.

The TM volume is on a 4TB WD Elements drive.

Time Machine has been working fine for me for quite a while. This morning I suddenly got the following message:

But, a few minutes later I initiated a backup and got the following:

So, why would it go from needing 132GB of free space to only backing up 3.42GB. Isn't Time Machine supposed to delete old backups "when your disk becomes full"?

When I ask tmutil to list backups, it only lists one:

MrMuscle:~ mnewman$ tmutil listbackups
/Volumes/TM/Backups.backupdb/MrMuscle/2021-06-04-091108

But when I look at the backup directory, there are 430 backups going back to January of this year:

MrMuscle:~ mnewman$ ls -l /Volumes/TM/Backups.backupdb/MrMuscle/ | wc -l
     430

Why are these old backups not pruned to make room for current backups?

MrMuscle:~ mnewman$ ls -l /Volumes/TM/Backups.backupdb/MrMuscle/
total 8
drwxr-xr-x@  4 root  staff  136 May 29 22:22 2021-01-24-081546
drwxr-xr-x@  4 root  staff  136 Jan 26 00:03 2021-01-25-000254
drwxr-xr-x@  4 root  staff  136 Jan 26 06:03 2021-01-25-050853
drwxr-xr-x@  4 root  staff  136 Feb 24 08:06 2021-01-25-071014
drwxr-xr-x@  4 root  staff  136 Jan 26 09:03 2021-01-25-080853
drwxr-xr-x@  4 root  staff  136 Jan 26 22:03 2021-01-25-211433
<snip>
drwxr-xr-x@  4 root  staff  136 Jun  4 09:45 2021-06-04-015027
drwxr-xr-x@  4 root  staff  136 Jun  4 09:47 2021-06-04-064503
drwxr-xr-x@ 13 root  staff  442 Jun  4 09:11 2021-06-04-091108
drwxr-xr-x@  7 root  staff  238 Jun  4 11:54 2021-06-04-115019.inProgress
lrwxr-xr-x   1 root  staff   17 Jun  4 09:11 Latest -> 2021-06-04-091108

Here's another bit of weirdness. The Time Machine Mechanic (from Eclectic Light Company) results are below. It shows two time machine volumes:

Backing up to TM (/dev/disk3s3): /Volumes/TM
Backing up to TM (/dev/disk4s3): /Volumes/TM

There actually is no disk3s3

Analysis from 2021-06-04 04:28:16 +0700 to 2021-06-04 12:28:16 +0700 for 8 hours:
Backing up to TM (/dev/disk3s3): /Volumes/TM
Backing up to TM (/dev/disk4s3): /Volumes/TM
Current free space on backup volumes:
✅    /Volumes/TM = 77.93 GB
✅    /Volumes/TM = 77.93 GB
Started 5 auto backup cycles, and 3 manual backups;
completed 8 volume backups successfully,
last backup completed successfully 197.1 minutes ago,
currently still making an auto backup,
currently still making a manual backup,
last manual backup started 11.1 minutes ago,
backed up a total of 12315 files, range 1 to 5650 in each backup,
total data for each backup was 3.25 GB, 69 bytes, Zero KB, 576.5 MB, 69 bytes, Zero KB, 2.76 GB, 69 bytes, Zero KB, 1.19 GB, 69 bytes, Zero KB.
Created 8 new backups, and deleted 0 old backups,
Created 14 new snapshots, and deleted 18 old snapshots,
cancelled 1 backups.
Of 20 volume backups:
    0 were full first backups,
    6 were deep scans,
    14 used FSEvents,
    0 used snapshot diffs,
    0 used consistency scans,
    0 used cached events.
✅ No error messages found.
⚠️ Running check on scheduling system (CTS and DAS).
DAS appears to be rescoring normally 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.

Any ideas as to how to fix this?

 

[Buadhai]

Turns out this was probably caused by a corrupt Time Machine preferences file (/Library/Preferences/com.apple.TimeMachine.plist). It was over 2000 lines long and had hundreds of "include" references to files that had been deleted over a decade ago (mostly TV show episodes). I deleted the preferences file and erased the destination volume and all seems back to normal now.