Mac – Time Machine backup silently fails. Log says “Backup canceled.”

backuptime-capsuletime-machine

Since a few days, most attempts of Time Machine on backing up my Mac are silently cancelled. Here's the situation:

  • Automatic Time Machine backups are turned on.
  • The preparation of backups is started on schedule as it can be seen by clicking on the Time Machine menubar item.
  • The backup procedure cancels without any further notice.

The last successful backup is now 48 hours old, though my Mac has been at home the whole day and it had plenty of chance to back up.

I'm on 10.14.2. I use a Time Capsule MB277 from 2008 or 2009 over WiFi. This is the Time Machine related syslog output of one failed attempt to manually backup my machine:

MacBook-Air-3:~ xxx$ log stream --style syslog  --predicate 'senderImagePath contains[cd] "TimeMachine"' --info
Filtering the log data using "senderImagePath CONTAINS[cd] "TimeMachine""
Timestamp                       (process)[PID]    
2019-01-29 17:42:58.119096+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Starting manual backup
2019-01-29 17:42:58.123368+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Destination Backups could not be found (url: (null) destinationID: 14938BA8-FAA4-47F2-9E2D-2C50C921FA93)
2019-01-29 17:42:58.129234+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Backup failed with error 18: The backup disk could not be found.
2019-01-29 17:42:58.155071+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Starting manual backup
2019-01-29 17:42:58.374462+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Attempting to mount 'afp://xxx;AUTH=SRP@Time%20Capsule._afpovertcp._tcp.local./Time%20Capsule'
2019-01-29 17:42:59.364160+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Mounted 'afp://xxx;AUTH=SRP@Time%20Capsule._afpovertcp._tcp.local./Time%20Capsule' at '/Volumes/com.apple.TimeMachine.Time Capsule-5E757F80-34D5-43A7-B4CB-7D2D9078DF8A'
2019-01-29 17:43:00.197845+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Checking size of '/Volumes/com.apple.TimeMachine.Time Capsule-5E757F80-34D5-43A7-B4CB-7D2D9078DF8A/MacBook Air (4).sparsebundle'
2019-01-29 17:43:13.729070+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Checking for runtime corruption on '/Volumes/com.apple.TimeMachine.Time Capsule-5E757F80-34D5-43A7-B4CB-7D2D9078DF8A/MacBook Air (4).sparsebundle'
2019-01-29 17:43:16.458494+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Runtime corruption check passed for '/Volumes/com.apple.TimeMachine.Time Capsule-5E757F80-34D5-43A7-B4CB-7D2D9078DF8A/MacBook Air (4).sparsebundle'
2019-01-29 17:43:16.609785+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Ejected disk2 from '/Volumes/com.apple.TimeMachine.Time Capsule-5E757F80-34D5-43A7-B4CB-7D2D9078DF8A/MacBook Air (4).sparsebundle'
2019-01-29 17:43:21.242322+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] '/Volumes/com.apple.TimeMachine.Time Capsule-5E757F80-34D5-43A7-B4CB-7D2D9078DF8A/MacBook Air (4).sparsebundle' mounted at '/Volumes/Time Machine-Backups'
2019-01-29 17:43:22.620336+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Backing up to /dev/disk2s2: /Volumes/Time Machine-Backups/Backups.backupdb
2019-01-29 17:43:30.734411+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove attribute 'com.apple.backupd.SnapshotVolumeFSEventStoreUUID' from 'file:///', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:30.734708+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove attribute 'com.apple.backupd.SnapshotVolumeLastFSEventID' from 'file:///', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:30.735162+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove attribute 'com.apple.backupd.SnapshotVolumeUUID' from 'file:///', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:30.735327+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove attribute 'com.apple.backupd.PreviousSnapshotVolumeUUID' from 'file:///', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:30.739730+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove attribute 'com.apple.backupd.PreviousSnapshotVolumeName' from 'file:///', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:30.739943+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove attribute 'com.apple.backupd.VolumeBytesUsed' from 'file:///', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:30.740102+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove attribute 'com.apple.backupd.VolumeIsCaseSensitive' from 'file:///', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:30.740257+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove attribute 'com.apple.backupd.fstypename' from 'file:///', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:30.740409+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove attribute 'com.apple.backupd.VolumeIsEncrypted' from 'file:///', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:31.351366+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Starting age based thinning of Time Machine local snapshots on disk '/'
2019-01-29 17:43:31.474925+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Skipping age based thinning of Time Machine reference snapshot 'com.apple.TimeMachine.2019-01-28-001417' on disk '/'
2019-01-29 17:43:42.350366+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Space based purging deleted Time Machine local snapshot 'com.apple.TimeMachine.2019-01-29-174115' on disk '/ in 56.4 seconds' - current free space: 6,58 GB (6.579.822.592 Byte), target free space: 14,87 GB (14.865.887.232 Byte), initial free space: 6,57 GB (6.566.518.784 Byte)
2019-01-29 17:43:42.358801+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Completed space based purging of snapshots on disk '/' in 56.5 seconds - current free space: 6,58 GB (6.579.822.592 Byte), target free space: 14,87 GB (14.865.887.232 Byte), initial free space: 6,57 GB (6.566.518.784 Byte), urgency: 3, remaining snapshots: (
    "com.apple.TimeMachine.2019-01-28-001417"
)
2019-01-29 17:43:42.365949+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to write unlock record UUIDs as extended attribute for disk '/', error: Error Domain=NSPOSIXErrorDomain Code=1 "Operation not permitted"
2019-01-29 17:43:43.243737+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Created Time Machine local snapshot with name 'com.apple.TimeMachine.2019-01-29-174342' on disk '/'
2019-01-29 17:43:43.250191+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Declared stable snapshot: com.apple.TimeMachine.2019-01-29-174342
2019-01-29 17:43:44.253895+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Mounted stable snapshot: com.apple.TimeMachine.2019-01-29-174342 at path: /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/MacBook Air (4)/2019-01-29-174342/Macintosh HD source: Macintosh HD
2019-01-29 17:43:44.265663+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Mounted reference snapshot: com.apple.TimeMachine.2019-01-28-001417 at path: /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/MacBook Air (4)/2019-01-28-001417/Macintosh HD source: Macintosh HD
2019-01-29 17:47:15.597633+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Will copy (2,32 GB) from Macintosh HD
2019-01-29 17:47:15.605699+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Found 23055 files (2,32 GB) needing backup
2019-01-29 17:47:16.048845+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] 7,72 GB required (including padding), 485,82 GB available
2019-01-29 17:47:47.476452+0100  localhost backupd-helper[69]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Not starting scheduled Time Machine backup: Backup already running
2019-01-29 17:50:50.519614+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Starting space based purging of local snapshots on disk '/' - current free space: 6,47 GB (6.474.358.784 Byte), target free space: 14,82 GB (14.817.628.979 Byte), initial free space: 6,47 GB (6.474.358.784 Byte), urgency: 1
2019-01-29 17:50:50.520324+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Starting age based thinning of Time Machine local snapshots on disk '/'
2019-01-29 17:50:50.521321+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Skipping age based thinning of Time Machine reference snapshot 'com.apple.TimeMachine.2019-01-28-001417' on disk '/'
2019-01-29 17:50:50.521873+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Space based purging skipped Time Machine dataless reference snapshot 'com.apple.TimeMachine.2019-01-28-001417' on disk '/'
2019-01-29 17:50:50.522128+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Space based purging skipped Time Machine stable snapshot 'com.apple.TimeMachine.2019-01-29-174342' on disk '/'
2019-01-29 17:50:50.528323+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Completed space based purging of snapshots on disk '/' in 0.0 seconds - current free space: 6,47 GB (6.474.358.784 Byte), target free space: 14,82 GB (14.817.628.979 Byte), initial free space: 6,47 GB (6.474.358.784 Byte), urgency: 1, remaining snapshots: (
    "com.apple.TimeMachine.2019-01-28-001417",
    "com.apple.TimeMachine.2019-01-29-174342"
)
2019-01-29 17:50:52.495903+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Starting space based purging of local snapshots on disk '/' - current free space: 6,47 GB (6.473.363.456 Byte), target free space: 14,82 GB (14.816.633.651 Byte), initial free space: 6,47 GB (6.473.363.456 Byte), urgency: 2
2019-01-29 17:50:52.496671+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Starting age based thinning of Time Machine local snapshots on disk '/'
2019-01-29 17:50:52.497723+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Skipping age based thinning of Time Machine reference snapshot 'com.apple.TimeMachine.2019-01-28-001417' on disk '/'
2019-01-29 17:50:52.498287+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Space based purging skipped Time Machine dataless reference snapshot 'com.apple.TimeMachine.2019-01-28-001417' on disk '/'
2019-01-29 17:50:52.498577+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Space based purging skipped Time Machine stable snapshot 'com.apple.TimeMachine.2019-01-29-174342' on disk '/'
2019-01-29 17:50:52.504812+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Completed space based purging of snapshots on disk '/' in 0.0 seconds - current free space: 6,47 GB (6.473.363.456 Byte), target free space: 14,82 GB (14.816.633.651 Byte), initial free space: 6,47 GB (6.473.363.456 Byte), urgency: 2, remaining snapshots: (
    "com.apple.TimeMachine.2019-01-28-001417",
    "com.apple.TimeMachine.2019-01-29-174342"
)
2019-01-29 17:51:17.367399+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Starting space based purging of local snapshots on disk '/' - current free space: 6,46 GB (6.462.078.976 Byte), target free space: 15,02 GB (15.021.101.056 Byte), initial free space: 6,46 GB (6.462.078.976 Byte), urgency: 3
2019-01-29 17:51:17.368247+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Starting age based thinning of Time Machine local snapshots on disk '/'
2019-01-29 17:51:17.369425+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Skipping age based thinning of Time Machine reference snapshot 'com.apple.TimeMachine.2019-01-28-001417' on disk '/'
2019-01-29 17:51:17.370016+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Space based purging skipped Time Machine dataless reference snapshot 'com.apple.TimeMachine.2019-01-28-001417' on disk '/'
2019-01-29 17:51:17.571228+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Received unmount notification of stable snapshot
2019-01-29 17:51:17.592214+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Copied 2764 items (48 KB) from volume Macintosh HD. Linked 21952.
2019-01-29 17:51:17.831507+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Unmounted local snapshot: com.apple.TimeMachine.2019-01-29-174342 at path: /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/MacBook Air (4)/2019-01-29-174342/Macintosh HD source: Macintosh HD
2019-01-29 17:51:17.987517+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Unmounted local snapshot: com.apple.TimeMachine.2019-01-28-001417 at path: /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/MacBook Air (4)/2019-01-28-001417/Macintosh HD source: Macintosh HD
2019-01-29 17:51:18.194718+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Backup canceled.
2019-01-29 17:51:29.247123+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Unmounted '/Volumes/Time Machine-Backups' (disk2s2)
2019-01-29 17:51:30.857160+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Ejected disk2 from '/Volumes/com.apple.TimeMachine.Time Capsule-5E757F80-34D5-43A7-B4CB-7D2D9078DF8A/MacBook Air (4).sparsebundle'
2019-01-29 17:51:31.580731+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogInfo] Unmounted '/Volumes/com.apple.TimeMachine.Time Capsule-5E757F80-34D5-43A7-B4CB-7D2D9078DF8A'
2019-01-29 17:51:31.581571+0100  localhost backupd[38644]: (TimeMachine) [com.apple.TimeMachine:TMLogError] Failed to remove directory '(null)', error: 14 Bad address

Best Answer

Try clearing some space on the origin drive you are attempting to backup.

I have seen Time Machine logs similar to this when Time Machine is having trouble organizing things within the space available on the origin drive. Often several GB are needed (I don't know why). So if you can get your drive to have more than 40GB of free space then do that.

By the way, using log stream --predicate 'subsystem == "com.apple.TimeMachine"' --info --debug labels lines that are considered errors a little more clearly.

Related Question