Time Machine over SMB -- Could not verify dataset

[KevDog]

I'm referencing this thread: https://www.ixsystems.com/community...ntal-support-for-time-machine-over-smb.70604/

I've got a few test systems set up for my time machine backups
1. An actual Apple Time Machine
2. Linux VM (Arch) installed with ZOL, root with afp, smb protocols
3. FreeNAS system with afp, smb protocols

I've let my MBP back up a directory via the Time Machine interface. After working through all the kinks getting Time Machine over SMB setup, I've let these test systems percolate now for about 2 weeks.
FreeNAS unfortunately is the only system that is giving me problems. It will run for about 4-5 days making backups, and then suddenly tell me it can't verify the remote and then wants to make a new sparse bundle. This unfortunately only happens when running the time machine over SMB, since when running time machine over afp -- I don't seem to get these problems. Conversely running Time Machine over smb to my Arch Linux install -- I don't ever seem to get these errors.

I'll list my smb settings and the settings for the share since I don't know if these are potential culprits

FreeNas
Within smb settings:

Code:

Workgroup = WORKGROUP
Local Master = Checked
Time Server for Domain = Checked
Guest Account = Nobody
No File or Directory Mask
No Aux Parameters
Unix Extensions = Checked
Zeroconf share discovery = Checked
Obey PAM restrictions = Checked

Actual Share

Code:

Time Machine = Checked
Browsable to Network Clients = Checked
Show Hidden Files = Checked
VFS Objects = catia, fruit, streams_xattr, zfs_space, zfsacl

Aux Parameters= 
create mask = 0644
force create mode = 0644
directory mask = 2755
force directory mode = 2755
fruit:time machine = yes

For comparison, here is my Linux SMB file

Code:

[global]
   netbios name = archTM_Xen
   create mask = 0644
   directory mask = 2755
   force create mode = 0644
   force directory mode = 2755
   server min protocol = SMB2_02
   smb encrypt = desired
   load printers = no
   printing = bsd
   printcap name = /dev/null
   disable spoolss = yes
   show add printer wizard = no
   delete veto files = true

   #Following was added based on recommendations here: https://wiki.samba.org/index.php/C
onfigure_Samba_to_Work_Better_with_Mac_OS_X
   min protocol = SMB2
   vfs objects = catia fruit streams_xattr
   ea support = yes
   fruit:metadata = stream
   fruit:model = MacSamba
   fruit:veto_appledouble = yes
   fruit:posix_rename = yes
   fruit:zero_file_id = yes
   fruit:wipe_intentionally_left_blank_rfork = yes
   fruit:delete_empty_adfiles = yes

[TimeMachine]
   comment = Time Machine SMB shares
   vfs objects = catia fruit streams_xattr
   fruit:time machine = yes
   path = /mnt/timemachine
   valid users = kevdog @timemachine
   force group = +timemachine
   public = no
   writeable = yes

This issue unfortunately seems to have been reported:

Initial / experimental support for time machine over SMB

On one of my Macs, I’ve had success since upgrading to U2... on another, I got the dreaded “start new backup” message right after completing the first backup. So, it appears to be a mixed bag for me. And, yes, the backup over SMB is WAY slower. Are you using a wired or wireless connection for...

www.ixsystems.com

Initial / experimental support for time machine over SMB

On one of my Macs, I’ve had success since upgrading to U2... on another, I got the dreaded “start new backup” message right after completing the first backup. So, it appears to be a mixed bag for me. And, yes, the backup over SMB is WAY slower. Are you using a wired or wireless connection for...

www.ixsystems.com

Initial / experimental support for time machine over SMB

The problem, as I've experienced it, actually manifests after the full backup, and even a few incremental, have occurred successfully... then, "something" happens, and I can't get any further backups to complete. I've been running a test since yesterday, on a 2012 Synology, which has thus far...

www.ixsystems.com

I'm happy to provide any appropriate logs if you'll instruct me what logs are necessary and how to access the particular log.
Really kind of frustrating.

 

[anodos]

Are you simultaneously sharing Time Machine over SMB and AFP on FreeNAS?

 

[KevDog]

Yes I am
Both in FreeNAS and Linux.
I'm also simultaneously sharing the same share over AFP/SMB on both machines as well.

 

[anodos]

Yes I am
Both in FreeNAS and Linux.
I'm also simultaneously sharing the same share over AFP/SMB on both machines as well.

In 11.2 we're using time machine support compiled into netatalk and samba (using mdnsresponder not avahi). Since the two services are both advertising the same hostname _adisk._tcp. mDNS srv records with different air disk volume UUID numbers and adVF values, you will also see undefined behavior. This second issue might be resolved by setting "zerconf name = freenas_smb" under Services->SMB.

<edit> didn't realize that the quoted smb.conf was from the Arch server.

 

[KevDog]

1. By auxiliary parameters you mean?:

Code:

Aux Parameters= 
create mask = 0644
force create mode = 0644
directory mask = 2755
force directory mode = 2755
fruit:time machine = yes

So is only the fruit:time machine = yes needed?

2. Ok in terms of zeroconf name = freenas_smb -- I'll make the change. Thanks.

 

[anodos]

1. By auxiliary parameters you mean?:

Code:

Aux Parameters=
create mask = 0644
force create mode = 0644
directory mask = 2755
force directory mode = 2755
fruit:time machine = yes

So is only the fruit:time machine = yes needed?

I misread your initial post. Try the "zeroconf name" change. 11.3 will properly handle the case of mixed AFP and SMB time machine shares.

 

[KevDog]

Ok -- I just upgraded to 11.2 U7 -- I realize that isn't 11.3 (which I wish would drop soon). I added zeroconf entry under auxillary parameters within Services->SMB. We'll see what happens. Usually it takes a few days for things to break down unfortunately.

 

[anodos]

Ok -- I just upgraded to 11.2 U7 -- I realize that isn't 11.3 (which I wish would drop soon). I added zeroconf entry under auxillary parameters within Services->SMB. We'll see what happens. Usually it takes a few days for things to break down unfortunately.

I've been running multiple time machine over SMB shares on FreeNAS for over a year without any breakage. I'm also in the process of writing a samba VFS module to automate and maintain snapshots of time machine backups so that users will be able to roll back to the last successful one if corruption occurs.

 

[KevDog]

@anodos - I have no idea how to write a samba VFS module, however your concept is awesome. I suppose the zfs snapshot would be taken after successful backup, however I really have no idea how a restore would be triggered automatically -- only manually. I'd be happy to test the module when it's at the appropriate stage.

 

[seanm]

I've been running multiple time machine over SMB shares on FreeNAS for over a year without any breakage.

For several months now, I have 10 Macs backing up to FreeNAS Time Machine over SMB. I've never even turned AFP on. I've been quite happy with it. But a few times I have found it stop working, with the Mac saying that it needs to start a brand new backup from scratch. I'm not sure I can fault FreeNAS for this though, because I've seen Time Machine do that even backing up to a local hard disk.

I'm also in the process of writing a samba VFS module to automate and maintain snapshots of time machine backups so that users will be able to roll back to the last successful one if corruption occurs.

Sweet! Man, I owe you so many beers! :) Is there a ticket I can CC myself on?

 

[anodos]

Sweet! Man, I owe you so many beers! :) Is there a ticket I can CC myself on?

I forgot to create a ticket for it. I've been working pretty heavily on smb/libzfs integration in samba (creating a library in samba to simplify this for vfs module developers) and this is kind of an offshoot of that effort.

 

[seanm]

So I guess I jinxed it, but I now have a Mac that's telling me:

"Time Machine completed a verification of your backups on “freenas.local”. To improve reliability, Time Machine must create a new backup for you."

@anodos is there some log somewhere, Mac and/or FreeNAS, that could help debug this?

 

[anodos]

On the FreeNAS side you can look for any obvious errors in log.smbd and /var/log/messages for error messages. The actual backup is opaque to us, and so any helpful logs might be on the mac side. You might be able to use tmutil on the mac to investigate further.

 

[seanm]

so any helpful logs might be on the mac side

So I invoked tmutil startbackup --block and got this in Console.app:

default 17:39:40.915759 -0500 kernel smbfs_vnop_ioctl: TM Read - attributes 0x1c reconnTO 30 QoS 0x20 default 17:39:40.919012 -0500 kernel smbfs_vnop_ioctl: TM Read - attributes 0x1c reconnTO 30 QoS 0x20 default 17:39:40.919066 -0500 kernel smbfs_vnop_ioctl: Attempt setting durable handle timeout to 30 default 17:39:40.921687 -0500 kernel smb2fs_smb_cmpd_create: smb2fs_smb_ntcreatex failed 13 default 17:39:40.921752 -0500 kernel smb2fs_smb_cmpd_create: smb2fs_smb_ntcreatex failed 13 default 17:39:40.921761 -0500 kernel smb2fs_smb_cmpd_create: smb2fs_smb_ntcreatex failed 13 default 17:39:40.936619 -0500 com.apple.prefs.backup.remoteservice UNIX error exception: 17 default 17:39:40.953047 -0500 com.apple.prefs.backup.remoteservice UNIX error exception: 17

Mean anything to you? :)

 

[KevDog]

I'm learning TM as a backup for FreeNAS isn't the most robust -- currently exploring Vorta/BorgBackup as an alternative ..
I found this somewhere on the apple forums for looking at TM logs. Run this on the Mac Client:

Code:

printf '\e[3J' && log show --predicate 'subsystem == "com.apple.TimeMachine"' --info --last 24h | grep -F 'eMac' | grep -Fv 'etat' | awk -F']' '{print substr($0,1,19), $NF}'

In terms or your error -- possibly a permissions issue?

@anodos -- Seems like the process of creating TM backups on FreeNAS creates an acl on the actual share and possibly the directory. Why? Is this necessary?

 

[seanm]

tmutil listbackups tells me my last successful backups were:

/Volumes/Time Machine Backups/Backups.backupdb/MyMacName/2019-11-18-231226 /Volumes/Time Machine Backups/Backups.backupdb/MyMacName/2019-11-19-000537 /Volumes/Time Machine Backups/Backups.backupdb/MyMacName/2019-11-19-010605

Then with log show --predicate 'subsystem == "com.apple.TimeMachine"' --info --last 4d (thanks @KevDog ) I looked at what was logged before & after that last successful backup. For the days where it worked fine, there's a sequence of logs that repeats the same every time. Then at 2019-11-19 00:06 things changed a bit with a generic I/O error:

2019-11-19 00:06:28.576615 Starting post-backup thinning 2019-11-19 00:11:39.799115 Error: Error Domain=NSOSStatusErrorDomain Code=-36 "ioErr: I/O error (bummers)" deleting backup: /Volumes/Time Machine Backups/Backups.backupdb/MyMacName/2019-10-21-002227 2019-11-19 00:11:49.469011 Deleted /Volumes/Time Machine Backups/Backups.backupdb/MyMacName/2019-11-17-233107 (34.4 MB) 2019-11-19 00:11:49.469030 Post-backup thinning complete: 1 expired backups removed 2019-11-19 00:11:49.999180 Backup completed successfully. 2019-11-19 00:12:01.437703 Ejected Time Machine disk image: /Volumes/TimeMachine/MyMacName.sparsebundle 2019-11-19 00:12:01.656811 Ejected Time Machine network volume.

Then an hour later very similar, seems it could not delete that backup:

2019-11-19 01:13:46.570516-0500 Error: Error Domain=NSOSStatusErrorDomain Code=-36 "ioErr: I/O error (bummers)" deleting backup: /Volumes/Time Machine Backups/Backups.backupdb/scm/2019-10-21-002227

then later it tries to start a new backup:

2019-11-19 01:58:15.653703-0500 Starting automatic backup 2019-11-19 01:58:15.660173-0500 Attempting to mount network destination URL: smb://username@freenas._smb._tcp.local./TimeMachine 2019-11-19 01:58:16.124542-0500 Mounted network destination at mount point: /Volumes/TimeMachine using URL: smb://username@freenas._smb._tcp.local./TimeMachine 2019-11-19 01:58:27.581582-0500 Checking for runtime corruption on /dev/disk1s2 2019-11-19 01:58:28.303594-0500 Runtime corruption detected on /Volumes/TimeMachine/MyMacName.sparsebundle (fsck_hfs -q termination status: 3)

I confirmed my scrub and SMART tasks were not running at those times.

So I'm not sure what to conclude, but there you have it...

 

[anodos]

So I invoked tmutil startbackup --block and got this in Console.app:

default 17:39:40.915759 -0500 kernel smbfs_vnop_ioctl: TM Read - attributes 0x1c reconnTO 30 QoS 0x20 default 17:39:40.919012 -0500 kernel smbfs_vnop_ioctl: TM Read - attributes 0x1c reconnTO 30 QoS 0x20 default 17:39:40.919066 -0500 kernel smbfs_vnop_ioctl: Attempt setting durable handle timeout to 30 default 17:39:40.921687 -0500 kernel smb2fs_smb_cmpd_create: smb2fs_smb_ntcreatex failed 13 default 17:39:40.921752 -0500 kernel smb2fs_smb_cmpd_create: smb2fs_smb_ntcreatex failed 13 default 17:39:40.921761 -0500 kernel smb2fs_smb_cmpd_create: smb2fs_smb_ntcreatex failed 13 default 17:39:40.936619 -0500 com.apple.prefs.backup.remoteservice UNIX error exception: 17 default 17:39:40.953047 -0500 com.apple.prefs.backup.remoteservice UNIX error exception: 17

Mean anything to you? :)

Possibly an ACL error. Post getfacl output for the the path to the share and the sparsebundle volume.

 

[anodos]

I'm learning TM as a backup for FreeNAS isn't the most robust -- currently exploring Vorta/BorgBackup as an alternative ..
I found this somewhere on the apple forums for looking at TM logs. Run this on the Mac Client:

Code:

printf '\e[3J' && log show --predicate 'subsystem == "com.apple.TimeMachine"' --info --last 24h | grep -F 'eMac' | grep -Fv 'etat' | awk -F']' '{print substr($0,1,19), $NF}'

In terms or your error -- possibly a permissions issue?

@anodos -- Seems like the process of creating TM backups on FreeNAS creates an acl on the actual share and possibly the directory. Why? Is this necessary?

I don't know the context. I would have to see the permissions on the path. Failure to delete is often a side-effect of someone manipulating the POSIX mode (which strips the delete permissions from files). I'm usually double-careful to prevent Macs from doing this (set aclmode to restricted and turn off NFS aces in vfs_fruit). FreeNAS doesn't create the ACL. We just do what the client requests (which it might be doing). The actual Time Machine code no FreeNAS is no different than any other platform using Time Machine over SMB. The simple fact of the matter is that none of the NAS platforms actually implements F_FULLFSYNC. So it might also be that you've gotten lucky so far on the other platforms. This is why I'm taking additional steps to ensure that we take snapshots on successful completion of backups.

Example of my home time machine share:

Code:

2018-12-14.03:55:31 zfs set aclmode=restricted dozer/SMB49TM #zpool history output

root@homenas[/mnt/dozer]# getfacl /mnt/dozer/SMB49TM
# file: /mnt/dozer/SMB49TM
# owner: smbuser
# group: wheel
            owner@:rwxpDdaARWcCos:fd-----:allow
            group@:rwxpDdaARWcCos:fd-----:allow
         everyone@:r-x---a-R-c---:fd-----:allow

[global]
        aio max threads = 2
        bind interfaces only = Yes
        deadtime = 15
        disable spoolss = Yes
        dns proxy = No
        kernel change notify = No
        load printers = No
        logging = file
        max log size = 51200
        nsupdate command = /usr/local/bin/samba-nsupdate -g
        server min protocol = SMB2_02
        server role = standalone server
        server string = FreeNAS Server
        unix extensions = No
        username map = /usr/local/etc/smbusername.map
        username map cache time = 60
        idmap config *: range = 90000001-100000000
        fruit:nfs_aces = No
        idmap config * : backend = tdb
        allocation roundup size = 0
        directory name cache size = 0
        dos filemode = Yes
        include = /usr/local/etc/smb4_share.conf

[TM_SMB]
        aio write size = 0
        mangled names = illegal
        path = /mnt/dozer/SMB49TM
        read only = No
        vfs objects = zfs_space zfsacl fruit streams_xattr
        nfs4:acedup = merge
        nfs4:chown = true
        fruit:volume_uuid = c398844e-5eb1-495c-8502-16566d867f1f
        fruit:time machine = yes
        fruit:resource = stream
        fruit:metadata = stream

It has been running constantly since December 14, 2018 without any issues. It started life on a special hacked-together and hotpatched development build, and has cycled through 11.2-stable to the nightly FN development builds. Hardware is a FreeNAS mini.

 

[seanm]

Possibly an ACL error. Post getfacl output for the the path to the share and the sparsebundle volume.

root@freenas[~]# getfacl /mnt/ekur/TimeMachine # file: /mnt/ekur/TimeMachine # owner: timemachine # group: nogroup owner@:rwxpDdaARWcCos:fd-----:allow group@:rwxpDdaARWcCos:fd-----:allow everyone@:r-x---a-R-c---:fd-----:allow root@freenas[~]# getfacl /mnt/ekur/TimeMachine/scm.sparsebundle # file: /mnt/ekur/TimeMachine/scm.sparsebundle # owner: timemachine # group: nogroup owner@:rwxpDdaARWcCos:fd----I:allow group@:rwxpDdaARWcCos:fd----I:allow everyone@:r-x---a-R-c---:fd----I:allow

Looks basically like yours.

For samba:

[global] aio max threads = 2 deadtime = 15 disable netbios = Yes disable spoolss = Yes dns proxy = No dos charset = CP437 hostname lookups = Yes kernel change notify = No lm announce = Yes load printers = No logging = file max log size = 51200 max open files = 1882991 nsupdate command = /usr/local/bin/samba-nsupdate -g obey pam restrictions = Yes printcap name = /dev/null security = USER server min protocol = SMB3_00 server role = standalone server server string = FreeNAS Server smb ports = 445 time server = Yes idmap config *: range = 90000001-100000000 fruit:nfs_aces = no idmap config * : backend = tdb acl allow execute always = Yes case sensitive = Yes create mask = 0666 directory mask = 0777 directory name cache size = 0 dos filemode = Yes strict locking = No [TimeMachine] access based share enum = Yes aio write size = 0 mangled names = illegal path = "/mnt/ekur/TimeMachine" read only = No smb encrypt = required veto files = /.snapshot/.windows/.mac/.zfs/ vfs objects = catia zfs_space zfsacl fruit streams_xattr zfsacl:acesort = dontcare nfs4:chown = true nfs4:acedup = merge nfs4:mode = simple fruit:volume_uuid = <some uuid> fruit:time machine = yes fruit:resource = stream fruit:metadata = stream

This is why I'm taking additional steps to ensure that we take snapshots on successful completion of backups.

Yeah, that'll be great, since it would hopefully allow going back to a good sparsebundle, instead of having to start all over. Though I wonder if Time Machine will get confused with such a rollback.

 

[seanm]

@anodos I was just thinking... I wonder if this is another 1/1300 chance name collision a la https://jira.ixsystems.com/browse/NAS-104096 ? I've set "mangled names = no" on my Time Machine shares, we'll see if it happens again...