On 1/20/21 8:35 PM, Pavel Begunkov wrote:
> On 20/01/2021 08:11, Joseph Qi wrote:
>> Abaci reported the following BUG:
>>
>> [ 27.629441] BUG: sleeping function called from invalid context at fs/file.c:402
>> [ 27.631317] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 1012, name: io_wqe_worker-0
>> [ 27.633220] 1 lock held by io_wqe_worker-0/1012:
>> [ 27.634286] #0: ffff888105e26c98 (&ctx->completion_lock){....}-{2:2}, at: __io_req_complete.part.102+0x30/0x70
>> [ 27.636487] irq event stamp: 66658
>> [ 27.637302] hardirqs last enabled at (66657): [<ffffffff8144ba02>] kmem_cache_free+0x1f2/0x3b0
>> [ 27.639211] hardirqs last disabled at (66658): [<ffffffff82003a77>] _raw_spin_lock_irqsave+0x17/0x50
>> [ 27.641196] softirqs last enabled at (64686): [<ffffffff824003c5>] __do_softirq+0x3c5/0x5aa
>> [ 27.643062] softirqs last disabled at (64681): [<ffffffff8220108f>] asm_call_irq_on_stack+0xf/0x20
>> [ 27.645029] CPU: 1 PID: 1012 Comm: io_wqe_worker-0 Not tainted 5.11.0-rc4+ #68
>> [ 27.646651] Hardware name: Alibaba Cloud Alibaba Cloud ECS, BIOS rel-1.7.5-0-ge51488c-20140602_164612-nilsson.home.kraxel.org 04/01/2014
>> [ 27.649249] Call Trace:
>> [ 27.649874] dump_stack+0xac/0xe3
>> [ 27.650666] ___might_sleep+0x284/0x2c0
>> [ 27.651566] put_files_struct+0xb8/0x120
>> [ 27.652481] __io_clean_op+0x10c/0x2a0
>> [ 27.653362] __io_cqring_fill_event+0x2c1/0x350
>> [ 27.654399] __io_req_complete.part.102+0x41/0x70
>> [ 27.655464] io_openat2+0x151/0x300
>> [ 27.656297] io_issue_sqe+0x6c/0x14e0
>> [ 27.657170] ? lock_acquire+0x31a/0x440
>> [ 27.658068] ? io_worker_handle_work+0x24e/0x8a0
>> [ 27.659119] ? find_held_lock+0x28/0xb0
>> [ 27.660026] ? io_wq_submit_work+0x7f/0x240
>> [ 27.660991] io_wq_submit_work+0x7f/0x240
>> [ 27.661915] ? trace_hardirqs_on+0x46/0x110
>> [ 27.662890] io_worker_handle_work+0x501/0x8a0
>> [ 27.663917] ? io_wqe_worker+0x135/0x520
>> [ 27.664836] io_wqe_worker+0x158/0x520
>> [ 27.665719] ? __kthread_parkme+0x96/0xc0
>> [ 27.666663] ? io_worker_handle_work+0x8a0/0x8a0
>> [ 27.667726] kthread+0x134/0x180
>> [ 27.668506] ? kthread_create_worker_on_cpu+0x90/0x90
>> [ 27.669641] ret_from_fork+0x1f/0x30
>>
>> It blames we call cond_resched() with completion_lock when clean
>> request. In fact we will do it during flush overflow and it seems we
>> have no reason to do it before. So just remove io_clean_op() in
>> __io_cqring_fill_event() to fix this BUG.
>
> Nope, it would be broken. You may override, e.g. iov pointer
> that is dynamically allocated, and the function makes sure all
> those are deleted and freed. Most probably there will be problems
> on flush side as well.
>
> Looks like the problem is that we do spin_lock_irqsave() in
> __io_req_complete() and then just spin_lock() for put_files_struct().
> Jens, is it a real problem?
>
>From the code, it is because it might sleep in close_files():
...
if (file) {
filp_close(file, files);
cond_resched();
}
Thanks,
Joseph
> At least for 5.12 there is a cleanup as below, moving drop_files()
> into io_req_clean_work/io_free_req(), which is out of locks. Depends
> on that don't-cancel-by-files patch, but I guess can be for 5.11
