SMB Partial Send Causes CIFS VFS Reconnection and File Copy Failure

SMB Partial Send Causes CIFS VFS Reconnection and File Copy Failure

[David Manpearl]

During file copy operations from our local file system to a Synology Samba server file system from within our app, we are seeing numerous partial data sends which appear to cause CIFS reconnections, which in turn cause the copies to fail.
We see these errors logged by our Golang application on the following operations:
os.Create
- tbd|ERROR [tbd/daemon] (tbd_copy_file.go:333#openWriters) Failed create file [open /media/smb_192_168_86_40_GBXShare/SHAREBOX/100MEDIA/DJI_0114.JPG: no such file or directory]
write
- tbd|ERROR [tbd/daemon] (tbd_copy_file.go:440#finishFile) writer [write /media/smb_192_168_86_40_GBXShare/SHAREBOX2/100MEDIA_01/DJI_0002.JPG: bad file descriptor]
- tbd|ERROR [tbd/daemon] (tbd_copy_file.go:294#openWriters) Failed create file [open /media/smb_192_168_86_40_GBXShare/SHAREBOX2/100MEDIA_01/DJI_0073.JPG: resource temporarily unavailable]
- tbd|ERROR [tbd/daemon] (tbd_copy_file.go:393#finishFile) writer [write /media/smb_192_168_86_40_GBXShare/SHAREBOX2/100MEDIA_01/DJI_0072.JPG: broken pipe]
file.Sync
- tbd|ERROR [tbd/daemon] (tbd_copy_file.go:395#finishFile) sync [sync /media/smb_192_168_86_40_GBXShare/SMBSHARE/100MEDIA_02/DJI_0014(1).JPG: input/output error]
file.Close
- tbd|WARN  [tbd/daemon] (tbd_copy_file.go:435#finishFile) close [close /media/smb_192_168_86_40_GBXShare/SHAREBOX2/100MEDIA_02/DJI_0097.JPG: input/output error]

Partial send log example:
[196361.832049] /usr/src/kernel/fs/cifs/transport.c: partial send (wanted=65652 sent=116): terminating session

Usually followed by:
[196361.868197] CIFS VFS: Free previous auth_key.response = ffff88011748b000

- What are the scenarios in which a partial send will occur, because this does not appear to be a network issue on our side?

- If this is expected behavior, how are we supposed to be handling the partial sends in userspace?

- Are there other errors you see in the attached logs?

Linux Kernel version: 4.9.115-yocto-standard
We are using the "fs/cifs/" directory from the "linux-4.9-full-backports" branch from this repo: https://github.com/smfrench/smb3-cifs-linux-stable-backports

Mount.cifs version: 6.7
Samba version:
http://192.168.86.40:5000
Control Panel > File Services > Max SMB3, Min SMB2.
Appliance: Synology:
Model name: DS1618
CPU: INTEL Atom C3538

DebugData:
# cat /proc/fs/cifs/DebugData
Display Internal CIFS Data Structures for Debugging
---------------------------------------------------
CIFS Version 2.11
Features: posix xattr
Active VFS Requests: 0
Servers:
Number of credits: 512 Dialect 0x202
1) Name: 192.168.86.40 Uses: 1 Capability: 0x300001 Session Status: 1 TCP status: 1
Local Users To Server: 1 SecMode: 0x1 Req On Wire: 0
Shares:
0) IPC: \\192.168.86.40\IPC$ Mounts: 1 DevInfo: 0x0 Attributes: 0x0
PathComponentMax: 0 Status: 1 type: 0
1) \\192.168.86.40\GBXShare Mounts: 4 DevInfo: 0x20 Attributes: 0x5006f
PathComponentMax: 255 Status: 1 type: DISK
MIDs:
Number of credits: 528 Dialect 0x302
2) Name: 192.168.86.40 Uses: 1 Capability: 0x300005 Session Status: 1 TCP status: 1
Local Users To Server: 1 SecMode: 0x1 Req On Wire: 0
Shares:
0) IPC: \\192.168.86.40\IPC$ Mounts: 1 DevInfo: 0x0 Attributes: 0x0
PathComponentMax: 0 Status: 1 type: 0
Share Capabilities: None Share Flags: 0x0

1) \\192.168.86.40\GBXShare Mounts: 1 DevInfo: 0x20 Attributes: 0x5006f
PathComponentMax: 255 Status: 1 type: DISK
Share Capabilities: None Aligned, Partition Aligned, Share Flags: 0x0 Optimal sector size: 0x200
MIDs:

Logs: dmesgCIFS-h.log: https://drive.google.com/file/d/1_fWpvSs5zeOFaV-YlGfW2ej3LGwFZSns/view?usp=sharing

- Thank you, David

Re: SMB Partial Send Causes CIFS VFS Reconnection and File Copy Failure

[Pavel Shilovsky]

Hi David,

Some issues with partial sends were fixed in the 5.1 kernel. I don't
think the patches were backported to 4.9.

In particular the following patches are needed:

https://www.spinics.net/lists/linux-cifs/msg16569.html
https://www.spinics.net/lists/linux-cifs/msg20496.html

The errors may occur if an application accessing a share uses signals
that may be triggered during system calls. Such errors should be
handled by retrying in the userspace if getting -EINTR.

--
Best regards,
Pavel Shilovsky

вт, 22 июн. 2021 г. в 20:42, David Manpearl <david@gnarbox.com>:

>
> During file copy operations from our local file system to a Synology Samba server file system from within our app, we are seeing numerous partial data sends which appear to cause CIFS reconnections, which in turn cause the copies to fail.
> We see these errors logged by our Golang application on the following operations:
> os.Create
> - tbd|ERROR [tbd/daemon] (tbd_copy_file.go:333#openWriters) Failed create file [open /media/smb_192_168_86_40_GBXShare/SHAREBOX/100MEDIA/DJI_0114.JPG: no such file or directory]
> write
> - tbd|ERROR [tbd/daemon] (tbd_copy_file.go:440#finishFile) writer [write /media/smb_192_168_86_40_GBXShare/SHAREBOX2/100MEDIA_01/DJI_0002.JPG: bad file descriptor]
> - tbd|ERROR [tbd/daemon] (tbd_copy_file.go:294#openWriters) Failed create file [open /media/smb_192_168_86_40_GBXShare/SHAREBOX2/100MEDIA_01/DJI_0073.JPG: resource temporarily unavailable]
> - tbd|ERROR [tbd/daemon] (tbd_copy_file.go:393#finishFile) writer [write /media/smb_192_168_86_40_GBXShare/SHAREBOX2/100MEDIA_01/DJI_0072.JPG: broken pipe]
> file.Sync
> - tbd|ERROR [tbd/daemon] (tbd_copy_file.go:395#finishFile) sync [sync /media/smb_192_168_86_40_GBXShare/SMBSHARE/100MEDIA_02/DJI_0014(1).JPG: input/output error]
> file.Close
> - tbd|WARN  [tbd/daemon] (tbd_copy_file.go:435#finishFile) close [close /media/smb_192_168_86_40_GBXShare/SHAREBOX2/100MEDIA_02/DJI_0097.JPG: input/output error]
>
> Partial send log example:
> [196361.832049] /usr/src/kernel/fs/cifs/transport.c: partial send (wanted=65652 sent=116): terminating session
>
> Usually followed by:
> [196361.868197] CIFS VFS: Free previous auth_key.response = ffff88011748b000
>
> - What are the scenarios in which a partial send will occur, because this does not appear to be a network issue on our side?
>
> - If this is expected behavior, how are we supposed to be handling the partial sends in userspace?
>
> - Are there other errors you see in the attached logs?
>
> Linux Kernel version: 4.9.115-yocto-standard
> We are using the "fs/cifs/" directory from the "linux-4.9-full-backports" branch from this repo: https://github.com/smfrench/smb3-cifs-linux-stable-backports
>
> Mount.cifs version: 6.7
> Samba version:
> http://192.168.86.40:5000
> Control Panel > File Services > Max SMB3, Min SMB2.
> Appliance: Synology:
> Model name: DS1618
> CPU: INTEL Atom C3538
>
> DebugData:
> # cat /proc/fs/cifs/DebugData
> Display Internal CIFS Data Structures for Debugging
> ---------------------------------------------------
> CIFS Version 2.11
> Features: posix xattr
> Active VFS Requests: 0
> Servers:
> Number of credits: 512 Dialect 0x202
> 1) Name: 192.168.86.40 Uses: 1 Capability: 0x300001 Session Status: 1 TCP status: 1
> Local Users To Server: 1 SecMode: 0x1 Req On Wire: 0
> Shares:
> 0) IPC: \\192.168.86.40\IPC$ Mounts: 1 DevInfo: 0x0 Attributes: 0x0
> PathComponentMax: 0 Status: 1 type: 0
> 1) \\192.168.86.40\GBXShare Mounts: 4 DevInfo: 0x20 Attributes: 0x5006f
> PathComponentMax: 255 Status: 1 type: DISK
> MIDs:
> Number of credits: 528 Dialect 0x302
> 2) Name: 192.168.86.40 Uses: 1 Capability: 0x300005 Session Status: 1 TCP status: 1
> Local Users To Server: 1 SecMode: 0x1 Req On Wire: 0
> Shares:
> 0) IPC: \\192.168.86.40\IPC$ Mounts: 1 DevInfo: 0x0 Attributes: 0x0
> PathComponentMax: 0 Status: 1 type: 0
> Share Capabilities: None Share Flags: 0x0
>
> 1) \\192.168.86.40\GBXShare Mounts: 1 DevInfo: 0x20 Attributes: 0x5006f
> PathComponentMax: 255 Status: 1 type: DISK
> Share Capabilities: None Aligned, Partition Aligned, Share Flags: 0x0 Optimal sector size: 0x200
> MIDs:
>
> Logs: dmesgCIFS-h.log: https://drive.google.com/file/d/1_fWpvSs5zeOFaV-YlGfW2ej3LGwFZSns/view?usp=sharing
>
> - Thank you, David
>
>