When CONFIG_PROVE_RAW_LOCK_NESTING=y 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() conditionally only when
CONFIG_PROVE_RAW_LOCK_NESTING is not enabled. After exploring other
options such as calling kasan_record_aux_stack() after releasing the
pool lock, opting for a least disruptive path of stubbing this record
function to avoid nesting raw spinlock and spinlock.
=============================
[ 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 <[email protected]>
---
Changes since v1:
-- Instead of changing when record happens, disable record
when CONFIG_PROVE_RAW_LOCK_NESTING=y
kernel/workqueue.c | 10 +++++++++-
1 file changed, 9 insertions(+), 1 deletion(-)
diff --git a/kernel/workqueue.c b/kernel/workqueue.c
index f148eacda55a..435970ef81ae 100644
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -1328,8 +1328,16 @@ 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 */
+ /*
+ * record the work call stack in order to print it in KASAN reports
+ * Doing this when CONFIG_PROVE_RAW_LOCK_NESTING is enabled results
+ * in nesting raw spinlock with page allocation spinlock.
+ *
+ * Avoid recording when CONFIG_PROVE_RAW_LOCK_NESTING is enabled.
+ */
+#if !defined(CONFIG_PROVE_RAW_LOCK_NESTING)
kasan_record_aux_stack(work);
+#endif
/* we own @work, set data and link */
set_work_pwq(work, pwq, extra_flags);
--
2.30.2
On Thu, 2 Sept 2021 at 22:01, Shuah Khan <[email protected]> wrote:
>
> When CONFIG_PROVE_RAW_LOCK_NESTING=y 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() conditionally only when
> CONFIG_PROVE_RAW_LOCK_NESTING is not enabled. After exploring other
> options such as calling kasan_record_aux_stack() after releasing the
> pool lock, opting for a least disruptive path of stubbing this record
> function to avoid nesting raw spinlock and spinlock.
>
> =============================
> [ 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 <[email protected]>
> ---
> Changes since v1:
> -- Instead of changing when record happens, disable record
> when CONFIG_PROVE_RAW_LOCK_NESTING=y
>
> kernel/workqueue.c | 10 +++++++++-
> 1 file changed, 9 insertions(+), 1 deletion(-)
>
> diff --git a/kernel/workqueue.c b/kernel/workqueue.c
> index f148eacda55a..435970ef81ae 100644
> --- a/kernel/workqueue.c
> +++ b/kernel/workqueue.c
> @@ -1328,8 +1328,16 @@ 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 */
> + /*
> + * record the work call stack in order to print it in KASAN reports
> + * Doing this when CONFIG_PROVE_RAW_LOCK_NESTING is enabled results
> + * in nesting raw spinlock with page allocation spinlock.
> + *
> + * Avoid recording when CONFIG_PROVE_RAW_LOCK_NESTING is enabled.
> + */
> +#if !defined(CONFIG_PROVE_RAW_LOCK_NESTING)
Just "if (!IS_ENABLED(CONFIG_PROVE_RAW_LOCK_NESTING))" should work
here, however...
... PROVE_RAW_LOCK_NESTING exists for PREEMPT_RT's benefit. I don't
think silencing the debugging tool is the solution, because the bug
still exists in a PREEMPT_RT kernel.
+Cc Sebastian for advice. I may have missed something obvious. :-)
I have a suspicion that kasan_record_aux_stack() (via
stack_depot_save()) is generally unsound on PREEMPT_RT kernels,
because allocating memory cannot be done within raw-locked critical
sections because memory allocation is preemptible on RT. Even using
GWP_NOWAIT/ATOMIC doesn't help (which kasan_record_aux_stack() uses).
It follows that if we do not know what type of locks may be held when
calling kasan_record_aux_stack() we have a bug in RT.
I see 3 options:
1. Try to move kasan_record_aux_stack() where no raw lock is held.
(Seems complicated per v1 attempt?)
But ideally we make kasan_record_aux_stack() more robust on RT:
2. Make kasan_record_aux_stack() a no-op on RT (and if
PROVE_RAW_LOCK_NESTING). Perhaps overkill?
3. Try to not allocate memory in stackdepot. Not sure this is feasible
without telling stackdepot to preallocate the max slabs on boot if RT.
Anything else? Because I don't think any of the options are satisfying.
Thanks,
-- Marco
> kasan_record_aux_stack(work);
> +#endif
>
> /* we own @work, set data and link */
> set_work_pwq(work, pwq, extra_flags);
> --
> 2.30.2
>
On 9/2/21 3:58 PM, Marco Elver wrote:
> On Thu, 2 Sept 2021 at 22:01, Shuah Khan <[email protected]> wrote:
>>
>> When CONFIG_PROVE_RAW_LOCK_NESTING=y 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.
>>
[snip]
>> Fix it by calling kasan_record_aux_stack() conditionally only when
>> CONFIG_PROVE_RAW_LOCK_NESTING is not enabled. After exploring other
>> options such as calling kasan_record_aux_stack() after releasing the
>> pool lock, opting for a least disruptive path of stubbing this record
>> function to avoid nesting raw spinlock and spinlock.
>>
[snip]
>>
>> Fixes: e89a85d63fb2 ("workqueue: kasan: record workqueue stack")
>> Signed-off-by: Shuah Khan <[email protected]>
>> ---
>> Changes since v1:
>> -- Instead of changing when record happens, disable record
>> when CONFIG_PROVE_RAW_LOCK_NESTING=y
>>
>> kernel/workqueue.c | 10 +++++++++-
>> 1 file changed, 9 insertions(+), 1 deletion(-)
>>
>> diff --git a/kernel/workqueue.c b/kernel/workqueue.c
>> index f148eacda55a..435970ef81ae 100644
>> --- a/kernel/workqueue.c
>> +++ b/kernel/workqueue.c
>> @@ -1328,8 +1328,16 @@ 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 */
>> + /*
>> + * record the work call stack in order to print it in KASAN reports
>> + * Doing this when CONFIG_PROVE_RAW_LOCK_NESTING is enabled results
>> + * in nesting raw spinlock with page allocation spinlock.
>> + *
>> + * Avoid recording when CONFIG_PROVE_RAW_LOCK_NESTING is enabled.
>> + */
>> +#if !defined(CONFIG_PROVE_RAW_LOCK_NESTING)
>
> Just "if (!IS_ENABLED(CONFIG_PROVE_RAW_LOCK_NESTING))" should work
> here, however...
>
Yes. That would work.
> ... PROVE_RAW_LOCK_NESTING exists for PREEMPT_RT's benefit. I don't
> think silencing the debugging tool is the solution, because the bug
> still exists in a PREEMPT_RT kernel.
>
This silencing is limited in scope to just the insert_work() and when
PROVE_RAW_LOCK_NESTING is enabled. Please see below under your proposed
option 2
> +Cc Sebastian for advice. I may have missed something obvious. :-)
>
Thanks for adding Sebastian
> I have a suspicion that kasan_record_aux_stack() (via
> stack_depot_save()) is generally unsound on PREEMPT_RT kernels,
> because allocating memory cannot be done within raw-locked critical
> sections because memory allocation is preemptible on RT. Even using
> GWP_NOWAIT/ATOMIC doesn't help (which kasan_record_aux_stack() uses).
>
> It follows that if we do not know what type of locks may be held when
> calling kasan_record_aux_stack() we have a bug in RT.
>
> I see 3 options:
>
> 1. Try to move kasan_record_aux_stack() where no raw lock is held.
> (Seems complicated per v1 attempt?)
>
Yes. kasan_record_aux_stack() is better called from insert_work()
prior to insertion. This makes it difficult to do - we don't want
to release the pool lock.
> But ideally we make kasan_record_aux_stack() more robust on RT:
>
> 2. Make kasan_record_aux_stack() a no-op on RT (and if
> PROVE_RAW_LOCK_NESTING). Perhaps overkill?
>
I considered it and didn't go down that route because it is a big
hammer. I choose to just disable the debug code in insert_work()
path instead. Not ideal, but limits the disable to a narrower
scope. Limiting the scope in kasan_record_aux_stack() extends to
all other paths where kasan_record_aux_stack() is used.
> 3. Try to not allocate memory in stackdepot. Not sure this is feasible
> without telling stackdepot to preallocate the max slabs on boot if RT.
>
We could. I have to ask though how much of the real world cases do we
need to impact for the debug code to work?
> Anything else? Because I don't think any of the options are satisfying.
>
One option to consider is checking dry-run invalid nesting check and
bail out if it is true in kasan_record_aux_stack()
thanks,
-- Shuah
On Thu, Sep 02, 2021 at 05:46PM -0600, Shuah Khan wrote:
[...]
> > 3. Try to not allocate memory in stackdepot. Not sure this is feasible
> > without telling stackdepot to preallocate the max slabs on boot if RT.
> >
>
> We could. I have to ask though how much of the real world cases do we
> need to impact for the debug code to work?
>
> > Anything else? Because I don't think any of the options are satisfying.
>
> One option to consider is checking dry-run invalid nesting check and
> bail out if it is true in kasan_record_aux_stack()
Sadly, if lockdep is off, this won't work. And we need a way to
generically fix this, as otherwise we still have a bug (which may also
cause issues on RT kernels).
I propose we properly fix this and prevent stackdepot from replenishing
its "stack slab" pool if memory allocations cannot be done in the
current context. Specifically, I noticed technically it's a bug to use
either GFP_ATOMIC nor GFP_NOWAIT in certain non-preemptive contexts,
including raw_spin_locks (see gfp.h and ab00db216c9c7).
This is what kasan_record_aux_stack() via stackdepot does, and it's a
bug here regardless if lockdep is on or off.
I've prepared a series (see attached draft patches) that allows telling
stackdepot to not replenish its pool if alloc_pages() cannot be called
at all (where GFP_ATOMIC/NOWAIT doesn't even work).
The only downside is that saving a stack trace may fail if: stackdepot
runs out of space AND the same stack trace has not been recorded before.
I expect this to be unlikely, and a simple experiment (boot the kernel)
didn't result in any failure to record stack trace from insert_work().
I think this is a reasonable trade-off. And considering that we're
unsure if queuing work can or cannot be done from within an outer
raw_spin_lock'ed critical section, I don't see a better way.
If you agree, I'll send this series out for further review.
Thanks,
-- Marco
On 2021-09-06 09:12:58 [+0200], Marco Elver wrote:
> On Thu, Sep 02, 2021 at 05:46PM -0600, Shuah Khan wrote:
> [...]
> > > 3. Try to not allocate memory in stackdepot. Not sure this is feasible
> > > without telling stackdepot to preallocate the max slabs on boot if RT.
> > >
> >
> > We could. I have to ask though how much of the real world cases do we
> > need to impact for the debug code to work?
> >
> > > Anything else? Because I don't think any of the options are satisfying.
> >
> > One option to consider is checking dry-run invalid nesting check and
> > bail out if it is true in kasan_record_aux_stack()
>
> Sadly, if lockdep is off, this won't work. And we need a way to
> generically fix this, as otherwise we still have a bug (which may also
> cause issues on RT kernels).
>
> I propose we properly fix this and prevent stackdepot from replenishing
> its "stack slab" pool if memory allocations cannot be done in the
> current context. Specifically, I noticed technically it's a bug to use
> either GFP_ATOMIC nor GFP_NOWAIT in certain non-preemptive contexts,
> including raw_spin_locks (see gfp.h and ab00db216c9c7).
I would say so, too. It is unlikely that we manage to remove
raw_spin_lock_t from the workqueue code or that memory allocation with
disabled preemption/ interrupts would be allowed on RT.
Also as Marco pointed out, avoiding this code once a debug switch has
been noticed is not good.
> This is what kasan_record_aux_stack() via stackdepot does, and it's a
> bug here regardless if lockdep is on or off.
>
> I've prepared a series (see attached draft patches) that allows telling
> stackdepot to not replenish its pool if alloc_pages() cannot be called
> at all (where GFP_ATOMIC/NOWAIT doesn't even work).
This sounds good. debug_object has also a memory pool which is
replenished from time to time.
> The only downside is that saving a stack trace may fail if: stackdepot
> runs out of space AND the same stack trace has not been recorded before.
> I expect this to be unlikely, and a simple experiment (boot the kernel)
> didn't result in any failure to record stack trace from insert_work().
>
> I think this is a reasonable trade-off. And considering that we're
> unsure if queuing work can or cannot be done from within an outer
> raw_spin_lock'ed critical section, I don't see a better way.
>
> If you agree, I'll send this series out for further review.
>
> Thanks,
> -- Marco
Sebastian