Re: WARNING in fuse_request_end

[Hou Tao]

Hi,

On 5/7/2024 10:52 AM, lee bruce wrote:
> Hello, I found a new bug titled "WARNING in fuse_request_end" and
> comfirmed in the lastest upstream.
>
> If you fix this issue, please add the following tag to the commit:
> Reported-by: xingwei lee <xrivendell7@xxxxxxxxx>
> Reported-by: yue sun <samsun1006219@xxxxxxxxx>
> kernel: upstream dccb07f2914cdab2ac3a5b6c98406f765acab803(lastest)
> kernel config: https://syzkaller.appspot.com/text?tag=KernelConfig&x=7144b4fe7fbf5900
> with KASAN enabled
> compiler: gcc (GCC) 13.2.1 20231011
>
> TITLE: WARNING in fuse_request_end
> ------------[ cut here ]------------
> WARNING: CPU: 0 PID: 8264 at fs/fuse/dev.c:300
> fuse_request_end+0x685/0x7e0 fs/fuse/dev.c:300
> Modules linked in:
> CPU: 0 PID: 8264 Comm: ab2 Not tainted 6.9.0-rc7-00012-gdccb07f2914c #27
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> 1.16.2-1.fc38 04/01/2014
> RIP: 0010:fuse_request_end+0x685/0x7e0 fs/fuse/dev.c:300
> Code: ff 3c 03 0f 8f d6 fd ff ff 4c 89 ff e8 24 31 f9 fe e9 c9 fd ff
> ff e8 1a 8b 9c fe 90 0f 0b 90 e9 a9 fa ff ff e8 0c 8b 9c fe 90 <0f> 0b
> 90 e9 e6 fa ff ff 48 89 34 24 e8 fa 30 f9 fe 48 8b 34 24 e9
> RSP: 0018:ffffc9000eb17a60 EFLAGS: 00010293
> RAX: 0000000000000000 RBX: ffff8880342cc008 RCX: ffffffff82f20b6a
> RDX: ffff88802fa79ec0 RSI: ffffffff82f21084 RDI: 0000000000000007
> RBP: ffff8880342cc038 R08: 0000000000000007 R09: 0000000000000000
> R10: 0000000000000100 R11: 0000000000000000 R12: ffff888029989000
> R13: ffff88802cc39740 R14: 0000000000000100 R15: ffff8880342cc038
> FS: 00007febdf6d96c0(0000) GS:ffff8880b9400000(0000) knlGS:0000000000000000
> CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 0000000020002200 CR3: 000000001fe6c000 CR4: 0000000000750ef0
> PKRU: 55555554
> Call Trace:
> <TASK>
> fuse_dev_do_read.constprop.0+0xd36/0x1dd0 fs/fuse/dev.c:1334
> fuse_dev_read+0x166/0x200 fs/fuse/dev.c:1367
> call_read_iter include/linux/fs.h:2104 [inline]
> new_sync_read fs/read_write.c:395 [inline]
> vfs_read+0x85b/0xba0 fs/read_write.c:476
> ksys_read+0x12f/0x260 fs/read_write.c:619
> do_syscall_x64 arch/x86/entry/common.c:52 [inline]
> do_syscall_64+0xce/0x260 arch/x86/entry/common.c:83
> entry_SYSCALL_64_after_hwframe+0x77/0x7f
> RIP: 0033:0x439ae9
> Code: 28 00 00 00 75 05 48 83 c4 28 c3 e8 f1 17 00 00 90 48 89 f8 48
> 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d
> 01 f0 ff ff 73 01 c3 48 c7 c1 b0 ff ff ff f7 d8 64 89 01 48
> RSP: 002b:00007febdf6d91f8 EFLAGS: 00000213 ORIG_RAX: 0000000000000000
> RAX: ffffffffffffffda RBX: 00007febdf6d96c0 RCX: 0000000000439ae9
> RDX: 0000000000002020 RSI: 0000000020000140 RDI: 0000000000000004
> RBP: 00007febdf6d9220 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000213 R12: ffffffffffffffb0
> R13: 000000000000006e R14: 00007ffde3c37740 R15: 00007ffde3c37828
> </TASK>
>
> =* repro.c =*

SNIP

>  case 4:
>    *(uint32_t*)0x20002200 = 0x28;
>    *(uint32_t*)0x20002204 = 7;
>    *(uint64_t*)0x20002208 = 0;
>    *(uint64_t*)0x20002210 = 0;
>    *(uint64_t*)0x20002218 = 0;
>    *(uint64_t*)0x20002220 = 0;
>    syscall(__NR_write, /*fd=*/r[1], /*arg=*/0x20002200ul, /*len=*/0x28ul);

Thanks for the report and the reproducer program.  It seems that the
warning is due to the FUSE_NOTIFY_RESEND notify send by the write()
syscall above and it happens as follows:

(1) the reproducer calls fuse_dev_read() to read the INIT request.
The read succeeds. During the read, bit FR_SENT will be set on req->flags.
(2) the reproducer calls fuse_dev_write() to write a FUSE_NOTIFY_RESEND
to resend all requests.
(3) the INIT request is moved from processing list to pending list again
(4) the reproducer calls fuse_dev_read() with an invalid output address
fuse_dev_read() will try to copy the INIT request to the output address,
but it fails,so the INIT request is ended and triggers the warning in
fuse_request_end().

A straightforward fix is to clear the FR_SENT bit in as show below:

diff --git a/fs/fuse/dev.c b/fs/fuse/dev.c
index 3ec8bb5e68ff5..840cefdf24e26 100644
--- a/fs/fuse/dev.c
+++ b/fs/fuse/dev.c
@@ -1814,6 +1814,7 @@ static void fuse_resend(struct fuse_conn *fc)

        list_for_each_entry_safe(req, next, &to_queue, list) {
                __set_bit(FR_PENDING, &req->flags);
+               clear_bit(FR_SENT, &req->flags);
                /* mark the request as resend request */
                req->in.h.unique |= FUSE_UNIQUE_RESEND;
        }

But I think more code checking and tests are needed before posting it as
a formal patch.

>    break;
>  case 5:
>    syscall(__NR_mmap, /*addr=*/0x20000000ul, /*len=*/0x3000ul, /*prot=*/0ul,
>            /*flags=*/0x12ul, /*fd=*/r[0], /*offset=*/0ul);
>    break;
>  case 6:
>    syscall(__NR_read, /*fd=*/r[1], /*buf=*/0x20000140ul, /*len=*/0x2020ul);
>    break;
>  }
> }
> int main(void)
> {
>  syscall(__NR_mmap, /*addr=*/0x1ffff000ul, /*len=*/0x1000ul, /*prot=*/0ul,
>          /*flags=*/0x32ul, /*fd=*/-1, /*offset=*/0ul);
>  syscall(__NR_mmap, /*addr=*/0x20000000ul, /*len=*/0x1000000ul, /*prot=*/7ul,
>          /*flags=*/0x32ul, /*fd=*/-1, /*offset=*/0ul);
>  syscall(__NR_mmap, /*addr=*/0x21000000ul, /*len=*/0x1000ul, /*prot=*/0ul,
>          /*flags=*/0x32ul, /*fd=*/-1, /*offset=*/0ul);
>  loop();
>  return 0;
> }
>
>
> =* repro.txt =*
> r0 = openat$cgroup_ro(0xffffffffffffff9c,
> &(0x7f0000001cc0)='memory.events\x00', 0x275a, 0x0)
> r1 = openat$fuse(0xffffffffffffff9c, &(0x7f0000000100), 0x2, 0x0)
> syz_mount_image$fuse(&(0x7f0000000080),
> &(0x7f00000000c0)='./file1\x00', 0x0, &(0x7f0000006380)={{'fd', 0x3d,
> r1}, 0x2c, {'rootmode', 0x3d, 0x4000}}, 0x0, 0x0, 0x0)
> read$FUSE(r1, &(0x7f0000000140)={0x2020}, 0x2020)
> write$FUSE_NOTIFY_INVAL_INODE(r1, &(0x7f0000002200)={0x28, 0x7}, 0x28)
> mmap(&(0x7f0000000000/0x3000)=nil, 0x3000, 0x0, 0x12, r0, 0x0)
> read$FUSE(r1, &(0x7f0000000140)={0x2020}, 0x2020)
>
>
> Please also see:
> https://gist.github.com/xrivendell7/346cb2c74cf5da4cad54cbdc8d1f0ded
>
> I hope it helps.
> Best regards.
> xingwei Lee
>
> .