[Samba] Debug file_new then open_file_ntcreate fails with doesn't exist
Jeremy Allison
jra at samba.org
Fri Jul 16 21:25:24 UTC 2021
On Fri, Jul 16, 2021 at 01:44:17PM -0700, Matthew Schumacher via samba wrote:
>On 7/16/21 12:12 PM, Jeremy Allison wrote:
>>>
>>>Anybody see this before or thoughts on work arounds? I'm running
>>>the latest stable samba 4.14.6 in AD mode.
>>
>>We haven't seen that, it looks strange. I take it there's no
>>other application running that could race and delete ?
>>
>>Can you check the recently release 4.15.rc1 to see if it's
>>something that got fixed ? There have been *lots* of changes
>>in the pathname area between 4.14.x -> 4.15.rc1.
>
>I isolated it to make sure there wasn't a race and checked with
>smbstatus to ensure nothing else is using the share.
>
>Looks like the same issue with 4.15rc1 The create was called at
>12:23:28.127137 and the open at 12:23:28.129007 which is only 2ms
>apart.
>
>Since the samba process to service both requests is the same, it
>doesn't seem like it's a samba issue, perhaps the filesystem is slow?
>The samba server is virtualized in qemu.
>
>Any suggestions on other stuff to look at will be helpful.
>
>Matt
>
>4.15rc1 logs below:
>
>$ grep -B1 ReadOnly temp3
>[2021/07/16 12:23:28.127137, 10, pid=6697, effective(1000, 10000),
>real(1000, 0), class=smb2]
>../../source3/smbd/smb2_create.c:732(smbd_smb2_create_send)
> smbd_smb2_create_send: name [PartShare\partlib\DB2017\ReadOnlyMode.ini]
>--
>[2021/07/16 12:23:28.127166, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/filename.c:989(unix_convert)
> unix_convert: Called on file [PartShare/partlib/DB2017/ReadOnlyMode.ini]
>--
>[2021/07/16 12:23:28.127218, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/filename.c:1174(unix_convert)
> unix_convert: Begin: name
>[PartShare/partlib/DB2017/ReadOnlyMode.ini] dirpath
>[PartShare/partlib/DB2017] name [ReadOnlyMode.ini]
>[2021/07/16 12:23:28.127235, 5, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/filename.c:255(check_parent_exists)
> check_parent_exists: name =
>PartShare/partlib/DB2017/ReadOnlyMode.ini, dirpath =
>PartShare/partlib/DB2017, start = ReadOnlyMode.ini
>[2021/07/16 12:23:28.127247, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/mangle_hash2.c:413(is_mangled)
> is_mangled ReadOnlyMode.ini ?
>[2021/07/16 12:23:28.127258, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)]
>../../source3/smbd/mangle_hash2.c:352(is_mangled_component)
> is_mangled_component ReadOnlyMode.ini (len 16) ?
>[2021/07/16 12:23:28.127268, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/filename.c:863(unix_convert_step)
> unix_convert_step: dirpath [PartShare/partlib/DB2017] name
>[ReadOnlyMode.ini]
>[2021/07/16 12:23:28.127279, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)]
>../../source3/smbd/filename.c:674(unix_convert_step_stat)
> unix_convert_step_stat: smb_fname
>[PartShare/partlib/DB2017/ReadOnlyMode.ini]
>[2021/07/16 12:23:28.127293, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/mangle_hash2.c:413(is_mangled)
> is_mangled ReadOnlyMode.ini ?
>[2021/07/16 12:23:28.127304, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)]
>../../source3/smbd/mangle_hash2.c:352(is_mangled_component)
> is_mangled_component ReadOnlyMode.ini (len 16) ?
>--
>[2021/07/16 12:23:28.127637, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/mangle_hash2.c:413(is_mangled)
> is_mangled ReadOnlyMode.ini ?
>[2021/07/16 12:23:28.127649, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)]
>../../source3/smbd/mangle_hash2.c:352(is_mangled_component)
> is_mangled_component ReadOnlyMode.ini (len 16) ?
>[2021/07/16 12:23:28.127660, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)]
>../../source3/smbd/filename.c:658(unix_convert_step_search_fail)
> unix_convert_step_search_fail: New file [ReadOnlyMode.ini]
>[2021/07/16 12:23:28.127672, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/filename.c:1374(unix_convert)
> unix_convert: Conversion finished
>[PartShare/partlib/DB2017/ReadOnlyMode.ini] ->
>[PartShare/partlib/DB2017/ReadOnlyMode.ini]
>[2021/07/16 12:23:28.127686, 10, pid=6697, effective(1000, 10000),
>real(1000, 0), class=vfs]
>../../source3/smbd/vfs.c:1323(check_reduced_name)
> check_reduced_name: check_reduced_name
>[PartShare/partlib/DB2017/ReadOnlyMode.ini] [/data/shop]
>[2021/07/16 12:23:28.127715, 10, pid=6697, effective(1000, 10000),
>real(1000, 0), class=vfs]
>../../source3/smbd/vfs.c:1388(check_reduced_name)
> check_reduced_name realpath
>[PartShare/partlib/DB2017/ReadOnlyMode.ini] ->
>[/data/shop/PartShare/partlib/DB2017/ReadOnlyMode.ini]
>[2021/07/16 12:23:28.127729, 5, pid=6697, effective(1000, 10000),
>real(1000, 0), class=vfs]
>../../source3/smbd/vfs.c:1493(check_reduced_name)
> check_reduced_name: PartShare/partlib/DB2017/ReadOnlyMode.ini
>reduced to /data/shop/PartShare/partlib/DB2017/ReadOnlyMode.ini
>[2021/07/16 12:23:28.127741, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)]
>../../source3/smbd/filename.c:2027(filename_convert_internal)
> filename_convert_internal:
>[PartShare/partlib/DB2017/ReadOnlyMode.ini] does not exist, skipping
>pathref fsp
>[2021/07/16 12:23:28.127755, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/open.c:6118(create_file_default)
> create_file_default: create_file: access_mask = 0x80 file_attributes
>= 0x0, share_access = 0x7, create_disposition = 0x1 create_options =
>0x200000 oplock_request = 0x0 private_flags = 0x0 ea_list = (nil), sd
>= (nil), fname = PartShare/partlib/DB2017/ReadOnlyMode.ini
>[2021/07/16 12:23:28.127770, 10, pid=6697, effective(1000, 10000),
>real(1000, 0)] ../../source3/smbd/open.c:5549(create_file_unixpath)
> create_file_unixpath: create_file_unixpath: access_mask = 0x80
>file_attributes = 0x0, share_access = 0x7, create_disposition = 0x1
>create_options = 0x200000 oplock_request = 0x0 private_flags = 0x0
>ea_list = (nil), sd = (nil), fname =
>PartShare/partlib/DB2017/ReadOnlyMode.ini
Oh hang on a minute. Look at that create_disposition = 0x1.
This means:
#define FILE_OPEN 1 /* File exists open. File not exist fail. */
So smbd is doing the right thing here. To create
a new file, create_disposition must be one of either:
#define FILE_CREATE 2 /* File exists fail. File not exist create. */
#define FILE_OPEN_IF 3 /* File exists open. File not exist create. */
#define FILE_OVERWRITE_IF 5 /* File exists overwrite. File not exist create. */
More information about the samba
mailing list