[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <af0134a7-6f2a-46e1-85aa-c97477bd6ed8@amd.com>
Date: Mon, 24 Mar 2025 16:17:53 +0530
From: K Prateek Nayak <kprateek.nayak@....com>
To: Oleg Nesterov <oleg@...hat.com>, Mateusz Guzik <mjguzik@...il.com>
CC: syzbot <syzbot+62262fdc0e01d99573fc@...kaller.appspotmail.com>,
<brauner@...nel.org>, <dhowells@...hat.com>, <jack@...e.cz>,
<jlayton@...nel.org>, <linux-fsdevel@...r.kernel.org>,
<linux-kernel@...r.kernel.org>, <netfs@...ts.linux.dev>,
<swapnil.sapkal@....com>, <syzkaller-bugs@...glegroups.com>,
<viro@...iv.linux.org.uk>
Subject: Re: [syzbot] [netfs?] INFO: task hung in netfs_unbuffered_write_iter
Hello Oleg, Mateusz,
On 3/24/2025 2:32 AM, Oleg Nesterov wrote:
> Prateek, Mateusz, thanks for your participation!
>
> On 03/23, Mateusz Guzik wrote:
>>
>> On Sun, Mar 23, 2025 at 8:47 PM Oleg Nesterov <oleg@...hat.com> wrote:
>>>
>>> OK, as expected.
>>>
>>> Dear syzbot, thank you.
>>>
>>> So far I think this is another problem revealed by aaec5a95d59615523db03dd5
>>> ("pipe_read: don't wake up the writer if the pipe is still full").
>>>
>>> I am going to forget about this report for now and return to it later, when
>>> all the pending pipe-related changes in vfs.git are merged.
>>>
>>
>> How do you ask syzbot for all stacks?
>
> Heh, I don't know.
>
>> The reproducer *does* use pipes, but it is unclear to me if they play
>> any role here
>
> please see the reproducer,
>
> https://syzkaller.appspot.com/x/repro.c?x=10d6a44c580000
>
> res = syscall(__NR_pipe2, /*pipefd=*/0x400000001900ul, /*flags=*/0ul);
> if (res != -1) {
> r[2] = *(uint32_t*)0x400000001900;
> r[3] = *(uint32_t*)0x400000001904;
> }
>
> then
>
> res = syscall(__NR_dup, /*oldfd=*/r[3]);
> if (res != -1)
> r[4] = res;
>
> so r[2] and r[4] are the read/write fd's.
>
> then later
>
> memcpy((void*)0x400000000280, "trans=fd,", 9);
> ...
> memcpy((void*)0x400000000289, "rfdno", 5);
> ...
> sprintf((char*)0x40000000028f, "0x%016llx", (long long)r[2]);
> ...
> memcpy((void*)0x4000000002a2, "wfdno", 5);
> ...
> sprintf((char*)0x4000000002a8, "0x%016llx", (long long)r[4]);
> ...
> syscall(__NR_mount, /*src=*/0ul, /*dst=*/0x400000000000ul,
> /*type=*/0x400000000040ul, /*flags=*/0ul, /*opts=*/0x400000000280ul);
>
> so this pipe is actually used as "trans=fd".
>
>> -- and notably we don't know if there is someone stuck
>> in pipe code, resulting in not waking up the reported thread.
>
> Yes, I am not familiar with 9p or netfs, so I don't know either.
Didn't have any luck reproducing this yet but I'm looking at
https://syzkaller.appspot.com/x/log.txt?x=1397319b980000
which is the trimmed log from original report and I see ...
[pid 5842] creat("./file0", 000) = 7
[ 137.753309][ T30] audit: type=1400 audit(1742312362.045:90): avc: denied { mount } for pid=5842 comm="syz-executor309" name="/" dev="9p" ino=2 scontext=root:sysadm_r:sysadm_t tcontext=system_u:object_r:unlabeled_t tclass=filesystem permissive=1
[ 137.775741][ T30] audit: type=1400 audit(1742312362.065:91): avc: denied { setattr } for pid=5842 comm="syz-executor309" name="/" dev="9p" ino=2 scontext=root:sysadm_r:sysadm_t tcontext=system_u:object_r:unlabeled_t tclass=file permissive=1
[ 137.798215][ T30] audit: type=1400 audit(1742312362.075:92): avc: denied { write } for pid=5842 comm="syz-executor309" dev="9p" ino=2 scontext=root:sysadm_r:sysadm_t tcontext=system_u:object_r:unlabeled_t tclass=file permissive=1
[ 137.819189][ T30] audit: type=1400 audit(1742312362.075:93): avc: denied { open } for pid=5842 comm="syz-executor309" path="/file0" dev="9p" ino=2 scontext=root:sysadm_r:sysadm_t tcontext=system_u:object_r:unlabeled_t tclass=file permissive=1
[pid 5842] write(7, "\x08\x00\x00\x00\x1a\x17\x92\x4a\xb2\x18\xea\xcb\x15\xa3\xfc\xcf\x92\x9e\x2d\xd2\x49\x79\x03\xc1\xf8\x53\xd9\x5b\x99\x5c\x65\xe9\x94\x49\xff\x95\x3f\xa1\x1c\x77\x23\xb2\x14\x9e\xcd\xaa\x7f\x83\x3f\x60\xe1\x3b\x19\xa6\x6e\x96\x3f\x7e\x8d\xa4\x29\x7e\xbb\xfd\xda\x5b\x36\xfb\x4d\x01\xbd\x02\xe6\xc6\x52\xdc\x4d\x99\xe2\xcb\x82\xc2\xa1\xd4\xa4\x5e\x4c\x89\xba\x99\x94\xe8\x2f\x85\x4b\xbc\x34\xa4\x0b\x3a"..., 32748 <unfinished ...>
So we have a "write" denied for pid 5842 and then it tries a write that
seems to hangs. In all the traces for hang, I see a denied for a task
followed by a hang for the task in the same tgid.
But since this is a "permissive" policy, it should not cause a hang,
only report that the program is in violation. Also I have no clue how a
spurious wakeup of a writer could then lead to progress.
Since in all cases the thread info flags "flags:0x00004006" has the
TIF_NOTIFY_SIGNAL bit set, I'm wondering if it has something to do with
the fact that pipe_read() directly return -ERESTARTSYS in case of a
pending signal without any wakeups?
Well here goes nothing I guess; Totally a shot in the dark:
P.S. I think it should be wake_next_reader but if this does not hang,
perhaps it could point to some interaction with signal pending and
wakeup. There are some EPOLL semantics in pipe_write() which will
cause readers to wakeup if the writer has signal_pending() and
pipe->poll_usage is set.
#syz test: upstream aaec5a95d59615523db03dd53c2052f0a87beea7
diff --git a/fs/pipe.c b/fs/pipe.c
index 82fede0f2111..9efeb86eaac5 100644
--- a/fs/pipe.c
+++ b/fs/pipe.c
@@ -359,6 +359,8 @@ pipe_read(struct kiocb *iocb, struct iov_iter *to)
ret = -EAGAIN;
break;
}
+ if (signal_pending(current) && pipe_full(pipe->head, pipe->tail, pipe->max_usage))
+ wake_writer = true;
mutex_unlock(&pipe->mutex);
/*
Powered by blists - more mailing lists