Andrew Gunnerson
2024-Nov-26 22:03 UTC
[Samba] Random EINVAL when opening files with SMB3 POSIX extensions enabled
Hello! I recently tried enabling SMB3 POSIX extensions as I'm only using Linux clients and would like to make use of the standard unix permission bits. However, I'm running into an issue where a simple `cat` fails with -EINVAL when opening the file: openat(AT_FDCWD, "Shells.txt", O_RDONLY) = -1 EINVAL (Invalid argument) The weird thing is that it's intermittent. It'll fail with EINVAL many times in a row and then suddenly work and then start failing again. When it fails, I see a message like this in the client's dmesg: [ 4295.972953] CIFS: enabling forceuid mount option implicitly because uid= option is specified [ 4295.972958] CIFS: enabling forcegid mount option implicitly because gid= option is specified [ 4295.972961] CIFS: Attempting to mount //sm-1.int.chiller3.com/home/Documents/Notes/Linux/Shells.txt [ 4295.974221] CIFS: VFS: cifs_mount failed w/return code = -22 (The `log level = 3` samba logs are included at the end of this email.) If I turn off SMB3 POSIX extensions, then this issue never occurs. On the server side, there isn't really anything special. There are only the standard Unix owner/group/mode set. The file in question and all parent directories have no POSIX ACLs nor NTACL xattrs. My server configuration is: [global] workgroup = SAMBA security = user passdb backend = tdbsam printing = cups printcap name = cups load printers = yes cups options = raw store dos attributes = no server min protocol = SMB2 server smb encrypt = desired use sendfile = yes vfs objects = recycle recycle:keeptree = yes recycle:versions = yes ea support = no smb3 unix extensions = yes log level = 3 [home] path = %H read only = no recycle:exclude = *, *.* # Other shares omitted Both the client and server are running Fedora 41 with: kernel-6.11.8-300.fc41.x86_64 cifs-utils-7.1-2.fc41.x86_64 samba-4.21.1-7.fc41.x86_64 The client mounts the share with the following fstab entry: //sm-1.int.chiller3.com/home /media/sm-1/home cifs nofail,credentials=/etc/samba/credentials/sm-1,uid=chenxiaolong,gid=chenxiaolong,posix,x-systemd.automount 0 0 Does anyone have any suggestions for how to troubleshoot this? I'm not quite sure if this issue is in the client's cifs.ko or in Samba. While I'm not familiar with either codebase nor the SMB protocol, I can definitely apply patches, add additional logging statements, etc. to try and help figure this out. Thanks! Andrew ==> log.smbd <=[2024/11/26 16:02:01.530148, 2] ../../source3/smbd/open.c:1614(open_file) chenxiaolong opened file Documents/Notes/Linux/Shells.txt read=No write=No (numopen=2) [2024/11/26 16:02:01.536920, 2] ../../source3/smbd/close.c:924(close_normal_file) chenxiaolong closed file Documents/Notes/Linux/Shells.txt (numopen=1) NT_STATUS_OK [2024/11/26 16:02:01.537483, 2] ../../source3/smbd/open.c:1614(open_file) chenxiaolong opened file Documents/Notes/Linux/Shells.txt read=No write=No (numopen=2) [2024/11/26 16:02:01.537520, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_NOT_A_REPARSE_POINT] || at ../../source3/smbd/smb2_ioctl.c:355 [2024/11/26 16:02:01.537531, 2] ../../source3/smbd/close.c:924(close_normal_file) chenxiaolong closed file Documents/Notes/Linux/Shells.txt (numopen=1) NT_STATUS_OK [2024/11/26 16:02:01.537673, 2] ../../source3/smbd/open.c:1614(open_file) chenxiaolong opened file Documents/Notes/Linux/Shells.txt read=No write=No (numopen=2) [2024/11/26 16:02:01.537710, 2] ../../source3/smbd/close.c:924(close_normal_file) chenxiaolong closed file Documents/Notes/Linux/Shells.txt (numopen=1) NT_STATUS_OK [2024/11/26 16:02:01.537842, 2] ../../source3/smbd/open.c:1614(open_file) chenxiaolong opened file Documents/Notes/Linux/Shells.txt read=No write=No (numopen=2) [2024/11/26 16:02:01.537862, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_NOT_A_REPARSE_POINT] || at ../../source3/smbd/smb2_ioctl.c:355 [2024/11/26 16:02:01.537868, 2] ../../source3/smbd/close.c:924(close_normal_file) chenxiaolong closed file Documents/Notes/Linux/Shells.txt (numopen=1) NT_STATUS_OK [2024/11/26 16:02:01.538016, 3] ../../source3/smbd/msdfs.c:985(get_referred_path) get_referred_path: |home| in dfs path \sm-1.int.chiller3.com\home is not a dfs root. [2024/11/26 16:02:01.538021, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_NOT_FOUND] || at ../../source3/smbd/smb2_ioctl.c:355 [2024/11/26 16:02:01.538367, 3] ../../source3/smbd/smb2_trans2.c:2066(smbd_do_qfsinfo) smbd_do_qfsinfo: level = 1005 [2024/11/26 16:02:01.538489, 3] ../../source3/smbd/smb2_trans2.c:2066(smbd_do_qfsinfo) smbd_do_qfsinfo: level = 1004 [2024/11/26 16:02:01.538590, 3] ../../source3/smbd/smb2_trans2.c:2066(smbd_do_qfsinfo) smbd_do_qfsinfo: level = 1001 [2024/11/26 16:02:01.538645, 3] ../../source3/smbd/smb2_trans2.c:2066(smbd_do_qfsinfo) smbd_do_qfsinfo: level = 1011 [2024/11/26 16:02:01.538778, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_INVALID_PARAMETER] || at ../../source3/smbd/smb2_create.c:362 [2024/11/26 16:02:01.556962, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_create.c:362 [2024/11/26 16:02:01.556971, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.556975, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[9] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.557205, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found . fname=. (.) [2024/11/26 16:02:01.557230, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found .. fname=.. (..) [2024/11/26 16:02:01.557261, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Kubernetes.txt fname=Kubernetes.txt (Kubernetes.txt) [2024/11/26 16:02:01.557277, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Hells.txt fname=Hells.txt (Hells.txt) [2024/11/26 16:02:01.557292, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Terminal Emulators.txt fname=Terminal Emulators.txt (Terminal Emulators.txt) [2024/11/26 16:02:01.557306, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Preempt.txt fname=Preempt.txt (Preempt.txt) [2024/11/26 16:02:01.557319, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Dell XPS 15 9560 Linux.txt fname=Dell XPS 15 9560 Linux.txt (Dell XPS 15 9560 Linux.txt) [2024/11/26 16:02:01.557333, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found tmux.txt fname=tmux.txt (tmux.txt) [2024/11/26 16:02:01.557347, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Fedora root on btrfs with Snapper.txt fname=Fedora root on btrfs with Snapper.txt (Fedora root on btrfs with Snapper.txt) [2024/11/26 16:02:01.557361, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found KDE Bugs.txt fname=KDE Bugs.txt (KDE Bugs.txt) [2024/11/26 16:02:01.557376, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found zsh.txt fname=zsh.txt (zsh.txt) [2024/11/26 16:02:01.557392, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Fedora Secure Boot With Clevis.txt fname=Fedora Secure Boot With Clevis.txt (Fedora Secure Boot With Clevis.txt) [2024/11/26 16:02:01.557404, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Shells.txt fname=Shells.txt (Shells.txt) [2024/11/26 16:02:01.557416, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found dracut-config-efistub.txt fname=dracut-config-efistub.txt (dracut-config-efistub.txt) [2024/11/26 16:02:01.557429, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found clevis.txt fname=clevis.txt (clevis.txt) [2024/11/26 16:02:01.557445, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Nix.txt fname=Nix.txt (Nix.txt) [2024/11/26 16:02:01.557458, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found GNOME Issues.txt fname=GNOME Issues.txt (GNOME Issues.txt) [2024/11/26 16:02:01.557470, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Distros.txt fname=Distros.txt (Distros.txt) [2024/11/26 16:02:01.557488, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found vtebench fname=vtebench (vtebench) [2024/11/26 16:02:01.557502, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found openSUSE.txt fname=openSUSE.txt (openSUSE.txt) [2024/11/26 16:02:01.557514, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Arch Linux.txt fname=Arch Linux.txt (Arch Linux.txt) [2024/11/26 16:02:01.557528, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Fedora root on ZFS.md fname=Fedora root on ZFS.md (Fedora root on ZFS.md) [2024/11/26 16:02:01.557541, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found notcurses-demo fname=notcurses-demo (notcurses-demo) [2024/11/26 16:02:01.557554, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found helix.txt fname=helix.txt (helix.txt) [2024/11/26 16:02:01.557566, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found btrfs snapshots.txt fname=btrfs snapshots.txt (btrfs snapshots.txt) [2024/11/26 16:02:01.557579, 3] ../../source3/smbd/dir.c:734(smbd_dirptr_get_entry) smbd_dirptr_get_entry: mask=[*] found Linux Gaming.txt fname=Linux Gaming.txt (Linux Gaming.txt) [2024/11/26 16:02:01.557695, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_create.c:362 [2024/11/26 16:02:01.557701, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.557704, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[9] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.557881, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_create.c:362 [2024/11/26 16:02:01.557885, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.557887, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[9] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558021, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[STATUS_NO_MORE_FILES] || at ../../source3/smbd/smb2_query_directory.c:161 [2024/11/26 16:02:01.558072, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_create.c:362 [2024/11/26 16:02:01.558076, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558078, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[9] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558166, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_create.c:362 [2024/11/26 16:02:01.558173, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558175, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[9] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558266, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_create.c:362 [2024/11/26 16:02:01.558269, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558272, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[9] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558524, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_create.c:362 [2024/11/26 16:02:01.558529, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558532, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[9] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558630, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_create.c:362 [2024/11/26 16:02:01.558634, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[5] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319 [2024/11/26 16:02:01.558636, 3] ../../source3/smbd/smb2_server.c:4052(smbd_smb2_request_error_ex) smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[9] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at ../../source3/smbd/smb2_server.c:3319
Rowland Penny
2024-Nov-28 09:34 UTC
[Samba] Random EINVAL when opening files with SMB3 POSIX extensions enabled
On Tue, 26 Nov 2024 17:03:04 -0500 Andrew Gunnerson via samba <samba at lists.samba.org> wrote:> Hello! > > I recently tried enabling SMB3 POSIX extensions as I'm only using > Linux clients and would like to make use of the standard unix > permission bits. However, I'm running into an issue where a simple > `cat` fails with -EINVAL when opening the file: > > openat(AT_FDCWD, "Shells.txt", O_RDONLY) = -1 EINVAL (Invalid > argument) > > The weird thing is that it's intermittent. It'll fail with EINVAL > many times in a row and then suddenly work and then start failing > again. When it fails, I see a message like this in the client's dmesg: > > [ 4295.972953] CIFS: enabling forceuid mount option implicitly > because uid= option is specified [ 4295.972958] CIFS: enabling > forcegid mount option implicitly because gid= option is specified [ > 4295.972961] CIFS: Attempting to mount > //sm-1.int.chiller3.com/home/Documents/Notes/Linux/Shells.txt [ > 4295.974221] CIFS: VFS: cifs_mount failed w/return code = -22 > > (The `log level = 3` samba logs are included at the end of this > email.) > > If I turn off SMB3 POSIX extensions, then this issue never occurs. > > On the server side, there isn't really anything special. There are > only the standard Unix owner/group/mode set. The file in question and > all parent directories have no POSIX ACLs nor NTACL xattrs. > > My server configuration is: > > [global] > workgroup = SAMBA > security = user > > passdb backend = tdbsam > > printing = cups > printcap name = cups > load printers = yes > cups options = raw > > store dos attributes = no > server min protocol = SMB2I do not use the SMB3 Unix extensions, but perhaps you may not be either, have you tried replacing 'server min protocol = SMB2' (which is the default anyway) with 'server min protocol = SMB3' ? Rowland
Ralph Boehme
2024-Nov-28 09:53 UTC
[Samba] Random EINVAL when opening files with SMB3 POSIX extensions enabled
On 11/26/24 11:03 PM, Andrew Gunnerson via samba wrote:> I recently tried enabling SMB3 POSIX extensions as I'm only using Linux clients > and would like to make use of the standard unix permission bits. However, I'm > running into an issue where a simple `cat` fails with -EINVAL when opening the > file: > > openat(AT_FDCWD, "Shells.txt", O_RDONLY) = -1 EINVAL (Invalid argument) > > The weird thing is that it's intermittent. It'll fail with EINVAL many times in > a row and then suddenly work and then start failing again.can you grab a network trace when it happens? <https://wiki.samba.org/index.php/Capture_Packets#Tracing_SMB_traffic_of_a_specific_client> Beware that SMB3 POSIX Extensions are still under active development and I would recommend not using them in production right now because of bugs in Samba and cifs.ko. -slow -- SerNet Samba Team Lead https://sernet.de/ Samba Team Member https://samba.org/ SAMBA+ packages https://samba.plus/ -------------- next part -------------- A non-text attachment was scrubbed... Name: OpenPGP_signature.asc Type: application/pgp-signature Size: 840 bytes Desc: OpenPGP digital signature URL: <http://lists.samba.org/pipermail/samba/attachments/20241128/84de99e0/OpenPGP_signature.sig>