Bug 14685 - Log clutter from filename_convert_internal()
Summary: Log clutter from filename_convert_internal()
Status: RESOLVED FIXED
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: File services (show other bugs)
Version: unspecified
Hardware: All All
: P5 normal (vote)
Target Milestone: ---
Assignee: Jule Anger
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-04-06 12:45 UTC by Ralph Böhme
Modified: 2021-10-18 09:29 UTC (History)
3 users (show)

See Also:


Attachments
untested and uncompiled :-) patch. (1.06 KB, patch)
2021-10-07 18:23 UTC, Jeremy Allison
no flags Details
git-am fix for 4.15.next. (1.87 KB, patch)
2021-10-12 19:46 UTC, Jeremy Allison
slow: review+
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Ralph Böhme 2021-04-06 12:45:13 UTC
From the mailing list

I have a Debian Buster member server which I upgraded to version 4.14.0 and since then I have been getting several log messages like this one in syslog:

Mar 13 10:33:34 lxd-m1 smbd[1406]: filename_convert_internal: open_pathref_fsp [roy] failed: NT_STATUS_ACCESS_DENIED

Have patch, need bugnumber.
Comment 1 Samba QA Contact 2021-04-06 14:40:03 UTC
This bug was referenced in samba master:

11aac9d0433ab59740c40712c3782f1cf4ac0418
Comment 2 Peter Eriksson 2021-10-06 20:37:25 UTC
Any progress on this veeeery important bug^H^H^Hannoying thing? :-)
Comment 3 Jeremy Allison 2021-10-06 20:51:32 UTC
Fixed in 4.15.0. Do you need a back-port for 4.14.next ?
Comment 4 Peter Eriksson 2021-10-07 14:23:30 UTC
(In reply to Jeremy Allison from comment #3)

Hmm.. I thought I saw these messages yesterday when I was watching some log files, but it might just have been an older 4.14-smbd generating those because when I'm looking now I'm not finding them. Upgraded all to 4.15.0 last night.


Anyway, now I'm seeing a gazillion of these instead :-)

[2021/10/07 16:19:15.134007,  0] ../../source3/smbd/fd_handle.c:92(fsp_get_io_fd)
  fsp_get_io_fd: fsp [bkv] is a path referencing fsp
Comment 5 Ralph Böhme 2021-10-07 14:46:52 UTC
(In reply to Peter Eriksson from comment #4)
This is bad, very bad. I'd expect your users should not be able to use Samba given this error.

Can you add a call to log_stack_trace() to the source so I can see what is triggering this?
Comment 6 Peter Eriksson 2021-10-07 17:45:33 UTC
That it's supposed to not work is a bit surprising considering nobody has screamed bloody murder all day, and some 3000-4000 users are connected, and all my automated SMB connection tests are running just fine (some 10 probe hosts that from various places around the university tests all file servers every minute 24/7 both with Kerberos and password logins + creates a directory + removes it)... :-)

Anyway, I'll add that on our test server...
Comment 7 Peter Eriksson 2021-10-07 18:01:46 UTC
[2021/10/07 19:53:19.442289,  0] ../../lib/util/fault.c:245(log_stack_trace)
  BACKTRACE:
   #0 log_stack_trace + 0x2e [ip=0x801b4f1b7] [sp=0x7fffffffd0d0]
   #1 fsp_get_io_fd + 0x17 [ip=0x8016a7212] [sp=0x7fffffffd990]
   #2 zfsacl_fget_nt_acl + 0x86 [ip=0x8126aeb9f] [sp=0x7fffffffd9a0]
   #3 smb_vfs_call_fget_nt_acl + 0x29 [ip=0x801727dfd] [sp=0x7fffffffdaf0]
   #4 check_parent_access_fsp + 0x74 [ip=0x801714a64] [sp=0x7fffffffdb00]
   #5 mkdir_internal + 0x6f [ip=0x801714f89] [sp=0x7fffffffdb70]
   #6 open_directory + 0x365 [ip=0x801718a5c] [sp=0x7fffffffdbd0]
   #7 create_file_unixpath + 0x553 [ip=0x80171987b] [sp=0x7fffffffdcb0]
   #8 create_file_default + 0x28c [ip=0x80171d255] [sp=0x7fffffffdf40]
   #9 vfswrap_create_file + 0x35 [ip=0x80180e031] [sp=0x7fffffffe0c0]
   #10 smb_vfs_call_create_file + 0x59 [ip=0x801724930] [sp=0x7fffffffe130]
   #11 smb_full_audit_create_file + 0x74 [ip=0x8124a3dbb] [sp=0x7fffffffe1a0]
   #12 smb_vfs_call_create_file + 0x59 [ip=0x801724930] [sp=0x7fffffffe240]
   #13 smbd_smb2_request_process_create + 0x1238 [ip=0x801756fe3] [sp=0x7fffffffe2b0]
   #14 smbd_smb2_request_dispatch + 0x12b4 [ip=0x80174d1c9] [sp=0x7fffffffe400]
   #15 smbd_smb2_connection_handler + 0x685 [ip=0x80174dea1] [sp=0x7fffffffe4b0]
   #16 tevent_common_invoke_fd_handler + 0x96 [ip=0x80260c82d] [sp=0x7fffffffe550]
   #17 poll_event_loop_once + 0x5b8 [ip=0x80260f00f] [sp=0x7fffffffe580]
   #18 _tevent_loop_once + 0x9b [ip=0x80260bde4] [sp=0x7fffffffe5e0]
   #19 tevent_common_loop_wait + 0x2a [ip=0x80260bfd7] [sp=0x7fffffffe620]
   #20 _tevent_loop_wait + 0xa [ip=0x80260c039] [sp=0x7fffffffe650]
   #21 smbd_process + 0x973 [ip=0x80173afab] [sp=0x7fffffffe660]
   #22 smbd_accept_connection + 0x1fa [ip=0x102e7c2] [sp=0x7fffffffe700]
   #23 tevent_common_invoke_fd_handler + 0x96 [ip=0x80260c82d] [sp=0x7fffffffe7f0]
   #24 poll_event_loop_once + 0x5b8 [ip=0x80260f00f] [sp=0x7fffffffe820]
   #25 _tevent_loop_once + 0x9b [ip=0x80260bde4] [sp=0x7fffffffe880]
   #26 tevent_common_loop_wait + 0x2a [ip=0x80260bfd7] [sp=0x7fffffffe8c0]
   #27 _tevent_loop_wait + 0xa [ip=0x80260c039] [sp=0x7fffffffe8f0]
   #28 main + 0x2105 [ip=0x1030a49] [sp=0x7fffffffe900]
   #29 _start + 0xe2 [ip=0x1028622] [sp=0x7fffffffec90]
   #30 <unknown symbol> [ip=0x801265000] [sp=0x7fffffffecd0]
[2021/10/07 19:53:19.557837,  0] ../../lib/util/fault.c:245(log_stack_trace)
  BACKTRACE:
   #0 log_stack_trace + 0x2e [ip=0x801b4f1b7] [sp=0x7fffffffd120]
   #1 fsp_get_io_fd + 0x17 [ip=0x8016a7212] [sp=0x7fffffffd9e0]
   #2 zfsacl_fget_nt_acl + 0x86 [ip=0x8126aeb9f] [sp=0x7fffffffd9f0]
   #3 smb_vfs_call_fget_nt_acl + 0x29 [ip=0x801727dfd] [sp=0x7fffffffdb40]
   #4 smbd_check_access_rights_fsp + 0xcc [ip=0x801714391] [sp=0x7fffffffdb50]
   #5 open_directory + 0xa78 [ip=0x80171916f] [sp=0x7fffffffdbd0]
   #6 create_file_unixpath + 0x553 [ip=0x80171987b] [sp=0x7fffffffdcb0]
   #7 create_file_default + 0x28c [ip=0x80171d255] [sp=0x7fffffffdf40]
   #8 vfswrap_create_file + 0x35 [ip=0x80180e031] [sp=0x7fffffffe0c0]
   #9 smb_vfs_call_create_file + 0x59 [ip=0x801724930] [sp=0x7fffffffe130]
   #10 smb_full_audit_create_file + 0x74 [ip=0x8124a3dbb] [sp=0x7fffffffe1a0]
   #11 smb_vfs_call_create_file + 0x59 [ip=0x801724930] [sp=0x7fffffffe240]
   #12 smbd_smb2_request_process_create + 0x1238 [ip=0x801756fe3] [sp=0x7fffffffe2b0]
   #13 smbd_smb2_request_dispatch + 0x12b4 [ip=0x80174d1c9] [sp=0x7fffffffe400]
   #14 smbd_smb2_connection_handler + 0x685 [ip=0x80174dea1] [sp=0x7fffffffe4b0]
   #15 tevent_common_invoke_fd_handler + 0x96 [ip=0x80260c82d] [sp=0x7fffffffe550]
   #16 poll_event_loop_once + 0x5b8 [ip=0x80260f00f] [sp=0x7fffffffe580]
   #17 _tevent_loop_once + 0x9b [ip=0x80260bde4] [sp=0x7fffffffe5e0]
   #18 tevent_common_loop_wait + 0x2a [ip=0x80260bfd7] [sp=0x7fffffffe620]
   #19 _tevent_loop_wait + 0xa [ip=0x80260c039] [sp=0x7fffffffe650]
   #20 smbd_process + 0x973 [ip=0x80173afab] [sp=0x7fffffffe660]
   #21 smbd_accept_connection + 0x1fa [ip=0x102e7c2] [sp=0x7fffffffe700]
   #22 tevent_common_invoke_fd_handler + 0x96 [ip=0x80260c82d] [sp=0x7fffffffe7f0]
   #23 poll_event_loop_once + 0x5b8 [ip=0x80260f00f] [sp=0x7fffffffe820]
   #24 _tevent_loop_once + 0x9b [ip=0x80260bde4] [sp=0x7fffffffe880]
   #25 tevent_common_loop_wait + 0x2a [ip=0x80260bfd7] [sp=0x7fffffffe8c0]
   #26 _tevent_loop_wait + 0xa [ip=0x80260c039] [sp=0x7fffffffe8f0]
   #27 main + 0x2105 [ip=0x1030a49] [sp=0x7fffffffe900]
   #28 _start + 0xe2 [ip=0x1028622] [sp=0x7fffffffec90]
   #29 <unknown symbol> [ip=0x801265000] [sp=0x7fffffffecd0]


Hmm.. It seems it's my Nagios check that provokes the warning, not my other automated tests. Hmm. I wonder what's different there... 

The nagios plugin script does:

TESTCMDS="mkdir nagios_test$$ ; rmdir nagios_test$$"
smbclient -c "$CDSUBDIR $TESTCMDS" -m "$MAXPROT" $AUTHARGS "//${HOST}/${SHARE}"

And it generated this log line:
  fsp_get_io_fd: fsp [nagios_test31582] is a path referencing fsp
Comment 8 Jeremy Allison 2021-10-07 18:12:51 UTC
Is this on a Linux + ZFS ? Or Solaris ? The Linux ACL code expects you can get/set ACLs on a pathref fsp (open with O_PATH). Looks like the ZFS module wants to use a io fsp for this.

What does the man page for facl() on your system say about the permissions on the file descriptor needed to fetch an ACL from an fd ?
Comment 9 Peter Eriksson 2021-10-07 18:22:06 UTC
FreeBSD, so no facl(). 

From "man acl":

NAME
     acl_get_fd, acl_get_fd_np, acl_get_file, acl_get_link_np – get an ACL for
     a file

LIBRARY
     Standard C Library (libc, -lc)

SYNOPSIS
     #include <sys/types.h>
     #include <sys/acl.h>

     acl_t
     acl_get_fd(int fd);

     acl_t
     acl_get_fd_np(int fd, acl_type_t type);

     acl_t
     acl_get_file(const char *path_p, acl_type_t type);

     acl_t
     acl_get_link_np(const char *path_p, acl_type_t type);
Comment 10 Peter Eriksson 2021-10-07 18:22:46 UTC
FreeBSD 12.1 + ZFS to be exact.
Comment 11 Jeremy Allison 2021-10-07 18:23:57 UTC
Created attachment 16839 [details]
untested and uncompiled :-) patch.

Hmmm. If we look at the Solaris man page here:

http://software.cfht.hawaii.edu/man/solaris/facl(2)

is says:

GETACL
Buffer aclbufp is filled with the file’s ACL entries. Read access to the file is not required, but all directories in the path name must be searchable.

which implies that a O_PATH file descriptor should be sufficient to get an ACL entry.

Can you try the following (untested and uncompiled as I don't have a system with ZFS acls) patch ?
Comment 12 Jeremy Allison 2021-10-07 18:26:39 UTC
(In reply to Peter Eriksson from comment #10)

On FreeBSD without O_PATH, we'll open a pathref fsp as root, so the patch I posted should Just Work (tm :-).

If FreeBSD has O_PATH, it depends on whether the O_PATH open allows ACL get/set or not.

I'm CC:ing Samba Team member Andrew Walker <awalker@ixsystems.com> as I know he will know more about this !
Comment 13 Andrew Walker 2021-10-07 18:51:06 UTC
Sorry, I've been out of loop for a while. Overloaded with work. 

I'll try to revisit the MR for O_PATH support next week. FreeBSD 13 kernel should have what we need. Just need to validate the work on it again since it probably bit-rotted.
Comment 14 Andrew Walker 2021-10-07 18:51:41 UTC
What version of libsunacl is this?
Comment 15 Jeremy Allison 2021-10-07 18:52:08 UTC
Ah, OK - if there's no O_PATH inside FreeBSD then we should open the pathref fsp's as root and my patch should "Just.Work" (tm:-).
Comment 16 Peter Eriksson 2021-10-07 18:57:08 UTC
That patch seems to work fine. Not more complaints in the log.

I'm not sure what the difference is for an end user though - both a patched and an unpatched samba seems to be able to retrieve the ACL?

(filur00 = patched 4.15.0, filur04 = unpatched 4.15.0)


$ smbcacls -k //filur00/peter86 Documents
REVISION:1
CONTROL:SR|DP
OWNER:AD\peter86
GROUP:AD\employee-liu.se
ACL:AD\peter86:ALLOWED/I/FULL
ACL:Creator Owner:ALLOWED/OI|CI|IO|I/FULL
ACL:AD\employee-liu.se:ALLOWED/I/0x00120088
ACL:Creator Group:ALLOWED/OI|CI|IO|I/0x00120088
ACL:Everyone:ALLOWED/OI|CI|I/0x00120088

$ smbcacls -k //filur04/peter86 Documents
REVISION:1
CONTROL:SR|PD|DP
OWNER:AD\peter86
GROUP:AD\employee-liu.se
ACL:AD\peter86:ALLOWED/0x0/FULL
ACL:Creator Owner:ALLOWED/OI|CI|IO/FULL
ACL:AD\employee-liu.se:ALLOWED/0x0/0x00120088
ACL:Everyone:ALLOWED/0x0/0x00120088

root@filur00# lac Documents/
# file: Documents/
# owner: peter86
# group: employee-liu.se
           owner@:rwxpDdaARWcCos:fd----I:allow
           group@:------a-R-c--s:fd----I:allow
        everyone@:------a-R-c--s:fd----I:allow

root@filur04# lac Documents/
# file: Documents/
# owner: peter86
# group: employee-liu.se
           owner@:rwxpDdaARWcCo-:fd-----:allow
           group@:------a-R-c--s:-------:allow
        everyone@:------a-R-c--s:-------:allow
Comment 17 Andrew Walker 2021-10-07 18:58:40 UTC
O_PATH should be in FreeBSD 13. Part that's missing is just plumbing in samba to use the fdescfs mount.

acl/facl are provided by sysutils/libsunacl port in FreeBSD.
Comment 18 Jeremy Allison 2021-10-07 19:09:37 UTC
For a FreeBSD without O_PATH there will be no difference.

What is happening is without O_PATH being available on FreeBSD, opening a pathref fsp for NTACL get/set is being done as root.

Obviously it is VITALLY IMPORTANT that a pathref fsp (a root fd) is NOT USED ACCIDENTALLY FOR ANY I/O :-).

The bug is in the source3/modules/vfs_zfsacl.c code that expects to be given an IO fsp, whereas it's actually being given a pathref fsp. The code in source3/smbd/fd_handle.c has:

int fsp_get_io_fd(const struct files_struct *fsp)
{
        if (fsp->fsp_flags.is_pathref) {
                DBG_ERR("fsp [%s] is a path referencing fsp\n",
                        fsp_str_dbg(fsp));
#ifdef DEVELOPER
                smb_panic("fsp is a pathref");
#endif
                return -1;
        }

        return fsp->fh->fd;
}

Note if you'd compiled with developer it would panic smbd rather than handing back a pathref fsp when asked for an io fsp. That's what Ralph meant when he said "This is bad, very bad. I'd expect your users should not be able to use Samba given this error." - meaning it would panic.

Without #ifdef DEVELOPER it just bitterly complains every time a pathref fsp is used in place of an IO fsp.

My patch simply fixes vfs_zfsacl.c to expect a pathref fsp and not an io fsp, and leave the checking of whether we have permissions to get/set the ACL to the SMB2 handle open code.
Comment 19 Jeremy Allison 2021-10-11 21:31:44 UTC
MR: https://gitlab.com/samba-team/samba/-/merge_requests/2200
Comment 20 Samba QA Contact 2021-10-12 18:15:03 UTC
This bug was referenced in samba master:

0a376b23dbaaec551d0ed48b7098129c09eec1bc
Comment 21 Jeremy Allison 2021-10-12 19:46:03 UTC
Created attachment 16847 [details]
git-am fix for 4.15.next.

Cherry-picked from master.
Comment 22 Ralph Böhme 2021-10-13 17:24:32 UTC
Reassigning to Jule for inclusion in 4.15.
Comment 23 Jule Anger 2021-10-18 07:20:08 UTC
Pushed to autobuild-v4-15-test.
Comment 24 Samba QA Contact 2021-10-18 09:08:04 UTC
This bug was referenced in samba v4-15-test:

dffca59ded19f39af7302ce6a42cbdfb06751486
Comment 25 Jule Anger 2021-10-18 09:29:28 UTC
Closing out bug report.

Thanks!