Bug 15247 - Permission denied when trying to delete file from android clients (gvfs?)
Summary: Permission denied when trying to delete file from android clients (gvfs?)
Status: CLOSED WORKSFORME
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: libsmbclient (show other bugs)
Version: 4.17.2
Hardware: x64 Linux
: P5 normal (vote)
Target Milestone: ---
Assignee: Jeremy Allison
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2022-11-18 06:13 UTC by RC Bosworth
Modified: 2022-12-07 23:59 UTC (History)
1 user (show)

See Also:


Attachments
Wireshark capture of android client (9.53 KB, application/octet-stream)
2022-11-22 04:57 UTC, RC Bosworth
no flags Details
Level 10 samba server log (130.22 KB, text/plain)
2022-11-22 04:57 UTC, RC Bosworth
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description RC Bosworth 2022-11-18 06:13:50 UTC
Most android file managers are failing to delete files after upgrade to 14.7.x   This was captured using Solid Explorer but most others are failing the same way.

Single files will result in a permission denied error (but will still be deleted.)

Multiple files/dirs will fail immediately after permission denied error.

I believe this is related to gvfs libs being used client side but something changed in 14.7.0 and seems related to bug #15195 which is very similar (but resolved in 14.7.2)  This bug remains outstanding.

I'm new to wireshark -- is there a best way to export the pcap file with the relevant information?

Server log: 
smbd[1668]: [2022/11/16 02:43:00.249990,  0] ../../source3/smbd/server.c:1741(main)
smbd[1668]:   smbd version 4.17.2 started.
smbd[1668]:   Copyright Andrew Tridgell and the Samba Team 1992-2022
nmbd[1673]: [2022/11/16 02:43:00.283325,  0] ../../source3/nmbd/nmbd.c:901(main)
nmbd[1673]:   nmbd version 4.17.2 started.
nmbd[1673]:   Copyright Andrew Tridgell and the Samba Team 1992-2022
...
smbd[22786]: [2022/11/17 00:15:38.152578,  2] ../../source3/smbd/open.c:1678(open_file)
admin opened file SERVER/FOO/file.mkv read=No write=No (numopen=2)
smbd[22786]: [2022/11/17 00:15:38.167282,  3] ../../source3/smbd/smb2_trans2.c:6834(smbd_do_setfilepathinfo)
smbd[22786]:   smbd_do_setfilepathinfo: file SERVER/FOO/file.mkv (fnum 1321203594) info_level=1013 totdata=1
smbd[22786]: [2022/11/17 00:15:38.175453,  2] ../../source3/smbd/close.c:830(close_normal_file)
smbd[22786]:   admin closed file file SERVER/FOO/file.mkv (numopen=0) NT_STATUS_ACCESS_DENIED
smbd[22786]:   smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at ../../source3/smbd/smb2_close.c:111
status[NT_STATUS_ACCESS_DENIED]Nov 17 00:15:38 Hippo  smbd[22786]: [2022/11/17 00:15:38.175530,  3] ../../source3/smbd/smb2_server.c:3955(smbd_smb2_request_error_ex)


Wireshark:
Negotiate Protocol Request
Negotiate Protocol Response
Session Setup Request, NTLMSSP_NEGOTIATE
Session Setup Response, Error: STATUS_MORE_PROCESSING_REQUIRED, NTLMSSP_CHALLENGE
Session Setup Request, NTLMSSP_AUTH, User: \\admin
Session Setup Response
Tree Connect Request Tree: \\\\192.168.1.10\\media
Tree Connect Response
Create Request File: 
Create Response File: 
Find Request File:  SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response
Find Request File:  SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response, Error: STATUS_NO_MORE_FILES
Close Request File: 
Close Response
Create Request File: SERVER
Create Response File: SERVER
Find Request File: SERVER SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response
Find Request File: SERVER SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response, Error: STATUS_NO_MORE_FILES
Close Request File: SERVER
Close Response
Create Request File: SERVER\\FOO
Create Response File: SERVER\\FOO
Find Request File: SERVER\\FOO SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response
Find Request File: SERVER\\FOO SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response, Error: STATUS_NO_MORE_FILES
Close Request File: SERVER\\FOO
Close Response
Create Request File: SERVER\\FOO\\banner.jpg
Create Response File: SERVER\\FOO\\banner.jpg
SetInfo Request FILE_INFO/SMB2_FILE_DISPOSITION_INFO File: SERVER\\FOO\\banner.jpg
SetInfo Response
Close Request File: SERVER\\FOO\\banner.jpg
Close Response, Error: STATUS_ACCESS_DENIED
Create Request File: SERVER\\FOO\\Folder
Create Response File: SERVER\\FOO\\Folder
Find Request File: SERVER\\FOO\\Folder SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response
Find Request File: SERVER\\FOO\\Folder SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response, Error: STATUS_NO_MORE_FILES
Close Request File: SERVER\\FOO\\Folder
Close Response
Create Request File: SERVER\\FOO\\Folder
Create Response File: SERVER\\FOO\\Folder
Find Request File: SERVER\\FOO\\Folder SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response
Find Request File: SERVER\\FOO\\Folder SMB2_FIND_ID_BOTH_DIRECTORY_INFO Pattern: *
Find Response, Error: STATUS_NO_MORE_FILES
Close Request File: SERVER\\FOO\\Folder
Close Response
Create Request File: SERVER\\FOO\\Folder\\File.mkv
Create Response File: SERVER\\FOO\\Folder\\File.mkv
SetInfo Request FILE_INFO/SMB2_FILE_DISPOSITION_INFO File: SERVER\\FOO\\Folder\\File.mkv
SetInfo Response
Close Request File: SERVER\\FOO\\Folder\\File.mkv
Close Response, Error: STATUS_ACCESS_DENIED
Comment 1 Jeremy Allison 2022-11-21 19:04:28 UTC
This is the "delete file" pattern:

Create Request File: SERVER\\FOO\\Folder\\File.mkv
Create Response File: SERVER\\FOO\\Folder\\File.mkv
SetInfo Request FILE_INFO/SMB2_FILE_DISPOSITION_INFO File: SERVER\\FOO\\Folder\\File.mkv
SetInfo Response
Close Request File: SERVER\\FOO\\Folder\\File.mkv
Close Response, Error: STATUS_ACCESS_DENIED

Which is correct, so it looks like the client libraries are doing the right thing.

Seems the server check for SetInfo (set file disposition "delete-on-close" is succeeding) but then an error occurs when actually trying to delete the file.

There could be lots of reasons for this, usually the logged on user not having the correct permissions in the target directory.

We really need a wireshark trace on TCP port 445 combined with an smbd debug level 10 trace to make progress on this, sorry.
Comment 2 RC Bosworth 2022-11-22 04:57:14 UTC
Created attachment 17667 [details]
Wireshark capture of android client
Comment 3 RC Bosworth 2022-11-22 04:57:45 UTC
Created attachment 17668 [details]
Level 10 samba server log
Comment 4 RC Bosworth 2022-11-22 05:00:11 UTC
(In reply to Jeremy Allison from comment #1)

Thanks for following up.  I've uploaded the wireshark capture as well as the level 10 log.

The odd behavior is that the server is actually deleting the file -- but it's responding with an ACCESS DENIED error that the client then reports that the operation failed.
Comment 5 Jeremy Allison 2022-11-22 17:12:34 UTC
I'm out on vacation until December 5th, so I'll have to follow-up after that. Thanks for the info !
Comment 6 Jeremy Allison 2022-12-07 00:41:55 UTC
OK, finally got time to look at this. The client is doing an SMB2_CREATE (requesting delete access) on temp2\temp.txt, setting the delete-on-close bit and then closing the file, at which time the reply to the client is ACCESS_DENIED.

What are the permissions for the user "admin" in the directory temp2 and on the file temp2\temp.txt in the share ?
Comment 7 Jeremy Allison 2022-12-07 00:43:00 UTC
smbd will check if the client has permission to delete the file at SETINFO time so it can tell the client ACCESS_DENIED on the setinfo request (that's what Windows clients expect). Somehow this calculation is not correct.
Comment 8 Jeremy Allison 2022-12-07 00:47:38 UTC
There's also a server crash in the logs, which certainly should not happen.

Nov 21 22:26:51 Hippo  smbd[5707]:   admin closed file temp2/temp.txt (numopen=0) NT_STATUS_INVALID_PARAMETER
Nov 21 22:26:51 Hippo  smbd[5706]: [2022/11/21 22:26:51.942943,  5, pid=5706, effective(0, 0), real(0, 0)] ../../source3/smbd/uid.c:494(smbd_change_to_root_user)
Nov 21 22:26:51 Hippo  smbd[5706]:   change_to_root_user: now uid=(0,0) gid=(0,0)
Nov 21 22:26:51 Hippo  smbd[5707]: [2022/11/21 22:26:51.942948,  0, pid=5707, effective(0, 0), real(0, 0)] ../../source3/smbd/fd_handle.c:39(fd_handle_destructor)
Nov 21 22:26:51 Hippo  smbd[5707]:   PANIC: assert failed at ../../source3/smbd/fd_handle.c(39): (fh->fd == -1) || (fh->fd == AT_FDCWD)
Nov 21 22:26:51 Hippo  smbd[5706]: [2022/11/21 22:26:51.942971,  5, pid=5706, effective(0, 0), real(0, 0)] ../../lib/dbwrap/dbwrap.c:143(dbwrap_lock_order_lock)
Nov 21 22:26:51 Hippo  smbd[5706]:   dbwrap_lock_order_lock: check lock order 1 for /var/cache/samba/smbXsrv_tcon_global.tdb

Can you tell me the exact version of Samba you are running, and also post your smb.conf please ?
Comment 9 RC Bosworth 2022-12-07 01:13:28 UTC
(In reply to Jeremy Allison from comment #8)
Thanks for looking into this!

admin is the user that created both that directory and file, so I would expect ownership is not an issue:

drwxrwxrwx 1 admin  users  30 Dec  6 19:09 temp2/
-rw-rw-rw- 1 admin  users  0 Dec  6 19:09 temp.txt

root@Hippo:~# smbstatus

Samba version 4.17.3



root@Hippo:~# cat /etc/samba/smb.conf
[global]
        # configurable identification
        include = /etc/samba/smb-names.conf

        # log stuff only to syslog
        logging = syslog@0

        # we don't do printers
        show add printer wizard = No
        disable spoolss = Yes
        load printers = No
        printing = bsd
        printcap name = /dev/null

        # disable aio by default
        aio read size = 0
        aio write size = 0

        # misc.
        invalid users = root
        unix extensions = No
        wide links = Yes
        use sendfile = Yes

        # ease upgrades from Samba 3.6
        acl allow execute always = Yes
        # permit NTLMv1 authentication
        ntlm auth = Yes

        # default global fruit settings:
        #fruit:aapl = Yes
        #fruit:nfs_aces = Yes
        fruit:nfs_aces = No
        #fruit:copyfile = No
        #fruit:model = MacSamba

        # hook for user-defined samba config
        include = /boot/config/smb-extra.conf

[global]
        # hook for unassigned devices shares
        include = /etc/samba/smb-unassigned.conf

        # auto-configured shares
        include = /etc/samba/smb-shares.conf
Comment 10 Jeremy Allison 2022-12-07 01:40:57 UTC
Well there's something very strange about that area of the filesystem. smbd checks (correctly) that it can delete the file, but then fails when actually trying to do it. Is this an NFS re-exported mount ?

This doesn't look like an smbclient issue. Can you delete this file from a Windows client ?
Comment 11 RC Bosworth 2022-12-07 02:44:42 UTC
(In reply to Jeremy Allison from comment #10)

Not a re-export or anything especially weird.

Windows works just fine as does other Linux clients.  This seems to be isolated to most (all?) android clients and did not exist before 14.7.x

And to be clear -- the ACCESS DENIED error is returned but the file is actually deleted (which seems to rule out permission/ownership issues?)
Comment 12 Jeremy Allison 2022-12-07 02:50:08 UTC
Can you upload a wireshark trace of a Linux client deleting the same file please 
 (and the smbd debug 10 log) ? I'd love to compare the failing trace with a working trace.
Comment 13 Jeremy Allison 2022-12-07 02:52:33 UTC
Oh. That smb.conf isn't complete.

It does:

include = /etc/samba/smb-shares.conf

so I'll need to see the contents of smb-shares.conf also in case there's some extra "vfs objects =" in there.
Comment 14 Jeremy Allison 2022-12-07 02:54:26 UTC
Tomorrow I'll try reproducing by deleting files from a local share using my android phone. My favourite SMB file manager app is Cx File Explorer. Can you confirm that is also causing problems for you ?
Comment 15 RC Bosworth 2022-12-07 03:05:06 UTC
[incoming]
        path = /mnt/user/incoming
        comment = 
        browseable = yes
        # Public
        public = yes
        writeable = yes
        case sensitive = auto
        preserve case = yes
        short preserve case = yes

CX File Explorer is working as expected -- no access denied error.
Comment 16 Jeremy Allison 2022-12-07 03:11:43 UTC
OK, I just did a quick test using Cx File Explorer to current master Samba, and I can delete a file without problems.

I just downloaded Solid Explorer, but I don't see how to make it talk to SMB shares ? Don't tell me to buy the full version if that's what I need to connect to SMB shares 'cos I'm not going to do that :-).
Comment 17 Jeremy Allison 2022-12-07 03:16:23 UTC
Never mind, I figured out how to make Solid Explorer connect and it works fine deleting a file against git master.

I'll try tomorrow against the v4-17-test tree and see if it fails locally.
Comment 18 Jeremy Allison 2022-12-07 20:31:59 UTC
OK, I've checked with Solid Explorer against v4-17-test tree and all works. No ACCESS_DENIED or crash issues.

I can't reproduce this at all.

Is this a self-compiled smbd server ? Or is it a vendor supplied binary ?
Comment 19 RC Bosworth 2022-12-07 23:01:05 UTC
Vendor supplied.  Included with Unraid (which is slackware based.)

I can open a port and send you ip/login information if it would be helpful?  jra@samba.org?
Comment 20 Jeremy Allison 2022-12-07 23:59:02 UTC
Sorry. It looks like your vendor has messed up the port of 4.17 (especially as smbd is crashing). You'll have to contact them directly. If you can reproduce with a "stock" Samba 4.17 then I'll take a look again but in the meantime I'm going to have to close this.