[Samba] Random EINVAL when opening files with SMB3 POSIX extensions enabled

Andrew Gunnerson accounts.samba at chiller3.com
Tue Nov 26 22:03:04 UTC 2024 

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

More information about the samba mailing list