Re: [syzbot] [netfs?] INFO: task hung in netfs_unbuffered_write_iter
From: K Prateek Nayak
Date: Mon Mar 24 2025 - 06:50:15 EST
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@xxxxxxxxxx> 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);
/*