Skip to the Main Content

Note:These pages make extensive use of the latest XHTML and CSS Standards. They ought to look great in any standards-compliant modern browser. Unfortunately, they will probably look horrible in older browsers, like Netscape 4.x and IE 4.x. Moreover, many posts use MathML, which is, currently only supported in Mozilla. My best suggestion (and you will thank me when surfing an ever-increasing number of sites on the web which have been crafted to use the new standards) is to upgrade to the latest version of your browser. If that's not possible, consider moving to the Standards-compliant and open-source Mozilla browser.

April 11, 2022

Monterey and Samba

I reluctantly upgraded my laptop from Mojave to Monterey (macOS 12.3.1). Things have not gone smoothly. My biggest annoyance, currently, is with Time Machine.

I have things set up, so that, at home, my laptop wirelessly backs up, alternately, to one of two Samba Servers. The way this works, is that Time Machine creates a .sparsebundle on the Share. Inside the .sparsebundle is a file system on which the actual backups reside. This is entirely opaque to the Linux system on which the Samba Server is running; all it sees is a directory full of ordinary files (“bands”) which comprise the .sparsebundle.

On older versions of macOS, the file system inside the .sparsebundle was HFS+. Monterey supposedly still supports that, but creates new .sparsebundles where the internal file system is APFS.

After upgrading, I tried to do an incremental backup. This repeatedly failed, with a slew of errors that I don’t want to get into right now. Evidently, whatever claims to the contrary, backing up to a Samba Server, with the .sparsebundle formatted as HFS+ does not work on Monterey.

Reluctantly, I decided to sacrifice one of my two backups, removing it from the list of backups, deleting the .sparsebundle from the Server, and letting Time Machine create a new one, this time, internally formatted as APFS. At first, the backup seemed to go OK. But, after a couple of days, and ~300 GB written to the server, the backup failed, and Time Machine refused to restart it. Investigating, the .sparsebundle would not even mount, if I attempted to mount it manually. Disk Utility reported that the APFS file system was corrupted, and could not be repaired.

So I tried again: removed the backup, deleted the .sparsebundle from the Server, and let Time Machine create a new one from scratch. ~250 GB and another couple of days later, the backup again failed, with the same symptoms.

Here’s the bit of the Time Machine log around the failure:


2022-04-10 16:48:58.645717-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:CopyProgress] Fatal failure to copy '/Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/Tin Can/2022-04-09-185804/Macintosh HD - Data/usr/local/lib/ruby/gems/2.3.0/doc/did_you_mean-1.0.2/rdoc/css/rdoc.css' to '/Volumes/Backups of Tin Can/2022-04-09-185823.inprogress/Macintosh HD - Data/usr/local/lib/ruby/gems/2.3.0/doc/did_you_mean-1.0.2/rdoc/css', error: -43, srcErr: NO
2022-04-10 16:49:03.152913-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:CopyProgress] Failed copy from volume "Macintosh HD - Data"
          113980 Total Items Added (l: 6.24 GB p: 6.68 GB)
               0 Total Items Propagated (shallow) (l: Zero KB p: Zero KB)
               0 Total Items Propagated (recursive) (l: Zero KB p: Zero KB)
          113980 Total Items in Backup (l: 6.24 GB p: 6.68 GB)
           95406 Files Copied (l: 6.2 GB p: 6.62 GB)
           15585 Directories Copied (l: Zero KB p: Zero KB)
             290 Symlinks Copied (l: 7 KB p: Zero KB)
            2699 Files Linked (l: 43.8 MB p: 52.1 MB)
2022-04-10 16:49:03.155424-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Copy stage failed with error: Error Domain=com.apple.backupd.ErrorDomain Code=11 "(null)" UserInfo={NSUnderlyingError=0x7fbebf3eccd0 {Error Domain=NSOSStatusErrorDomain Code=-43 "fnfErr: File not found"}, MessageParameters=(
    "/usr/local/lib/ruby/gems/2.3.0/doc/did_you_mean-1.0.2/rdoc/css/rdoc.css"
)}
2022-04-10 16:49:11.487666-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:49:21.387970-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Unmounted '/Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/Tin Can/2022-04-09-185804/Personal'
2022-04-10 16:49:21.400097-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Unmounted local snapshot: com.apple.TimeMachine.2022-04-09-185804.local at path: /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/Tin Can/2022-04-09-185804/Personal source: Personal
2022-04-10 16:49:21.950579-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:49:21.987207-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:49:22.353689-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Unmounted '/Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/Tin Can/2022-04-09-185804/Macintosh HD - Data'
2022-04-10 16:49:22.359520-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:49:23.901539-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Unmounted local snapshot: com.apple.TimeMachine.2022-04-09-185804.local at path: /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/Tin Can/2022-04-09-185804/Macintosh HD - Data source: Macintosh HD - Data
2022-04-10 16:49:27.292449-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:49:27.292852-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint '/Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0' is still valid
2022-04-10 16:49:27.685979-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint '/Volumes/Backups of Tin Can' is still valid
2022-04-10 16:49:28.103532-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint '/Volumes/Backups of Tin Can' is still valid
2022-04-10 16:49:28.512397-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint '/Volumes/Personal' is still valid
2022-04-10 16:49:28.713895-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint '/System/Volumes/Data' is still valid
2022-04-10 16:49:31.394479-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Backup failed (11: BACKUP_FAILED_COPY_STAGE)
2022-04-10 16:49:37.756029-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Unmounted '/Volumes/Backups of Tin Can'
2022-04-10 16:49:42.891886-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Failed to unmount '/Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0', Disk Management error: {
    Action = Unmount;
    Dissenter = 1;
    DissenterPID = 19902;
    DissenterPPID = 0;
    DissenterStatus = 49168;
    Target = "file:///Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler%20Backup%200/";
}
2022-04-10 16:49:42.896012-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Failed to unmount '/Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0', error: Error Domain=com.apple.diskmanagement Code=0 "No error" UserInfo={NSDebugDescription=No error, NSLocalizedDescription=No Error.}
2022-04-10 16:49:42.935636-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:BackupScheduling] Not prioritizing backups with priority errors. lockState=0
...
2022-04-10 16:53:07.167148-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Starting automatic backup
2022-04-10 16:53:07.168919-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Network destination already mounted at: /Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0
2022-04-10 16:53:07.169298-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Initial network volume parameters for 'Distler Backup 0' {disablePrimaryReconnect: 0, disableSecondaryReconnect: 0, reconnectTimeOut: 30, QoS: 0x20, attributes: 0x1C}
2022-04-10 16:53:07.187213-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Configured network volume parameters for 'Distler Backup 0' {disablePrimaryReconnect: 0, disableSecondaryReconnect: 0, reconnectTimeOut: 30, QoS: 0x20, attributes: 0x1C}
2022-04-10 16:53:08.678084-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Skipping periodic backup verification: no previous backups to this destination.
2022-04-10 16:53:09.696741-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] 'Tin Can.sparsebundle' does not need resizing - current logical size is 2.06 TB (2,055,262,778,880 bytes), size limit is 2.06 TB (2,055,262,778,982 bytes)
2022-04-10 16:53:09.915293-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint '/Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0' is still valid
2022-04-10 16:53:09.996881-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Checking for runtime corruption on '/Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0/Tin Can.sparsebundle'
2022-04-10 16:53:19.437911-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Successfully attached using DiskImages2 as 'disk2' from URL '/Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0/Tin Can.sparsebundle'
2022-04-10 16:53:19.440910-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:19.643846-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:20.583484-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint '/Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0' is still valid
2022-04-10 16:53:20.586062-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:20.586242-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Runtime corruption check passed for '/Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0/Tin Can.sparsebundle'
2022-04-10 16:53:20.587567-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:20.589086-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:20.590174-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:20.591703-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:20.592900-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:20.593027-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Attempting to mount APFS volume from disk3s1
2022-04-10 16:53:50.382455-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Failed to mount 'disk3s1', dissenter {
    DAStatus = 49218;
}, status: (null)
2022-04-10 16:53:50.791300-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Mount dissented, retrying...
2022-04-10 16:53:53.893930-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:53.897615-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:53.916581-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:53:53.916724-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Attempting to mount APFS volume from disk3s1
2022-04-10 16:54:09.948095-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Failed to mount 'disk3s1', dissenter {
    DAStatus = 49218;
}, status: (null)
2022-04-10 16:54:10.324846-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Mount dissented, retrying...
2022-04-10 16:54:13.425438-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:54:13.427379-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:54:13.429332-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:54:13.429410-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Attempting to mount APFS volume from disk3s1
2022-04-10 16:54:20.216256-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Failed to mount 'disk3s1', dissenter {
    DAStatus = 49218;
}, status: (null)
2022-04-10 16:54:20.533201-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Mount dissented, retrying...
2022-04-10 16:54:23.633572-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:54:25.816743-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Unmounted '/Volumes/.timemachine/192.168.0.xxx/81CD6E80-8234-4079-B19A-3AC33F7E06EF/Distler Backup 0'
2022-04-10 16:54:25.829714-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Waiting 60 seconds and trying again.
2022-04-10 16:55:31.572028-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Attempting to mount 'smb://distler-backup@192.168.0.xxx/Distler%20Backup%200'
2022-04-10 16:55:33.819999-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Mounted 'smb://distler-backup@192.168.0.xxx/Distler%20Backup%200' at '/Volumes/.timemachine/192.168.0.xxx/8D2542FA-CFAB-4C6B-9E66-9005383E0039/Distler Backup 0' (1.77 TB of 2.16 TB available)
2022-04-10 16:55:33.820214-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Initial network volume parameters for 'Distler Backup 0' {disablePrimaryReconnect: 0, disableSecondaryReconnect: 0, reconnectTimeOut: 60, QoS: 0x0, attributes: 0x1C}
2022-04-10 16:55:34.030606-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Configured network volume parameters for 'Distler Backup 0' {disablePrimaryReconnect: 0, disableSecondaryReconnect: 0, reconnectTimeOut: 30, QoS: 0x20, attributes: 0x1C}
2022-04-10 16:55:34.784320-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Skipping periodic backup verification: no previous backups to this destination.
2022-04-10 16:55:35.248129-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint '/Volumes/.timemachine/192.168.0.xxx/8D2542FA-CFAB-4C6B-9E66-9005383E0039/Distler Backup 0' is still valid
2022-04-10 16:55:35.332770-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Checking for runtime corruption on '/Volumes/.timemachine/192.168.0.xxx/8D2542FA-CFAB-4C6B-9E66-9005383E0039/Distler Backup 0/Tin Can.sparsebundle'
2022-04-10 16:55:42.623176-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Successfully attached using DiskImages2 as 'disk2' from URL '/Volumes/.timemachine/192.168.0.xxx/8D2542FA-CFAB-4C6B-9E66-9005383E0039/Distler Backup 0/Tin Can.sparsebundle'
2022-04-10 16:55:42.625886-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:55:42.627412-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:55:43.234062-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint '/Volumes/.timemachine/192.168.0.xxx/8D2542FA-CFAB-4C6B-9E66-9005383E0039/Distler Backup 0' is still valid
2022-04-10 16:55:43.236237-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:55:43.236358-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Runtime corruption check passed for '/Volumes/.timemachine/192.168.0.xxx/8D2542FA-CFAB-4C6B-9E66-9005383E0039/Distler Backup 0/Tin Can.sparsebundle'
2022-04-10 16:55:43.237707-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:55:43.238827-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:55:43.239902-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:55:43.241266-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:55:43.242325-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:DiskImages] Found disk3s1 41504653-0000-11AA-AA11-00306543ECAC
2022-04-10 16:55:43.242443-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Attempting to mount APFS volume from disk3s1
2022-04-10 16:56:03.825110-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:General] Failed to mount 'disk3s1', dissenter {
    DAStatus = 49218;
}, status: (null)
2022-04-10 16:56:03.940935-0500  localhost backupd[71202]: (TimeMachine) [com.apple.TimeMachine:Mounting] Mount dissented, retrying...

Won’t even mount, eh?


% sudo fsck_apfs /dev/disk3s1
Password:
** Checking the container superblock.
   Checking the checkpoint with transaction ID 2703.
** Checking the space manager.
** Checking the space manager free queue trees.
** Checking the object map.
** Checking volume /dev/rdisk3s1.
** Checking the APFS volume superblock.
   The volume Backups of Tin Can was formatted by newfs_apfs (1934.101.3) and last modified by apfs_kext (1934.101.3).
** Checking the object map.
warning: (oid 0x432370d) om: btn: invalid o_cksum (0xce8d60bd7f753902)
   Object map is invalid.
** The volume /dev/rdisk3s1 was found to be corrupt and cannot be repaired.
** Verifying allocated space.
** The volume /dev/disk3s1 could not be verified completely.

Time Machine managed to corrupt the Object B-tree, on its first attempt. And fsck_apfs can’t repair it. The entire file system is hosed. So much for the “robustness” of APFS and so much for the quality of Apple’s backup software.

And it ain’t just me. There are lots of complaints on the Synology Forum from people having the same issue.

Next time, I’ll tell you about Fink.

Posted by distler at April 11, 2022 1:48 AM

TrackBack URL for this Entry:   https://golem.ph.utexas.edu/cgi-bin/MT-3.0/dxy-tb.fcgi/3392



0 Comments & 0 Trackbacks

Post a New Comment