Re: INFO: task hung in __io_uring_files_cancel
From: Pavel Begunkov
Date: Sun Nov 22 2020 - 11:00:26 EST
On 22/11/2020 09:20, Hillf Danton wrote:
> On Sun, 22 Nov 2020 03:32:01 +0000 Pavel Begunkov wrote:
>> On 22/11/2020 03:04, Hillf Danton wrote:
>>> On Sat, 21 Nov 2020 14:35:15 -0800
>>>> syzbot found the following issue on:
>>>>
>>>> bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=10401726500000
>>>> final oops: https://syzkaller.appspot.com/x/report.txt?x=12401726500000
>>>> console output: https://syzkaller.appspot.com/x/log.txt?x=14401726500000
>>>>
>>>> IMPORTANT: if you fix the issue, please add the following tag to the commit:
>>>> Reported-by: syzbot+c0d52d0b3c0c3ffb9525@xxxxxxxxxxxxxxxxxxxxxxxxx
>>>> Fixes: 4d004099a668 ("lockdep: Fix lockdep recursion")
>>>>
>>>> INFO: task syz-executor.0:9557 blocked for more than 143 seconds.
>>>> Not tainted 5.10.0-rc4-next-20201117-syzkaller #0
>>>> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>>>> task:syz-executor.0 state:D stack:28584 pid: 9557 ppid: 8485 flags:0x00004002
>>>> Call Trace:
>>>> context_switch kernel/sched/core.c:4269 [inline]
>>>> __schedule+0x890/0x2030 kernel/sched/core.c:5019
>>>> schedule+0xcf/0x270 kernel/sched/core.c:5098
>>>> io_uring_cancel_files fs/io_uring.c:8720 [inline]
>>>> io_uring_cancel_task_requests fs/io_uring.c:8772 [inline]
>>>> __io_uring_files_cancel+0xc4d/0x14b0 fs/io_uring.c:8868
>>>> io_uring_files_cancel include/linux/io_uring.h:51 [inline]
>>>> exit_files+0xe4/0x170 fs/file.c:456
>>>> do_exit+0xb61/0x29f0 kernel/exit.c:818
>>>> do_group_exit+0x125/0x310 kernel/exit.c:920
>>>> get_signal+0x3ea/0x1f70 kernel/signal.c:2750
>>>> arch_do_signal_or_restart+0x2a6/0x1ea0 arch/x86/kernel/signal.c:811
>>>> handle_signal_work kernel/entry/common.c:145 [inline]
>>>> exit_to_user_mode_loop kernel/entry/common.c:169 [inline]
>>>> exit_to_user_mode_prepare+0x124/0x200 kernel/entry/common.c:199
>>>> syscall_exit_to_user_mode+0x38/0x260 kernel/entry/common.c:274
>>>> entry_SYSCALL_64_after_hwframe+0x44/0xa9
>>>> RIP: 0033:0x45deb9
>>>> Code: Unable to access opcode bytes at RIP 0x45de8f.
>>>> RSP: 002b:00007fa68397ccf8 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
>>>> RAX: fffffffffffffe00 RBX: 000000000118bf28 RCX: 000000000045deb9
>>>> RDX: 0000000000000000 RSI: 0000000000000080 RDI: 000000000118bf28
>>>> RBP: 000000000118bf20 R08: 0000000000000000 R09: 0000000000000000
>>>> R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
>>>> R13: 00007fff50acc9af R14: 00007fa68397d9c0 R15: 000000000118bf2c
>>>>
>> ...
>>>
>>> Fix 311daef8013a ("io_uring: replace inflight_wait with tctx->wait")
>>> by cutting the pre-condition to wakeup because waitqueue_active()
>>> speaks the language in the East End while atomic_read() may speak
>>> the language in Paris.
>>
>> Your description doesn't help,
>
> That is what I could find to describe the changs added in
> 311daef8013a, given that waitqueue_active() and atomic_read() IMO are
> primary bricks without natural links prebuilt. I dont think either
> of them could be replaced with another even in 311daef8013a.
There are not linked, but that doesn't make it automatically wrong.
I still don't understand how it fixes the problem, and it's better
to find the root cause because there are similar places that might
still be similarly flawed.
>> why do you think this is the problem?
>
> This is not a tough question, thanks to the reproducer.
>
>> ->in_idle is always set when io_uring_cancel_files() sleeps on it,
>> and ->inflight_lock should guarantee ordering.
>
> The syzbot report makes sense, right?
>
>>>
>>> --- a/fs/io_uring.c
>>> +++ b/fs/io_uring.c
>>> @@ -6082,8 +6082,7 @@ static void io_req_drop_files(struct io_
>>>
>>> spin_lock_irqsave(&ctx->inflight_lock, flags);
>>> list_del(&req->inflight_entry);
>>> - if (atomic_read(&tctx->in_idle))
>>> - wake_up(&tctx->wait);
>>> + wake_up(&tctx->wait);
>>> spin_unlock_irqrestore(&ctx->inflight_lock, flags);
>>> req->flags &= ~REQ_F_INFLIGHT;
>>> put_files_struct(req->work.identity->files);
--
Pavel Begunkov