9

My Time Machine is in the cleanup state for a long time (several days). The backup is to an external drive and the disk on the mac laptop is less than 500 GB. It usaually takes much less time to clean up.

Is there a way to inspect what the Time Machine actually is doing during the cleanup?

The following log is not helpful.

$ log show --debug --predicate 'subsystem == "com.apple.TimeMachine"' --info --last 4h
Filtering the log data using "subsystem == "com.apple.TimeMachine""
Timestamp                       Thread     Type        Activity             PID    TTL  
2020-02-21 13:36:41.329729-0600 0xb4acfa   Info        0x0                  98     0    backupd-helper: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Not starting scheduled Time Machine backup: Backup already running
2020-02-21 14:36:55.424274-0600 0xb60241   Info        0x0                  98     0    backupd-helper: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Not starting scheduled Time Machine backup: Backup already running
2020-02-21 15:42:20.848345-0600 0xb64cb9   Info        0x0                  98     0    backupd-helper: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Not starting scheduled Time Machine backup: Backup already running
2020-02-21 16:36:27.614466-0600 0xb8060d   Info        0x0                  98     0    backupd-helper: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Not starting scheduled Time Machine backup: Backup already running
--------------------------------------------------------------------------------------------------------------------
Log      - Default:          0, Info:                4, Debug:             0, Error:          0, Fault:          0
Activity - Create:           0, Transition:          0, Actions:           0
Improve this question
9
  • You probably updated to latest MacOS, then there is a lot of work to do.
    – Thorbjørn Ravn Andersen
    Feb 21, 2020 at 23:58
  • I have not updated my MacOS. The only thing is that there might be 100GB data changed since the last backup to the current one. But it doens't make sense to clean up for many days, it takes even more time than the backup stage.
    – user1424739
    Feb 22, 2020 at 5:51
  • I would suspect the Time Machine drive is damaged. I used to see this kind of thing a lot on [High] Sierra, a lot less since Mojave. The only thing I've found that can fix it is DiskWarrior You could also try thinning/deleting local snapshots, but I never found that to really fix anything - see apple.stackexchange.com/a/362658/85275
    – Tetsujin
    Feb 22, 2020 at 8:30
  • Buy another disk and do a fresh backup to that. The cleaning process to remove old images may apparently be quite slow in the latest. My time capsule took forever to catch up
    – Thorbjørn Ravn Andersen
    Feb 22, 2020 at 10:18
  • Buying another disk could be a solution. But I will lose the history of the backups. Is there a way to see debug what is wrong with the excessively long cleanup stage?
    – user1424739
    Feb 23, 2020 at 2:04

3 Answers 3

Reset to default
4

I noticed that cleaning up old backups can be very slow. In my case, I can hear my external backup drive rattling along, so I know it's doing something.

You can check on progress by opening the latest backup log. Look for the directory with a name ending in .inProgress on your backup drive. Within it, open the log file with the most recent timestamp:

$ sudo less +F "/Volumes/MacBackup/Backups.backupdb/MacBook Pro/2020-08-05-163227.inProgress/.Backup.618330747.626060.log"

Substitute MacBackup, MacBook Pro and the backup/log path. If you're not familiar with less, press Ctrl-C, followed by q to exit.

The log file will tell you how much space needs to be cleared and which of the backups it's (very slowly) deleting. Looking at the amount of free space on your backup disk should give you an idea of how far along it is.

Improve this answer
9
  • Apparently "Cleaning up" is possible even without a .inProgress backup and plenty of free space. My current backup has been "Cleaning up" for almost 36 hours and there is no .inProgress dir. The latest backup's Backup.log ends with "Backup complete. Total time elapsed: 14 minutes...". And my backup drive has 5TB free. I'm not sure what to make of the extended cleaning, but I see it frequently.
    – Jason Campbell
    Jul 19, 2021 at 19:15
  • @JasonCampbell Can't check now, but perhaps the .inProgess directory is hidden in Finder? Did you try looking for it in a terminal (using ls -a)?
    – Brecht Machiels
    Jul 20, 2021 at 7:59
  • I understood from the pathname in your answer that .inProgress is a suffix on the date-stamped backup directory's name. i.e., it's the trailing part of the name, where the dot would not cause it to be hidden. Is it a standalone .inProgress subdir enclosed in the date-stamped dir instead? Thanks!
    – Jason Campbell
    Jul 21, 2021 at 9:54
  • @JasonCampbell No, it is a suffix indeed, but I can imagine that Finder still hides this "special" directory (so ls should suffice). Again, I have not verified this guess...
    – Brecht Machiels
    Jul 21, 2021 at 11:58
  • 1
    Man, this is Macintosh. just open the log file (the Console App should do it) by either navigating and double-clicking the .log file, or in Terminal "open <path to log file>" instead of sudo less. looks better, can be searched better, and feels "native" for Mac users.
    – Motti Shneor
    Aug 28, 2021 at 22:55
4

Good to see you @Jason Campbell! Mine is backing up to a Synology (aptly named "Hades") and there is no "*.inProgress" anywhere in the SMB-mounted Synology folder. But there is one in my local TM snapshot folder. That, however is empty and hasn't been touched in an hour:

tkunze@zork ~ % ls -la /Volumes/Time\ Machine\ Backups/Backups.backupdb/.RecoverySets/
total 0
drwxr-xr-x  4 root  wheel  136 Aug  1 19:29 ./
drwxr-xr-x@ 6 root  wheel  204 Dec 24  2019 ../
drwxr-xr-x  3 root  wheel  102 Oct 15  2020 0/
drwxr-xr-x  2 root  wheel   68 Aug  1 19:29 1.F9D6D42C-90FB-4BFD-A7E6-44E2D39CAB88.inProgress/
tkunze@zork ~ % ls -la /Volumes/Time\ Machine\ Backups/Backups.backupdb/.RecoverySets/1.F9D6D42C-90FB-4BFD-A7E6-44E2D39CAB88.inProgress
total 0
drwxr-xr-x  2 root  wheel   68 Aug  1 19:29 ./
drwxr-xr-x  4 root  wheel  136 Aug  1 19:29 ../

Meanwhile, the TM preference panel still says "Cleaning up…". It seems backupd is still reading and writing to disk, so I upped its IO priority by running

tkunze@zork ~ % sudo sysctl debug.lowpri_throttle_enabled=0
debug.lowpri_throttle_enabled: 1 -> 0

and that made a difference. And now, as I just typed that sentence, the cleanup is done. Don't forget to revert the sudo…

Improve this answer
0

I would recommend that you do not limit your log show by this predicate, which leaves just one subsystem, but rather - use predicate specifying the Process name (or path) instead. (Don't know which process does the backup - but simple inspection in Activity Monitor will tell you.

Why? because then you see log messages not just by the backup daemon itself, but also from all the Cocoa frameworks and other sub-systems it makes use of.

This is immensely more helpful, and you can quite easily see where things go wrong / slow and if there were retries.

Improve this answer

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .