* [PATCH] workqueue: Don't record workqueue stack holding raw_spin_lock
@ 2021-08-27 23:49 Shuah Khan
2021-08-30 2:18 ` Lai Jiangshan
2021-08-30 5:40 ` Dmitry Vyukov
0 siblings, 2 replies; 5+ messages in thread
From: Shuah Khan @ 2021-08-27 23:49 UTC (permalink / raw)
To: tj, jiangshanlai, elver, akpm, dvyukov, walter-zh.wu
Cc: Shuah Khan, linux-kernel
When CONFIG_PROVE_RAW_LOCK_NESTING and CONFIG_KASAN are enabled,
kasan_record_aux_stack() runs into "BUG: Invalid wait context" when
it tries to allocate memory attempting to acquire spinlock in page
allocation code while holding workqueue pool raw_spinlock.
There are several instances of this problem when block layer tries
to __queue_work(). Call trace from one of these instances is below:
kblockd_mod_delayed_work_on()
mod_delayed_work_on()
__queue_delayed_work()
__queue_work() (rcu_read_lock, raw_spin_lock pool->lock held)
insert_work()
kasan_record_aux_stack()
kasan_save_stack()
stack_depot_save()
alloc_pages()
__alloc_pages()
get_page_from_freelist()
rm_queue()
rm_queue_pcplist()
local_lock_irqsave(&pagesets.lock, flags);
[ BUG: Invalid wait context triggered ]
Fix it by calling kasan_record_aux_stack() without holding pool lock.
There is no need to hold pool lock in this path.
=============================
[ BUG: Invalid wait context ]
5.14.0-rc7+ #8 Not tainted
-----------------------------
snap/532 is trying to lock:
ffff888374f32ba0 (lock#2){..-.}-{3:3}, at: get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
other info that might help us debug this:
context-{5:5}
3 locks held by snap/532:
#0: ffff888139fa4408 (&type->i_mutex_dir_key#10){.+.+}-{4:4}, at: walk_component (fs/namei.c:1663 fs/namei.c:1959)
#1: ffffffffab870c40 (rcu_read_lock){....}-{1:3}, at: __queue_work (./arch/x86/include/asm/preempt.h:80 ./include/linux/rcupdate.h:68 ./include/linux/rcupdate.h:685 kernel/workqueue.c:1421)
#2: ffff888374f36cd8 (&pool->lock){-.-.}-{2:2}, at: __queue_work (kernel/workqueue.c:1466)
stack backtrace:
CPU: 14 PID: 532 Comm: snap Not tainted 5.14.0-rc7+ #8
Hardware name: LENOVO 90Q30008US/3728, BIOS O4ZKT1CA 09/16/2020
Call Trace:
dump_stack_lvl (lib/dump_stack.c:106 (discriminator 4))
dump_stack (lib/dump_stack.c:113)
__lock_acquire.cold (kernel/locking/lockdep.c:4666 kernel/locking/lockdep.c:4727 kernel/locking/lockdep.c:4965)
? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4873)
? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
lock_acquire (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5627 kernel/locking/lockdep.c:5590)
? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
? lock_release (kernel/locking/lockdep.c:5593)
? __kasan_check_read (mm/kasan/shadow.c:32)
? __lock_acquire (kernel/locking/lockdep.c:5019)
? __zone_watermark_ok (./include/linux/list.h:282 ./include/linux/mmzone.h:111 mm/page_alloc.c:3908)
get_page_from_freelist (./include/linux/local_lock_internal.h:43 mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
? is_bpf_text_address (./arch/x86/include/asm/preempt.h:85 ./include/linux/rcupdate.h:73 ./include/linux/rcupdate.h:719 kernel/bpf/core.c:708)
? lock_downgrade (kernel/locking/lockdep.c:5633)
? __zone_watermark_ok (mm/page_alloc.c:4054)
__alloc_pages (mm/page_alloc.c:5391)
? __alloc_pages_slowpath.constprop.0 (mm/page_alloc.c:5354)
? create_prof_cpu_mask (kernel/stacktrace.c:82)
? _find_first_bit (lib/find_bit.c:83)
alloc_pages (mm/mempolicy.c:2249)
stack_depot_save (lib/stackdepot.c:304)
? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
kasan_save_stack (mm/kasan/common.c:41)
? kasan_save_stack (mm/kasan/common.c:39)
? kasan_record_aux_stack (mm/kasan/generic.c:348)
? insert_work (./include/linux/instrumented.h:71 ./include/asm-generic/bitops/instrumented-non-atomic.h:134 kernel/workqueue.c:616 kernel/workqueue.c:623 kernel/workqueue.c:1335)
? __queue_work (kernel/workqueue.c:1501)
? __queue_delayed_work (kernel/workqueue.c:1657)
? mod_delayed_work_on (kernel/workqueue.c:1720)
? kblockd_mod_delayed_work_on (block/blk-core.c:1633)
? __blk_mq_delay_run_hw_queue (block/blk-mq.c:1567)
? blk_mq_run_hw_queue (block/blk-mq.c:1610)
? blk_mq_sched_insert_request (block/blk-mq-sched.c:480)
? blk_mq_submit_bio (block/blk-mq.c:2276)
Fixes: e89a85d63fb2 ("workqueue: kasan: record workqueue stack")
Signed-off-by: Shuah Khan <skhan@linuxfoundation.org>
---
kernel/workqueue.c | 18 +++++++++++++++---
1 file changed, 15 insertions(+), 3 deletions(-)
diff --git a/kernel/workqueue.c b/kernel/workqueue.c
index f148eacda55a..e647b29b9fb0 100644
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -1328,9 +1328,6 @@ static void insert_work(struct pool_workqueue *pwq, struct work_struct *work,
{
struct worker_pool *pool = pwq->pool;
- /* record the work call stack in order to print it in KASAN reports */
- kasan_record_aux_stack(work);
-
/* we own @work, set data and link */
set_work_pwq(work, pwq, extra_flags);
list_add_tail(&work->entry, head);
@@ -1499,6 +1496,14 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
out:
raw_spin_unlock(&pwq->pool->lock);
+
+ /*
+ * record the work call stack in order to print it in KASAN reports
+ * Do this without pool raw_spinlock hold to avoid nesting raw
+ * spinlock with page allocation spinlock.
+ */
+ kasan_record_aux_stack(work);
+
rcu_read_unlock();
}
@@ -3012,6 +3017,13 @@ static bool start_flush_work(struct work_struct *work, struct wq_barrier *barr,
insert_wq_barrier(pwq, barr, work, worker);
raw_spin_unlock_irq(&pool->lock);
+ /*
+ * record the work call stack in order to print it in KASAN reports
+ * Do this without pool raw_spinlock hold to avoid nesting raw
+ * spinlock with page allocation spinlock.
+ */
+ kasan_record_aux_stack(work);
+
/*
* Force a lock recursion deadlock when using flush_work() inside a
* single-threaded or rescuer equipped workqueue.
--
2.30.2
^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: [PATCH] workqueue: Don't record workqueue stack holding raw_spin_lock
2021-08-27 23:49 [PATCH] workqueue: Don't record workqueue stack holding raw_spin_lock Shuah Khan
@ 2021-08-30 2:18 ` Lai Jiangshan
2021-08-30 16:27 ` Shuah Khan
2021-08-30 5:40 ` Dmitry Vyukov
1 sibling, 1 reply; 5+ messages in thread
From: Lai Jiangshan @ 2021-08-30 2:18 UTC (permalink / raw)
To: Shuah Khan
Cc: Tejun Heo, Marco Elver, Andrew Morton, Dmitry Vyukov, walter-zh.wu, LKML
On Sat, Aug 28, 2021 at 7:49 AM Shuah Khan <skhan@linuxfoundation.org> wrote:
>
> When CONFIG_PROVE_RAW_LOCK_NESTING and CONFIG_KASAN are enabled,
> kasan_record_aux_stack() runs into "BUG: Invalid wait context" when
> it tries to allocate memory attempting to acquire spinlock in page
> allocation code while holding workqueue pool raw_spinlock.
>
> There are several instances of this problem when block layer tries
> to __queue_work(). Call trace from one of these instances is below:
>
> kblockd_mod_delayed_work_on()
> mod_delayed_work_on()
> __queue_delayed_work()
> __queue_work() (rcu_read_lock, raw_spin_lock pool->lock held)
> insert_work()
> kasan_record_aux_stack()
> kasan_save_stack()
> stack_depot_save()
> alloc_pages()
> __alloc_pages()
> get_page_from_freelist()
> rm_queue()
> rm_queue_pcplist()
> local_lock_irqsave(&pagesets.lock, flags);
> [ BUG: Invalid wait context triggered ]
>
> Fix it by calling kasan_record_aux_stack() without holding pool lock.
> There is no need to hold pool lock in this path.
>
> =============================
> [ BUG: Invalid wait context ]
> 5.14.0-rc7+ #8 Not tainted
> -----------------------------
> snap/532 is trying to lock:
> ffff888374f32ba0 (lock#2){..-.}-{3:3}, at: get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
> other info that might help us debug this:
> context-{5:5}
> 3 locks held by snap/532:
> #0: ffff888139fa4408 (&type->i_mutex_dir_key#10){.+.+}-{4:4}, at: walk_component (fs/namei.c:1663 fs/namei.c:1959)
> #1: ffffffffab870c40 (rcu_read_lock){....}-{1:3}, at: __queue_work (./arch/x86/include/asm/preempt.h:80 ./include/linux/rcupdate.h:68 ./include/linux/rcupdate.h:685 kernel/workqueue.c:1421)
> #2: ffff888374f36cd8 (&pool->lock){-.-.}-{2:2}, at: __queue_work (kernel/workqueue.c:1466)
> stack backtrace:
> CPU: 14 PID: 532 Comm: snap Not tainted 5.14.0-rc7+ #8
> Hardware name: LENOVO 90Q30008US/3728, BIOS O4ZKT1CA 09/16/2020
> Call Trace:
> dump_stack_lvl (lib/dump_stack.c:106 (discriminator 4))
> dump_stack (lib/dump_stack.c:113)
> __lock_acquire.cold (kernel/locking/lockdep.c:4666 kernel/locking/lockdep.c:4727 kernel/locking/lockdep.c:4965)
> ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4873)
> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
> lock_acquire (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5627 kernel/locking/lockdep.c:5590)
> ? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
> ? lock_release (kernel/locking/lockdep.c:5593)
> ? __kasan_check_read (mm/kasan/shadow.c:32)
> ? __lock_acquire (kernel/locking/lockdep.c:5019)
> ? __zone_watermark_ok (./include/linux/list.h:282 ./include/linux/mmzone.h:111 mm/page_alloc.c:3908)
> get_page_from_freelist (./include/linux/local_lock_internal.h:43 mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
> ? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
> ? is_bpf_text_address (./arch/x86/include/asm/preempt.h:85 ./include/linux/rcupdate.h:73 ./include/linux/rcupdate.h:719 kernel/bpf/core.c:708)
> ? lock_downgrade (kernel/locking/lockdep.c:5633)
> ? __zone_watermark_ok (mm/page_alloc.c:4054)
> __alloc_pages (mm/page_alloc.c:5391)
> ? __alloc_pages_slowpath.constprop.0 (mm/page_alloc.c:5354)
> ? create_prof_cpu_mask (kernel/stacktrace.c:82)
> ? _find_first_bit (lib/find_bit.c:83)
> alloc_pages (mm/mempolicy.c:2249)
> stack_depot_save (lib/stackdepot.c:304)
> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
> kasan_save_stack (mm/kasan/common.c:41)
> ? kasan_save_stack (mm/kasan/common.c:39)
> ? kasan_record_aux_stack (mm/kasan/generic.c:348)
> ? insert_work (./include/linux/instrumented.h:71 ./include/asm-generic/bitops/instrumented-non-atomic.h:134 kernel/workqueue.c:616 kernel/workqueue.c:623 kernel/workqueue.c:1335)
> ? __queue_work (kernel/workqueue.c:1501)
> ? __queue_delayed_work (kernel/workqueue.c:1657)
> ? mod_delayed_work_on (kernel/workqueue.c:1720)
> ? kblockd_mod_delayed_work_on (block/blk-core.c:1633)
> ? __blk_mq_delay_run_hw_queue (block/blk-mq.c:1567)
> ? blk_mq_run_hw_queue (block/blk-mq.c:1610)
> ? blk_mq_sched_insert_request (block/blk-mq-sched.c:480)
> ? blk_mq_submit_bio (block/blk-mq.c:2276)
>
> Fixes: e89a85d63fb2 ("workqueue: kasan: record workqueue stack")
> Signed-off-by: Shuah Khan <skhan@linuxfoundation.org>
> ---
> kernel/workqueue.c | 18 +++++++++++++++---
> 1 file changed, 15 insertions(+), 3 deletions(-)
>
> diff --git a/kernel/workqueue.c b/kernel/workqueue.c
> index f148eacda55a..e647b29b9fb0 100644
> --- a/kernel/workqueue.c
> +++ b/kernel/workqueue.c
> @@ -1328,9 +1328,6 @@ static void insert_work(struct pool_workqueue *pwq, struct work_struct *work,
> {
> struct worker_pool *pool = pwq->pool;
>
> - /* record the work call stack in order to print it in KASAN reports */
> - kasan_record_aux_stack(work);
> -
> /* we own @work, set data and link */
> set_work_pwq(work, pwq, extra_flags);
> list_add_tail(&work->entry, head);
> @@ -1499,6 +1496,14 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
>
> out:
> raw_spin_unlock(&pwq->pool->lock);
> +
> + /*
> + * record the work call stack in order to print it in KASAN reports
> + * Do this without pool raw_spinlock hold to avoid nesting raw
> + * spinlock with page allocation spinlock.
> + */
> + kasan_record_aux_stack(work);
> +
Hello
After the pool lock is released, the work item can be executed and be freed
before kasan_record_aux_stack() is called. Is it Ok?
And I think queue_work() is allowed to be called with other raw_spin held.
If it is the case, kasan_record_aux_stack() is still in raw_spin held section.
Thanks
Lai
> rcu_read_unlock();
> }
>
> @@ -3012,6 +3017,13 @@ static bool start_flush_work(struct work_struct *work, struct wq_barrier *barr,
> insert_wq_barrier(pwq, barr, work, worker);
> raw_spin_unlock_irq(&pool->lock);
>
> + /*
> + * record the work call stack in order to print it in KASAN reports
> + * Do this without pool raw_spinlock hold to avoid nesting raw
> + * spinlock with page allocation spinlock.
> + */
> + kasan_record_aux_stack(work);
> +
> /*
> * Force a lock recursion deadlock when using flush_work() inside a
> * single-threaded or rescuer equipped workqueue.
> --
> 2.30.2
>
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] workqueue: Don't record workqueue stack holding raw_spin_lock
2021-08-27 23:49 [PATCH] workqueue: Don't record workqueue stack holding raw_spin_lock Shuah Khan
2021-08-30 2:18 ` Lai Jiangshan
@ 2021-08-30 5:40 ` Dmitry Vyukov
2021-08-30 16:47 ` Shuah Khan
1 sibling, 1 reply; 5+ messages in thread
From: Dmitry Vyukov @ 2021-08-30 5:40 UTC (permalink / raw)
To: Shuah Khan; +Cc: tj, jiangshanlai, elver, akpm, walter-zh.wu, linux-kernel
On Sat, 28 Aug 2021 at 01:49, Shuah Khan <skhan@linuxfoundation.org> wrote:
>
> When CONFIG_PROVE_RAW_LOCK_NESTING and CONFIG_KASAN are enabled,
> kasan_record_aux_stack() runs into "BUG: Invalid wait context" when
> it tries to allocate memory attempting to acquire spinlock in page
> allocation code while holding workqueue pool raw_spinlock.
>
> There are several instances of this problem when block layer tries
> to __queue_work(). Call trace from one of these instances is below:
>
> kblockd_mod_delayed_work_on()
> mod_delayed_work_on()
> __queue_delayed_work()
> __queue_work() (rcu_read_lock, raw_spin_lock pool->lock held)
> insert_work()
> kasan_record_aux_stack()
> kasan_save_stack()
> stack_depot_save()
> alloc_pages()
> __alloc_pages()
> get_page_from_freelist()
> rm_queue()
> rm_queue_pcplist()
> local_lock_irqsave(&pagesets.lock, flags);
> [ BUG: Invalid wait context triggered ]
>
> Fix it by calling kasan_record_aux_stack() without holding pool lock.
> There is no need to hold pool lock in this path.
>
> =============================
> [ BUG: Invalid wait context ]
> 5.14.0-rc7+ #8 Not tainted
> -----------------------------
> snap/532 is trying to lock:
> ffff888374f32ba0 (lock#2){..-.}-{3:3}, at: get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
> other info that might help us debug this:
> context-{5:5}
> 3 locks held by snap/532:
> #0: ffff888139fa4408 (&type->i_mutex_dir_key#10){.+.+}-{4:4}, at: walk_component (fs/namei.c:1663 fs/namei.c:1959)
> #1: ffffffffab870c40 (rcu_read_lock){....}-{1:3}, at: __queue_work (./arch/x86/include/asm/preempt.h:80 ./include/linux/rcupdate.h:68 ./include/linux/rcupdate.h:685 kernel/workqueue.c:1421)
> #2: ffff888374f36cd8 (&pool->lock){-.-.}-{2:2}, at: __queue_work (kernel/workqueue.c:1466)
> stack backtrace:
> CPU: 14 PID: 532 Comm: snap Not tainted 5.14.0-rc7+ #8
> Hardware name: LENOVO 90Q30008US/3728, BIOS O4ZKT1CA 09/16/2020
> Call Trace:
> dump_stack_lvl (lib/dump_stack.c:106 (discriminator 4))
> dump_stack (lib/dump_stack.c:113)
> __lock_acquire.cold (kernel/locking/lockdep.c:4666 kernel/locking/lockdep.c:4727 kernel/locking/lockdep.c:4965)
> ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4873)
> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
> lock_acquire (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5627 kernel/locking/lockdep.c:5590)
> ? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
> ? lock_release (kernel/locking/lockdep.c:5593)
> ? __kasan_check_read (mm/kasan/shadow.c:32)
> ? __lock_acquire (kernel/locking/lockdep.c:5019)
> ? __zone_watermark_ok (./include/linux/list.h:282 ./include/linux/mmzone.h:111 mm/page_alloc.c:3908)
> get_page_from_freelist (./include/linux/local_lock_internal.h:43 mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
> ? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
> ? is_bpf_text_address (./arch/x86/include/asm/preempt.h:85 ./include/linux/rcupdate.h:73 ./include/linux/rcupdate.h:719 kernel/bpf/core.c:708)
> ? lock_downgrade (kernel/locking/lockdep.c:5633)
> ? __zone_watermark_ok (mm/page_alloc.c:4054)
> __alloc_pages (mm/page_alloc.c:5391)
> ? __alloc_pages_slowpath.constprop.0 (mm/page_alloc.c:5354)
> ? create_prof_cpu_mask (kernel/stacktrace.c:82)
> ? _find_first_bit (lib/find_bit.c:83)
> alloc_pages (mm/mempolicy.c:2249)
> stack_depot_save (lib/stackdepot.c:304)
> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
> kasan_save_stack (mm/kasan/common.c:41)
> ? kasan_save_stack (mm/kasan/common.c:39)
> ? kasan_record_aux_stack (mm/kasan/generic.c:348)
> ? insert_work (./include/linux/instrumented.h:71 ./include/asm-generic/bitops/instrumented-non-atomic.h:134 kernel/workqueue.c:616 kernel/workqueue.c:623 kernel/workqueue.c:1335)
> ? __queue_work (kernel/workqueue.c:1501)
> ? __queue_delayed_work (kernel/workqueue.c:1657)
> ? mod_delayed_work_on (kernel/workqueue.c:1720)
> ? kblockd_mod_delayed_work_on (block/blk-core.c:1633)
> ? __blk_mq_delay_run_hw_queue (block/blk-mq.c:1567)
> ? blk_mq_run_hw_queue (block/blk-mq.c:1610)
> ? blk_mq_sched_insert_request (block/blk-mq-sched.c:480)
> ? blk_mq_submit_bio (block/blk-mq.c:2276)
>
> Fixes: e89a85d63fb2 ("workqueue: kasan: record workqueue stack")
> Signed-off-by: Shuah Khan <skhan@linuxfoundation.org>
> ---
> kernel/workqueue.c | 18 +++++++++++++++---
> 1 file changed, 15 insertions(+), 3 deletions(-)
>
> diff --git a/kernel/workqueue.c b/kernel/workqueue.c
> index f148eacda55a..e647b29b9fb0 100644
> --- a/kernel/workqueue.c
> +++ b/kernel/workqueue.c
> @@ -1328,9 +1328,6 @@ static void insert_work(struct pool_workqueue *pwq, struct work_struct *work,
> {
> struct worker_pool *pool = pwq->pool;
>
> - /* record the work call stack in order to print it in KASAN reports */
> - kasan_record_aux_stack(work);
> -
> /* we own @work, set data and link */
> set_work_pwq(work, pwq, extra_flags);
> list_add_tail(&work->entry, head);
> @@ -1499,6 +1496,14 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
>
> out:
> raw_spin_unlock(&pwq->pool->lock);
> +
> + /*
> + * record the work call stack in order to print it in KASAN reports
> + * Do this without pool raw_spinlock hold to avoid nesting raw
> + * spinlock with page allocation spinlock.
> + */
> + kasan_record_aux_stack(work);
Hi Shuah,
I agree that the current code is problematic and we don't need to hold
the lock around kasan_record_aux_stack().
However, I think we need to call kasan_record_aux_stack() before the
actual queueing, otherwise the work can be dequeued and cause a bug
before we call kasan_record_aux_stack() in this task (it's like
setting permissions on an fd after publishing it in fd table).
Also, this happens after "out:" label and it seems we go to it even if
we don't queue the work in some cases. Ideally we only call
kasan_record_aux_stack() only if we queue it, because the capacity for
aux stacks are only 2 stacks (the oldest gets evicted). However, I
think the first point is more important. So if move
kasan_record_aux_stack() to happen before insert_work() and won't be
able to predict if we actually queue it later or not, then I think
it's fine to episodically call kasan_record_aux_stack() even if we
don't queue later. At least I don't see a better solution.
> rcu_read_unlock();
> }
>
> @@ -3012,6 +3017,13 @@ static bool start_flush_work(struct work_struct *work, struct wq_barrier *barr,
> insert_wq_barrier(pwq, barr, work, worker);
> raw_spin_unlock_irq(&pool->lock);
>
> + /*
> + * record the work call stack in order to print it in KASAN reports
> + * Do this without pool raw_spinlock hold to avoid nesting raw
> + * spinlock with page allocation spinlock.
> + */
> + kasan_record_aux_stack(work);
> +
> /*
> * Force a lock recursion deadlock when using flush_work() inside a
> * single-threaded or rescuer equipped workqueue.
> --
> 2.30.2
>
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] workqueue: Don't record workqueue stack holding raw_spin_lock
2021-08-30 2:18 ` Lai Jiangshan
@ 2021-08-30 16:27 ` Shuah Khan
0 siblings, 0 replies; 5+ messages in thread
From: Shuah Khan @ 2021-08-30 16:27 UTC (permalink / raw)
To: Lai Jiangshan
Cc: Tejun Heo, Marco Elver, Andrew Morton, Dmitry Vyukov,
walter-zh.wu, LKML, Shuah Khan
On 8/29/21 8:18 PM, Lai Jiangshan wrote:
> On Sat, Aug 28, 2021 at 7:49 AM Shuah Khan <skhan@linuxfoundation.org> wrote:
>>
>> When CONFIG_PROVE_RAW_LOCK_NESTING and CONFIG_KASAN are enabled,
>> kasan_record_aux_stack() runs into "BUG: Invalid wait context" when
>> it tries to allocate memory attempting to acquire spinlock in page
>> allocation code while holding workqueue pool raw_spinlock.
>>
>> There are several instances of this problem when block layer tries
>> to __queue_work(). Call trace from one of these instances is below:
>>
>> kblockd_mod_delayed_work_on()
>> mod_delayed_work_on()
>> __queue_delayed_work()
>> __queue_work() (rcu_read_lock, raw_spin_lock pool->lock held)
>> insert_work()
>> kasan_record_aux_stack()
>> kasan_save_stack()
>> stack_depot_save()
>> alloc_pages()
>> __alloc_pages()
>> get_page_from_freelist()
>> rm_queue()
>> rm_queue_pcplist()
>> local_lock_irqsave(&pagesets.lock, flags);
>> [ BUG: Invalid wait context triggered ]
>>
>> Fix it by calling kasan_record_aux_stack() without holding pool lock.
>> There is no need to hold pool lock in this path.
>>
>> =============================
>> [ BUG: Invalid wait context ]
>> 5.14.0-rc7+ #8 Not tainted
>> -----------------------------
>> snap/532 is trying to lock:
>> ffff888374f32ba0 (lock#2){..-.}-{3:3}, at: get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
>> other info that might help us debug this:
>> context-{5:5}
>> 3 locks held by snap/532:
>> #0: ffff888139fa4408 (&type->i_mutex_dir_key#10){.+.+}-{4:4}, at: walk_component (fs/namei.c:1663 fs/namei.c:1959)
>> #1: ffffffffab870c40 (rcu_read_lock){....}-{1:3}, at: __queue_work (./arch/x86/include/asm/preempt.h:80 ./include/linux/rcupdate.h:68 ./include/linux/rcupdate.h:685 kernel/workqueue.c:1421)
>> #2: ffff888374f36cd8 (&pool->lock){-.-.}-{2:2}, at: __queue_work (kernel/workqueue.c:1466)
>> stack backtrace:
>> CPU: 14 PID: 532 Comm: snap Not tainted 5.14.0-rc7+ #8
>> Hardware name: LENOVO 90Q30008US/3728, BIOS O4ZKT1CA 09/16/2020
>> Call Trace:
>> dump_stack_lvl (lib/dump_stack.c:106 (discriminator 4))
>> dump_stack (lib/dump_stack.c:113)
>> __lock_acquire.cold (kernel/locking/lockdep.c:4666 kernel/locking/lockdep.c:4727 kernel/locking/lockdep.c:4965)
>> ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4873)
>> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
>> lock_acquire (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5627 kernel/locking/lockdep.c:5590)
>> ? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
>> ? lock_release (kernel/locking/lockdep.c:5593)
>> ? __kasan_check_read (mm/kasan/shadow.c:32)
>> ? __lock_acquire (kernel/locking/lockdep.c:5019)
>> ? __zone_watermark_ok (./include/linux/list.h:282 ./include/linux/mmzone.h:111 mm/page_alloc.c:3908)
>> get_page_from_freelist (./include/linux/local_lock_internal.h:43 mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
>> ? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
>> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
>> ? is_bpf_text_address (./arch/x86/include/asm/preempt.h:85 ./include/linux/rcupdate.h:73 ./include/linux/rcupdate.h:719 kernel/bpf/core.c:708)
>> ? lock_downgrade (kernel/locking/lockdep.c:5633)
>> ? __zone_watermark_ok (mm/page_alloc.c:4054)
>> __alloc_pages (mm/page_alloc.c:5391)
>> ? __alloc_pages_slowpath.constprop.0 (mm/page_alloc.c:5354)
>> ? create_prof_cpu_mask (kernel/stacktrace.c:82)
>> ? _find_first_bit (lib/find_bit.c:83)
>> alloc_pages (mm/mempolicy.c:2249)
>> stack_depot_save (lib/stackdepot.c:304)
>> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
>> kasan_save_stack (mm/kasan/common.c:41)
>> ? kasan_save_stack (mm/kasan/common.c:39)
>> ? kasan_record_aux_stack (mm/kasan/generic.c:348)
>> ? insert_work (./include/linux/instrumented.h:71 ./include/asm-generic/bitops/instrumented-non-atomic.h:134 kernel/workqueue.c:616 kernel/workqueue.c:623 kernel/workqueue.c:1335)
>> ? __queue_work (kernel/workqueue.c:1501)
>> ? __queue_delayed_work (kernel/workqueue.c:1657)
>> ? mod_delayed_work_on (kernel/workqueue.c:1720)
>> ? kblockd_mod_delayed_work_on (block/blk-core.c:1633)
>> ? __blk_mq_delay_run_hw_queue (block/blk-mq.c:1567)
>> ? blk_mq_run_hw_queue (block/blk-mq.c:1610)
>> ? blk_mq_sched_insert_request (block/blk-mq-sched.c:480)
>> ? blk_mq_submit_bio (block/blk-mq.c:2276)
>>
>> Fixes: e89a85d63fb2 ("workqueue: kasan: record workqueue stack")
>> Signed-off-by: Shuah Khan <skhan@linuxfoundation.org>
>> ---
>> kernel/workqueue.c | 18 +++++++++++++++---
>> 1 file changed, 15 insertions(+), 3 deletions(-)
>>
>> diff --git a/kernel/workqueue.c b/kernel/workqueue.c
>> index f148eacda55a..e647b29b9fb0 100644
>> --- a/kernel/workqueue.c
>> +++ b/kernel/workqueue.c
>> @@ -1328,9 +1328,6 @@ static void insert_work(struct pool_workqueue *pwq, struct work_struct *work,
>> {
>> struct worker_pool *pool = pwq->pool;
>>
>> - /* record the work call stack in order to print it in KASAN reports */
>> - kasan_record_aux_stack(work);
>> -
>> /* we own @work, set data and link */
>> set_work_pwq(work, pwq, extra_flags);
>> list_add_tail(&work->entry, head);
>> @@ -1499,6 +1496,14 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
>>
>> out:
>> raw_spin_unlock(&pwq->pool->lock);
>> +
>> + /*
>> + * record the work call stack in order to print it in KASAN reports
>> + * Do this without pool raw_spinlock hold to avoid nesting raw
>> + * spinlock with page allocation spinlock.
>> + */
>> + kasan_record_aux_stack(work);
>> +
>
> Hello
>
> After the pool lock is released, the work item can be executed and be freed
> before kasan_record_aux_stack() is called. Is it Ok?
>
Right. That is a concern. As Dmitry pointed out there is a bug in the
code that kasan_record_aux_stack() is in the "out:" path.
> And I think queue_work() is allowed to be called with other raw_spin held.
> If it is the case, kasan_record_aux_stack() is still in raw_spin held section.
>
I looked for queue_work() -> queue_work_on() -> __queue_work() and
function header doc. I couldn't find any place it says it is okay to
call queue_work() with raw spinlock held.
I am thinking that is not the case, since __queue_work() acquires pool
lock which is a raw spinlock. The lockdep warning will occur when the
pool lock acquire happens. I haven't seen it. We have 1290 callers of
queue_work() and we would have seen this before.
thanks,
-- Shuah
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: [PATCH] workqueue: Don't record workqueue stack holding raw_spin_lock
2021-08-30 5:40 ` Dmitry Vyukov
@ 2021-08-30 16:47 ` Shuah Khan
0 siblings, 0 replies; 5+ messages in thread
From: Shuah Khan @ 2021-08-30 16:47 UTC (permalink / raw)
To: Dmitry Vyukov
Cc: tj, jiangshanlai, elver, akpm, walter-zh.wu, linux-kernel, Shuah Khan
On 8/29/21 11:40 PM, Dmitry Vyukov wrote:
> On Sat, 28 Aug 2021 at 01:49, Shuah Khan <skhan@linuxfoundation.org> wrote:
>>
>> When CONFIG_PROVE_RAW_LOCK_NESTING and CONFIG_KASAN are enabled,
>> kasan_record_aux_stack() runs into "BUG: Invalid wait context" when
>> it tries to allocate memory attempting to acquire spinlock in page
>> allocation code while holding workqueue pool raw_spinlock.
>>
>> There are several instances of this problem when block layer tries
>> to __queue_work(). Call trace from one of these instances is below:
>>
>> kblockd_mod_delayed_work_on()
>> mod_delayed_work_on()
>> __queue_delayed_work()
>> __queue_work() (rcu_read_lock, raw_spin_lock pool->lock held)
>> insert_work()
>> kasan_record_aux_stack()
>> kasan_save_stack()
>> stack_depot_save()
>> alloc_pages()
>> __alloc_pages()
>> get_page_from_freelist()
>> rm_queue()
>> rm_queue_pcplist()
>> local_lock_irqsave(&pagesets.lock, flags);
>> [ BUG: Invalid wait context triggered ]
>>
>> Fix it by calling kasan_record_aux_stack() without holding pool lock.
>> There is no need to hold pool lock in this path.
>>
>> =============================
>> [ BUG: Invalid wait context ]
>> 5.14.0-rc7+ #8 Not tainted
>> -----------------------------
>> snap/532 is trying to lock:
>> ffff888374f32ba0 (lock#2){..-.}-{3:3}, at: get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
>> other info that might help us debug this:
>> context-{5:5}
>> 3 locks held by snap/532:
>> #0: ffff888139fa4408 (&type->i_mutex_dir_key#10){.+.+}-{4:4}, at: walk_component (fs/namei.c:1663 fs/namei.c:1959)
>> #1: ffffffffab870c40 (rcu_read_lock){....}-{1:3}, at: __queue_work (./arch/x86/include/asm/preempt.h:80 ./include/linux/rcupdate.h:68 ./include/linux/rcupdate.h:685 kernel/workqueue.c:1421)
>> #2: ffff888374f36cd8 (&pool->lock){-.-.}-{2:2}, at: __queue_work (kernel/workqueue.c:1466)
>> stack backtrace:
>> CPU: 14 PID: 532 Comm: snap Not tainted 5.14.0-rc7+ #8
>> Hardware name: LENOVO 90Q30008US/3728, BIOS O4ZKT1CA 09/16/2020
>> Call Trace:
>> dump_stack_lvl (lib/dump_stack.c:106 (discriminator 4))
>> dump_stack (lib/dump_stack.c:113)
>> __lock_acquire.cold (kernel/locking/lockdep.c:4666 kernel/locking/lockdep.c:4727 kernel/locking/lockdep.c:4965)
>> ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4873)
>> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
>> lock_acquire (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5627 kernel/locking/lockdep.c:5590)
>> ? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
>> ? lock_release (kernel/locking/lockdep.c:5593)
>> ? __kasan_check_read (mm/kasan/shadow.c:32)
>> ? __lock_acquire (kernel/locking/lockdep.c:5019)
>> ? __zone_watermark_ok (./include/linux/list.h:282 ./include/linux/mmzone.h:111 mm/page_alloc.c:3908)
>> get_page_from_freelist (./include/linux/local_lock_internal.h:43 mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
>> ? get_page_from_freelist (mm/page_alloc.c:3665 mm/page_alloc.c:3703 mm/page_alloc.c:4165)
>> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
>> ? is_bpf_text_address (./arch/x86/include/asm/preempt.h:85 ./include/linux/rcupdate.h:73 ./include/linux/rcupdate.h:719 kernel/bpf/core.c:708)
>> ? lock_downgrade (kernel/locking/lockdep.c:5633)
>> ? __zone_watermark_ok (mm/page_alloc.c:4054)
>> __alloc_pages (mm/page_alloc.c:5391)
>> ? __alloc_pages_slowpath.constprop.0 (mm/page_alloc.c:5354)
>> ? create_prof_cpu_mask (kernel/stacktrace.c:82)
>> ? _find_first_bit (lib/find_bit.c:83)
>> alloc_pages (mm/mempolicy.c:2249)
>> stack_depot_save (lib/stackdepot.c:304)
>> ? lock_is_held_type (kernel/locking/lockdep.c:5368 kernel/locking/lockdep.c:5668)
>> kasan_save_stack (mm/kasan/common.c:41)
>> ? kasan_save_stack (mm/kasan/common.c:39)
>> ? kasan_record_aux_stack (mm/kasan/generic.c:348)
>> ? insert_work (./include/linux/instrumented.h:71 ./include/asm-generic/bitops/instrumented-non-atomic.h:134 kernel/workqueue.c:616 kernel/workqueue.c:623 kernel/workqueue.c:1335)
>> ? __queue_work (kernel/workqueue.c:1501)
>> ? __queue_delayed_work (kernel/workqueue.c:1657)
>> ? mod_delayed_work_on (kernel/workqueue.c:1720)
>> ? kblockd_mod_delayed_work_on (block/blk-core.c:1633)
>> ? __blk_mq_delay_run_hw_queue (block/blk-mq.c:1567)
>> ? blk_mq_run_hw_queue (block/blk-mq.c:1610)
>> ? blk_mq_sched_insert_request (block/blk-mq-sched.c:480)
>> ? blk_mq_submit_bio (block/blk-mq.c:2276)
>>
>> Fixes: e89a85d63fb2 ("workqueue: kasan: record workqueue stack")
>> Signed-off-by: Shuah Khan <skhan@linuxfoundation.org>
>> ---
>> kernel/workqueue.c | 18 +++++++++++++++---
>> 1 file changed, 15 insertions(+), 3 deletions(-)
>>
>> diff --git a/kernel/workqueue.c b/kernel/workqueue.c
>> index f148eacda55a..e647b29b9fb0 100644
>> --- a/kernel/workqueue.c
>> +++ b/kernel/workqueue.c
>> @@ -1328,9 +1328,6 @@ static void insert_work(struct pool_workqueue *pwq, struct work_struct *work,
>> {
>> struct worker_pool *pool = pwq->pool;
>>
>> - /* record the work call stack in order to print it in KASAN reports */
>> - kasan_record_aux_stack(work);
>> -
>> /* we own @work, set data and link */
>> set_work_pwq(work, pwq, extra_flags);
>> list_add_tail(&work->entry, head);
>> @@ -1499,6 +1496,14 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
>>
>> out:
>> raw_spin_unlock(&pwq->pool->lock);
>> +
>> + /*
>> + * record the work call stack in order to print it in KASAN reports
>> + * Do this without pool raw_spinlock hold to avoid nesting raw
>> + * spinlock with page allocation spinlock.
>> + */
>> + kasan_record_aux_stack(work);
>
> Hi Shuah,
>
> I agree that the current code is problematic and we don't need to hold
> the lock around kasan_record_aux_stack().
>
Good.
> However, I think we need to call kasan_record_aux_stack() before the
> actual queueing, otherwise the work can be dequeued and cause a bug
> before we call kasan_record_aux_stack() in this task (it's like
> setting permissions on an fd after publishing it in fd table).
>
You are right. This patch does change the order of recording by moving
from insert_work(). I couldn't find a unrecord step in the current
code? Where does that happen? Is it necessary to deallocate and do
other cleanup when work gets dequeued?
> Also, this happens after "out:" label and it seems we go to it even if
> we don't queue the work in some cases. Ideally we only call
> kasan_record_aux_stack() only if we queue it, because the capacity for
> aux stacks are only 2 stacks (the oldest gets evicted). However, I
> think the first point is more important. So if move
> kasan_record_aux_stack() to happen before insert_work() and won't be
> able to predict if we actually queue it later or not, then I think
> it's fine to episodically call kasan_record_aux_stack() even if we
> don't queue later. At least I don't see a better solution.
>
>
Yeah. I missed that. I was careful with the start_flush_work() out leg.
thanks,
-- Shuah
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2021-08-30 16:47 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-08-27 23:49 [PATCH] workqueue: Don't record workqueue stack holding raw_spin_lock Shuah Khan
2021-08-30 2:18 ` Lai Jiangshan
2021-08-30 16:27 ` Shuah Khan
2021-08-30 5:40 ` Dmitry Vyukov
2021-08-30 16:47 ` Shuah Khan
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).