[Samba] OS X 10.4.11 Tiger cannot write to Samba 4.5.12 file server with vfs_fruit enabled

Tue Oct 31 06:11:55 UTC 2017

 Hello, thought I’d post here before opening up an issue on Bugzilla, just
in case…

I’m setting up a combination Samba 4.5.12/Netatalk 3.1.11 file server on
Debian Stretch (kernel version 4.9.0-4-amd64), servicing a network
containing Windows, macOS, and OS X Tiger 10.4.11 systems. As I understand
it, vfs_fruit is necessary for proper interoperation with Netatalk 3, so I
have that enabled on my server. Reading and writing files containing
resource forks works fine using my El Capitan-based MacBook Pro. When
connecting to the same share from a Tiger-based Mac though, writing does
not work at all and only data forks of existing files show up in Finder.
For example if in Tiger I copy a classic Mac application called “Blackjack
2.0” to my share called “Files” as user “made," I get the following error
message in Finder:

“You cannot copy some of these items to the destination because their names
are too long or contain invalid characters for the destination.”

Drilling down further, if I attempt the same copy using Terminal— `ditto
/Volumes/Stuff/Games/Blackjack\ 2.0 /Volumes/Files/` — I get the following,
slightly more descriptive error message:

“ditto: /Volumes/Files/._Blackjack 2.0__: No such file or directory”

This suggests to me that the ._ file that Tiger creates for the resource
fork is getting blocked by vfs_fruit, since if I disable vfs_fruit, I can
copy files in Tiger just fine (but then I am incompatible with Netatalk).
But I can’t tell if that’s the case from looking at the log:

[2017/10/30 22:39:09.897190,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 30 of length 74 (0 toread)
[2017/10/30 22:39:09.897244,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.897270,  3]
../source3/smbd/trans2.c:4123(call_trans2qfsinfo)
call_trans2qfsinfo: level = 1
[2017/10/30 22:39:09.897292,  3]
../source3/smbd/trans2.c:3422(smbd_do_qfsinfo)
smbd_do_qfsinfo: level = 1
[2017/10/30 22:39:09.898643,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 31 of length 82 (0 toread)
[2017/10/30 22:39:09.898687,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.898712,  3]
../source3/smbd/trans2.c:5775(call_trans2qfilepathinfo)
call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 257
[2017/10/30 22:39:09.898769,  3]
../source3/smbd/trans2.c:5938(call_trans2qfilepathinfo)
call_trans2qfilepathinfo . (fnum [fsp is NULL]) level=257 call=5
total_data=0
[2017/10/30 22:39:09.900304,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 32 of length 114 (0 toread)
[2017/10/30 22:39:09.900346,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.900373,  3]
../source3/smbd/trans2.c:2632(call_trans2findfirst)
call_trans2findfirst: dirtype = 16, maxentries = 4, close_after_first=1,
close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x104,
max_data_bytes = 16644
[2017/10/30 22:39:09.900570,  3] ../source3/smbd/dir.c:656(dptr_create)
creating new dirptr 256 for path ., expect_close = 1
[2017/10/30 22:39:09.900646,  3]
../source3/smbd/error.c:82(error_packet_set)
NT error packet at ../source3/smbd/trans2.c(2931) cmd=50 (SMBtrans2)
NT_STATUS_NO_SUCH_FILE
[2017/10/30 22:39:09.902062,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 33 of length 114 (0 toread)
[2017/10/30 22:39:09.902106,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.902133,  3]
../source3/smbd/trans2.c:2632(call_trans2findfirst)
call_trans2findfirst: dirtype = 16, maxentries = 4, close_after_first=1,
close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x104,
max_data_bytes = 16644
[2017/10/30 22:39:09.902321,  3] ../source3/smbd/dir.c:656(dptr_create)
creating new dirptr 256 for path ., expect_close = 1
[2017/10/30 22:39:09.902396,  3]
../source3/smbd/error.c:82(error_packet_set)
NT error packet at ../source3/smbd/trans2.c(2931) cmd=50 (SMBtrans2)
NT_STATUS_NO_SUCH_FILE
[2017/10/30 22:39:09.904191,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 34 of length 108 (0 toread)
[2017/10/30 22:39:09.904233,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.904260,  3]
../source3/smbd/trans2.c:2632(call_trans2findfirst)
call_trans2findfirst: dirtype = 16, maxentries = 4, close_after_first=1,
close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x104,
max_data_bytes = 16644
[2017/10/30 22:39:09.904451,  3] ../source3/smbd/dir.c:656(dptr_create)
creating new dirptr 256 for path ., expect_close = 1
[2017/10/30 22:39:09.904527,  3]
../source3/smbd/error.c:82(error_packet_set)
NT error packet at ../source3/smbd/trans2.c(2931) cmd=50 (SMBtrans2)
NT_STATUS_NO_SUCH_FILE
[2017/10/30 22:39:09.905683,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 35 of length 108 (0 toread)
[2017/10/30 22:39:09.905732,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.905846,  3]
../source3/smbd/trans2.c:2632(call_trans2findfirst)
call_trans2findfirst: dirtype = 16, maxentries = 4, close_after_first=1,
close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x104,
max_data_bytes = 16644
[2017/10/30 22:39:09.906026,  3] ../source3/smbd/dir.c:656(dptr_create)
creating new dirptr 256 for path ., expect_close = 1
[2017/10/30 22:39:09.906104,  3]
../source3/smbd/error.c:82(error_packet_set)
NT error packet at ../source3/smbd/trans2.c(2931) cmd=50 (SMBtrans2)
NT_STATUS_NO_SUCH_FILE
[2017/10/30 22:39:09.907038,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 36 of length 112 (0 toread)
[2017/10/30 22:39:09.907079,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBntcreateX (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.907387,  2] ../source3/smbd/open.c:1342(open_file)
made opened file .BC.B4iVrC read=No write=Yes (numopen=1)
[2017/10/30 22:39:09.908319,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 37 of length 45 (0 toread)
[2017/10/30 22:39:09.908357,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBclose (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.908380,  3] ../source3/smbd/reply.c:5399(reply_close)
Close file fd=33 fnum 55940 (numopen=1)
[2017/10/30 22:39:09.908426,  2]
../source3/smbd/close.c:788(close_normal_file)
made closed file .BC.B4iVrC (numopen=0) NT_STATUS_OK
[2017/10/30 22:39:09.909319,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 38 of length 108 (0 toread)
[2017/10/30 22:39:09.909357,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.909382,  3]
../source3/smbd/trans2.c:2632(call_trans2findfirst)
call_trans2findfirst: dirtype = 16, maxentries = 4, close_after_first=1,
close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x104,
max_data_bytes = 16644
[2017/10/30 22:39:09.909532,  3] ../source3/smbd/dir.c:656(dptr_create)
creating new dirptr 256 for path ., expect_close = 1
[2017/10/30 22:39:09.909585,  3]
../source3/smbd/dir.c:1227(smbd_dirptr_get_entry)
smbd_dirptr_get_entry mask=[.BC.B4iVrC] found .BC.B4iVrC fname=.BC.B4iVrC
(.BC.B4iVrC)
[2017/10/30 22:39:09.911248,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 39 of length 112 (0 toread)
[2017/10/30 22:39:09.911287,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.911312,  3]
../source3/smbd/trans2.c:2632(call_trans2findfirst)
call_trans2findfirst: dirtype = 16, maxentries = 4, close_after_first=1,
close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x104,
max_data_bytes = 16644
[2017/10/30 22:39:09.911404,  3]
../source3/smbd/filename.c:1615(filename_convert_internal)
filename_convert_internal: check_name failed for name ._.BC.B4iVrC with
NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/10/30 22:39:09.911426,  3]
../source3/smbd/error.c:82(error_packet_set)
NT error packet at ../source3/smbd/trans2.c(2716) cmd=50 (SMBtrans2)
NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/10/30 22:39:09.912428,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 40 of length 112 (0 toread)
[2017/10/30 22:39:09.912466,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBntcreateX (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.912647,  2] ../source3/smbd/open.c:1342(open_file)
made opened file .BC.B4iVrC read=No write=Yes (numopen=1)
[2017/10/30 22:39:09.913906,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 41 of length 45 (0 toread)
[2017/10/30 22:39:09.913945,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBclose (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.913966,  3] ../source3/smbd/reply.c:5399(reply_close)
Close file fd=33 fnum 58375 (numopen=1)
[2017/10/30 22:39:09.914019,  2]
../source3/smbd/close.c:788(close_normal_file)
made closed file .BC.B4iVrC (numopen=0) NT_STATUS_OK
[2017/10/30 22:39:09.915266,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 42 of length 122 (0 toread)
[2017/10/30 22:39:09.915304,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.915329,  3]
../source3/smbd/trans2.c:2632(call_trans2findfirst)
call_trans2findfirst: dirtype = 16, maxentries = 4, close_after_first=1,
close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x104,
max_data_bytes = 16644
[2017/10/30 22:39:09.915419,  3]
../source3/smbd/filename.c:1615(filename_convert_internal)
filename_convert_internal: check_name failed for name ._Blackjack 2.0__
with NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/10/30 22:39:09.915458,  3]
../source3/smbd/error.c:82(error_packet_set)
NT error packet at ../source3/smbd/trans2.c(2716) cmd=50 (SMBtrans2)
NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/10/30 22:39:09.916351,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 43 of length 82 (0 toread)
[2017/10/30 22:39:09.916388,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.916411,  3]
../source3/smbd/trans2.c:5775(call_trans2qfilepathinfo)
call_trans2qfilepathinfo: TRANSACT2_QPATHINFO: level = 257
[2017/10/30 22:39:09.916461,  3]
../source3/smbd/trans2.c:5938(call_trans2qfilepathinfo)
call_trans2qfilepathinfo . (fnum [fsp is NULL]) level=257 call=5
total_data=0
[2017/10/30 22:39:09.917505,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 44 of length 126 (0 toread)
[2017/10/30 22:39:09.917543,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBntcreateX (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.917633,  3]
../source3/smbd/filename.c:1615(filename_convert_internal)
filename_convert_internal: check_name failed for name ._Blackjack 2.0__
with NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/10/30 22:39:09.917660,  3]
../source3/smbd/error.c:82(error_packet_set)
NT error packet at ../source3/smbd/nttrans.c(556) cmd=162 (SMBntcreateX)
NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/10/30 22:39:09.944304,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 45 of length 66 (0 toread)
[2017/10/30 22:39:09.944347,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBunlink (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.944397,  3] ../source3/smbd/reply.c:3257(reply_unlink)
reply_unlink : .BC.B4iVrC
[2017/10/30 22:39:09.944629,  2] ../source3/smbd/open.c:1342(open_file)
made opened file .BC.B4iVrC read=No write=No (numopen=1)
[2017/10/30 22:39:09.944925,  2]
../source3/smbd/close.c:788(close_normal_file)
made closed file .BC.B4iVrC (numopen=0) NT_STATUS_OK
[2017/10/30 22:39:09.946160,  3] ../source3/smbd/process.c:1957(process_smb)
Transaction 46 of length 112 (0 toread)
[2017/10/30 22:39:09.946203,  3]
../source3/smbd/process.c:1538(switch_message)
switch message SMBtrans2 (pid 1672) conn 0x560deaead7c0
[2017/10/30 22:39:09.946228,  3]
../source3/smbd/trans2.c:2632(call_trans2findfirst)
call_trans2findfirst: dirtype = 16, maxentries = 4, close_after_first=1,
close_if_end = 1 requires_resume_key = 1 backup_priv = 0 level = 0x104,
max_data_bytes = 16644
[2017/10/30 22:39:09.946322,  3]
../source3/smbd/filename.c:1615(filename_convert_internal)
filename_convert_internal: check_name failed for name ._.BC.B4iVrC with
NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/10/30 22:39:09.946348,  3]
../source3/smbd/error.c:82(error_packet_set)
NT error packet at ../source3/smbd/trans2.c(2716) cmd=50 (SMBtrans2)
NT_STATUS_OBJECT_NAME_NOT_FOUND

Any ideas? On the server side, the share is hosted on an ext4 volume. Here
is my smb.conf (taken from `testparm -s`):

# Global parameters
[global]
log file = /var/log/samba/log.%m
max log size = 1000
syslog = 0
panic action = /usr/share/samba/panic-action %d
usershare allow guests = Yes
map to guest = Bad User
ntlm auth = Yes
obey pam restrictions = Yes
pam password change = Yes
passwd chat = *Enter\snew\s*\spassword:* %n\n *Retype\snew\s*\spassword:*
%n\n *password\supdated\ssuccessfully* .
passwd program = /usr/bin/passwd %u
server role = standalone server
unix password sync = Yes
dns proxy = No
fruit:encoding = native
idmap config * : backend = tdb
hide files = /.DS_Store/Network Trash
Folder/TheFindByContentFolder/TheVolumeSettingsFolder/Temporary
Items/.TemporaryItems/.VolumeIcon.icns/Icon?/.FBCIndex/.FBCLockFolder/
ea support = Yes
vfs objects = catia fruit streams_xattr

[homes]
comment = Home Directories
browseable = No
create mask = 0700
directory mask = 0700
valid users = %S

[printers]
comment = All Printers
path = /var/spool/samba
browseable = No
printable = Yes
create mask = 0700

[print$]
comment = Printer Drivers
path = /var/lib/samba/printers

[Files]
path = /srv/Test
guest ok = Yes
write list = made

Here are the results of ls -l /srv:

total 4
drwxrwxrwx 2 root root 4096 Oct 30 22:39 Test

Thanks
Keith