[Samba] Time-machine replies with 17: File Exists

Mon Apr 26 14:53:29 UTC 2021

On Mon, Apr 26, 2021 at 1:47 AM Jorgen Lundman via samba <
samba at lists.samba.org> wrote:

>
> Sorry it’s another time-machine related issue;
>
> Server:
> OmniOS 151036
> Samba-4.14.3
>
> Clients:
> macOS 11.2.3 (BigSur/M1)
> macOS 11.0
>
> The final messages from TimeMachine client are:
>
>  backupd: (TimeMachine) [com.apple.TimeMachine:General] Starting manual
> backup
>  backupd: (TimeMachine) [com.apple.TimeMachine:General] Attempting to
> mount 'smb://lundman@192.168.10.10/backup'
>
>  backupd: (TimeMachine) [com.apple.TimeMachine:General] Mounted 'smb://
> lundman at 192.168.10.10/backup' at '/Volumes/.timemachine/
> 192.168.10.10/A85D5933-0B47-4CD0-8CDD-BF3A15399B06/backup'
>
> backupd: (TimeMachine) [com.apple.TimeMachine:General] Initial network
> volume parameters for 'backup' {disablePrimaryReconnect: 0,
> disableSecondaryReconnect: 0, reconnectTimeOut: 60, QoS: 0x0, attributes:
> 0x1C}
>
>  backupd: (TimeMachine) [com.apple.TimeMachine:General] Configured network
> volume parameters for 'backup' {disablePrimaryReconnect: 0,
> disableSecondaryReconnect: 0, reconnectTimeOut: 30, QoS: 0x20, attributes:
> 0x1C}
>
>  backupd: (TimeMachine) [com.apple.TimeMachine:General] Failed to set
> resource value with key 'NSURLIsUserImmutableKey' to '0' for
> '/Volumes/.timemachine/
> 192.168.10.10/A85D5933-0B47-4CD0-8CDD-BF3A15399B06/backup/8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/token',
> error: Error Domain=NSCocoaErrorDomain Code=4 "The file “token” doesn’t
> exist." UserInfo={NSURL=file:///Volumes/.timemachine/
> 192.168.10.10/A85D5933-0B47-4CD0-8CDD-BF3A15399B06/backup/8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/token,
> NSFilePath=/Volumes/.timemachine/
> 192.168.10.10/A85D5933-0B47-4CD0-8CDD-BF3A15399B06/backup/8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/token,
> NSUnderlyingError=0x12b705e40 {Error Domain=NSPOSIXErrorDomain Code=2 "No
> such file or directory"}}
>
> backupd: (TimeMachine) [com.apple.TimeMachine:General] Deleted
> '8F4543E4-C770-549D-98ED-F2396DA6BE6F.purgeable.sparsebundle', 9.39 TB
> available on 'backup'
>
> backupd: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint
> '/Volumes/.timemachine/
> 192.168.10.10/A85D5933-0B47-4CD0-8CDD-BF3A15399B06/backup' is still valid
>
> backupd: (TimeMachine) [com.apple.TimeMachine:General] Mountpoint
> '/Volumes/.timemachine/
> 192.168.10.10/A85D5933-0B47-4CD0-8CDD-BF3A15399B06/backup' is still valid
>
> backupd: (TimeMachine) [com.apple.TimeMachine:General] Creating a
> sparsebundle using Case-sensitive APFS filesystem
>
> backupd: (TimeMachine) [com.apple.TimeMachine:General] Failed to create
> '/Volumes/.timemachine/
> 192.168.10.10/A85D5933-0B47-4CD0-8CDD-BF3A15399B06/backup/8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle',
> results: {
> }, error: 17 File exists
>
> backupd: (TimeMachine) [com.apple.TimeMachine:General] Backup failed (20:
> BACKUP_FAILED_DISK_IMAGE_NOT_CREATED)
>
>
>
>
> Juicy bits from "./sbin/smbd -F -S -d 3 --no-process-group”
>
>
> check_ntlm_password:  authentication for user [lundman] -> [lundman] ->
> [lundman] succeeded
> make_connection_snum: Connect path is '/time-machine' for service
> [time-machine]
> Initialising default vfs hooks
> Initialising custom vfs hooks from [/[Default VFS]/]
> Initialising custom vfs hooks from [streams_xattr]
> load_module_absolute_path: Module
> '/usr/local/samba/lib/vfs/streams_xattr.so' loaded
> Initialising custom vfs hooks from [fruit]
> load_module_absolute_path: Module '/usr/local/samba/lib/vfs/fruit.so'
> loaded
> Initialising custom vfs hooks from [catia]
> load_module_absolute_path: Module '/usr/local/samba/lib/vfs/catia.so'
> loaded
> Initialising custom vfs hooks from [zfsacl]
> load_module_absolute_path: Module '/usr/local/samba/lib/vfs/zfsacl.so'
> loaded
> fruit_connect: Enabling durable handles for Time Machine support on
> [time-machine]
> macbookpro-bff9 (ipv4:192.168.10.69:64222) connect to service
> time-machine initially as user lundman (uid=100, gid=1) (pid 24337)
> Allowed connection from 192.168.10.69 (192.168.10.69)
> make_connection_snum: Connect path is '/tmp' for service [IPC$]
> Initialising default vfs hooks
> Initialising custom vfs hooks from [/[Default VFS]/]
> Initialising custom vfs hooks from [streams_xattr]
> Initialising custom vfs hooks from [fruit]
> Initialising custom vfs hooks from [catia]
> Initialising custom vfs hooks from [zfsacl]
>
>
> smbd_dirptr_get_entry mask=[*] found
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/Info.plist
> fname=Info.plist (Info.plist)
> smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1]
> status[STATUS_NO_MORE_FILES] || at
> ../../source3/smbd/smb2_query_directory.c:160
> lundman opened file
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/token read=No write=No
> (numopen=1)
> smbd_do_setfilepathinfo:
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/token (fnum 3947838781)
> info_level=65290 totdata=182
> rename_internals_fsp: succeeded doing rename on
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/token ->
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/.smbdeleteAAA982192ed2c879048
> lundman closed file
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/.smbdeleteAAA982192ed2c879048
> (numopen=0) NT_STATUS_OK
> Server exit (NT_STATUS_END_OF_FILE)
> lundman opened file
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/Info.bckup read=No
> write=No (numopen=1)
> smbd_do_setfilepathinfo:
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/Info.bckup (fnum
> 768919259) info_level=1013 totdata=1
> lundman closed file
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/Info.bckup (numopen=0)
> NT_STATUS_OK
> smbd_dirptr_get_entry mask=[*] found
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/bands/. fname=. (.)
> smbd_dirptr_get_entry mask=[*] found
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/bands/.. fname=.. (..)
> smbd_dirptr_get_entry
> mask=[8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle] found
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle
> fname=8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle
> (8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle)
> smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1]
> status[STATUS_NO_MORE_FILES] || at
> ../../source3/smbd/smb2_query_directory.c:160
> Registered MSG_REQ_POOL_USAGE
> Allowed connection from 192.168.10.69 (192.168.10.69)
> init_oplocks: initializing messages.
> Transaction 0 of length 106 (0 toread)
> Selected protocol SMB3_02
> GENSEC backend 'gssapi_spnego' registered
> GENSEC backend 'gssapi_krb5' registered
> GENSEC backend 'gssapi_krb5_sasl' registered
> GENSEC backend 'spnego' registered
> GENSEC backend 'schannel' registered
> GENSEC backend 'naclrpc_as_system' registered
> GENSEC backend 'sasl-EXTERNAL' registered
> GENSEC backend 'ntlmssp' registered
> GENSEC backend 'ntlmssp_resume_ccache' registered
> GENSEC backend 'http_basic' registered
> GENSEC backend 'http_ntlm' registered
> GENSEC backend 'http_negotiate' registered
> smbd_do_setfilepathinfo:
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/bands (fnum 3312185253)
> info_level=1013 totdata=1
> smbd_dirptr_get_entry
> mask=[8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle] found
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle
> fname=8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle
> (8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle)
> lundman opened file
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/Info.plist read=No
> write=No (numopen=1)
> smbd_do_setfilepathinfo:
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/Info.plist (fnum
> 1016267877) info_level=1013 totdata=1
> lundman closed file
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/Info.plist (numopen=0)
> NT_STATUS_OK
> smbd_dirptr_get_entry
> mask=[8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle] found
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle
> fname=8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle
> (8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle)
> smbd_do_setfilepathinfo: 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle
> (fnum 1866063505) info_level=1013 totdata=1
> smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5]
> status[NT_STATUS_DIRECTORY_NOT_EMPTY] || at
> ../../source3/smbd/smb2_setinfo.c:137
> smbd_dirptr_get_entry mask=[*] found
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/. fname=. (.)
> smbd_dirptr_get_entry mask=[*] found
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/.. fname=.. (..)
> smbd_dirptr_get_entry mask=[*] found
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/.smbdeleteAAA982192ed2c879048
> fname=.smbdeleteAAA982192ed2c879048 (.smbdeleteAAA982192ed2c879048)
> smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1]
> status[STATUS_NO_MORE_FILES] || at
> ../../source3/smbd/smb2_query_directory.c:160
> smbd_do_qfsinfo: level = 1003
> lundman opened file
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/.smbdeleteAAA982192ed2c879048
> read=No write=No (numopen=1)
> smbd_do_setfilepathinfo:
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/.smbdeleteAAA982192ed2c879048
> (fnum 100708349) info_level=1013 totdata=1
> lundman closed file
> 8F4543E4-C770-549D-98ED-F2396DA6BE6F.sparsebundle/.smbdeleteAAA982192ed2c879048
> (numopen=0) NT_STATUS_OK
> macbookpro-bff9 (ipv4:192.168.10.69:64222) closed connection to service
> time-machine
> Server exit (NT_STATUS_END_OF_FILE)
>
>
>
> It seems that it expects to not see ".smbdeleteAAA982192ed2c879048” and
> yet it is there?
>
> /time-machine is a ZFS dataset, that is rm -rf each test, crowned to me:
>
> ls -la /time-machine
> total 81
> drwxrwxrwx   2 lundman  other          2 Apr 26 14:18 .
> drwxr-xr-x  29 root     root          30 Apr 17 08:41 ..
>
>
> My smb.conf:
>
> [global]
> workgroup = LUNDMAN
> interfaces = 192.168.10.10/24
> min protocol = SMB2
> server signing = mandatory
> vfs objects = zfsacl catia fruit streams_xattr
>

I believe you'll want these in the following order: "catia fruit zfsacl
streams_xattr". What is ACL on /timemachine? What are aclmode and
aclinherit properties on dataset set to?