Re: Problematic interaction of io_uring and CIFS

[Shyam Prasad N <nspmangalore@gmail.com>]

On Sat, Jul 9, 2022 at 9:00 AM Shyam Prasad N <nspmangalore@gmail.com> wrote:
>
> On Fri, Jul 8, 2022 at 11:22 PM Enzo Matsumiya <ematsumiya@suse.de> wrote:
> >
> > On 07/08, Fabian Ebner wrote:
> > >(Re-sending without the log from the older kernel, because the mail hit
> > >the 100000 char limit with that)
> > >
> > >Hi,
> > >it seems that in kernels >= 5.15, io_uring and CIFS don't interact
> > >nicely sometimes, leading to IO errors. Unfortunately, my reproducer is
> > >a QEMU VM with a disk on CIFS (original report by one of our users [0]),
> > >but I can try to cook up something simpler if you want.
> > >
> > >Bisecting got me to 8ef12efe26c8 ("io_uring: run regular file
> > >completions from task_work") being the first bad commit.
> > >
> > >Attached are debug logs taken with Ubuntu's build of 5.18.6. QEMU trace
> > >was taken with '-trace luring*' and CIFS debug log was enabled as
> > >described in [1].
> > >
> > >Without CIFS debugging, the error messages in syslog are, for 5.18.6:
> > >> Jun 29 12:41:45 pve702 kernel: [  112.664911] CIFS: VFS: \\192.168.20.241 Error -512 sending data on socket to server
> > >> Jun 29 12:41:46 pve702 kernel: [  112.796227] CIFS: Status code returned 0xc00000d0 STATUS_REQUEST_NOT_ACCEPTED
> > >> Jun 29 12:41:46 pve702 kernel: [  112.796250] CIFS: VFS: \\192.168.20.241 Send error in SessSetup = -5
> > >> Jun 29 12:41:46 pve702 kernel: [  112.797781] CIFS: VFS: \\192.168.20.241 Send error in SessSetup = -11
> > >> Jun 29 12:41:46 pve702 kernel: [  112.798065] CIFS: VFS: \\192.168.20.241 Send error in SessSetup = -11
> > >> Jun 29 12:41:46 pve702 kernel: [  112.813485] CIFS: Status code returned 0xc00000d0 STATUS_REQUEST_NOT_ACCEPTED
> > >> Jun 29 12:41:46 pve702 kernel: [  112.813497] CIFS: VFS: \\192.168.20.241 Send error in SessSetup = -5
> > >> Jun 29 12:41:46 pve702 kernel: [  112.826829] CIFS: Status code returned 0xc00000d0 STATUS_REQUEST_NOT_ACCEPTED
> > >> Jun 29 12:41:46 pve702 kernel: [  112.826837] CIFS: VFS: \\192.168.20.241 Send error in SessSetup = -5
> > >> Jun 29 12:41:46 pve702 kernel: [  112.839369] CIFS: Status code returned 0xc00000d0 STATUS_REQUEST_NOT_ACCEPTED
> > >> Jun 29 12:41:46 pve702 kernel: [  112.839381] CIFS: VFS: \\192.168.20.241 Send error in SessSetup = -5
> > >> Jun 29 12:41:46 pve702 kernel: [  112.851854] CIFS: Status code returned 0xc00000d0 STATUS_REQUEST_NOT_ACCEPTED
> > >> Jun 29 12:41:46 pve702 kernel: [  112.851867] CIFS: VFS: \\192.168.20.241 Send error in SessSetup = -5
> > >> Jun 29 12:41:46 pve702 kernel: [  112.870763] CIFS: Status code returned 0xc00000d0 STATUS_REQUEST_NOT_ACCEPTED
> > >> Jun 29 12:41:46 pve702 kernel: [  112.870777] CIFS: VFS: \\192.168.20.241 Send error in SessSetup = -5
> >
> > It looks like this has something to do with multiple session setups on
> > the same channel, and there's a fix introduced in 5.19-rc1:
> >
> > 5752bf645f9 "cifs: avoid parallel session setups on same channel"
> >
> > Can you build a test kernel with that commit and test it again? I
> > couldn't reproduce this with a small liburing test program. If you can
> > provide one, I'd be happy to take a deeper look at this bug.
> >
> > Please note that the actual root cause of the error (CIFS needing
> > reconnect) is not very clear to me, but I don't have experience with
> > io_uring anyway:
> >
> > 178 Jun 29 11:25:39 pve702 kernel: [   87.439910] CIFS: fs/cifs/transport.c: signal is pending after attempt to send
> > 179 Jun 29 11:25:39 pve702 kernel: [   87.439920] CIFS: fs/cifs/transport.c: partial send (wanted=65652 sent=53364): terminating session

This error indicates that the socket could only send partial data to
the server. This causes the client to reconnect. While I don't think
this is the primary issue here, it is definitely an issue. Please look
into that as well.

> > 180 Jun 29 11:25:39 pve702 kernel: [   87.439970] CIFS: VFS: \\192.168.20.241 Error -512 sending data on socket to server
> > <cifs marks all sessions and tcons for reconnect and gets in the
> > erroneous reconnect loop as shown above>
> >
> >
> > Cheers,
> >
> > Enzo
>
> Hi Fabian,
>
> It looks like the server is rejecting new binding session requests
> with STATUS_REQUEST_NOT_ACCEPTED.
> Are you saying that the issue is specific to 5.15+ kernel, and the
> issue doesn't happen on older kernels?
> Also, what server are you using? Has that changed across these attempts?
>
> Can you please dump the output of:
> cat /proc/fs/cifs/DebugData
> when the issue is happening?
>
> --
> Regards,
> Shyam



-- 
Regards,
Shyam