2022-07-27 11:06:59

by Kassey Li

[permalink] [raw]
Subject: [PATCH] workqueue: avoid re-entry of pwq->pool->lock through __queue_work

[0:swapper/4]BUG: spinlock recursion on CPU#4, swapper/4/0
[0:swapper/4]lock: 0xffffff8000c0f400, .magic: dead4ead, .owner:
swapper/4/0, .owner_cpu: 4
[0:swapper/4]CPU: 4 PID: 0 Comm: swapper/4 Tainted: G S
[0:swapper/4]Call trace:
[0:swapper/4] dump_backtrace.cfi_jt+0x0/0x8
[0:swapper/4] show_stack+0x1c/0x2c
[0:swapper/4] dump_stack_lvl+0xd8/0x16c
[0:swapper/4] spin_dump+0x104/0x278
[0:swapper/4] do_raw_spin_lock+0xec/0x15c
[0:swapper/4] _raw_spin_lock+0x28/0x3c
[0:swapper/4] __queue_work+0x1fc/0x618
[0:swapper/4] queue_work_on+0x64/0x134
[0:swapper/4] memlat_hrtimer_handler+0x28/0x3c [memlat]
[0:swapper/4] __run_hrtimer+0xe8/0x448
[0:swapper/4] hrtimer_interrupt+0x184/0x40c
[0:swapper/4] arch_timer_handler_virt+0x5c/0x98
[0:swapper/4] handle_percpu_devid_irq+0xd8/0x3e0
[0:swapper/4] __handle_domain_irq+0xd0/0x19c
[0:swapper/4] gic_handle_irq+0x6c/0x134
[0:swapper/4] el1_irq+0xe4/0x1c0
[0:swapper/4] _raw_spin_unlock_irqrestore+0x2c/0x60
[0:swapper/4] try_to_wake_up.llvm.14610847381734009831+0x334/0x888
[0:swapper/4] wake_up_process+0x1c/0x2c
[0:swapper/4] __queue_work+0x3e8/0x618
[0:swapper/4] delayed_work_timer_fn+0x24/0x34
[0:swapper/4] call_timer_fn+0x58/0x268
[0:swapper/4] expire_timers+0xe0/0x1c4
[0:swapper/4] __run_timers+0x16c/0x1c4
[0:swapper/4] run_timer_softirq+0x34/0x60
[0:swapper/4] efi_header_end+0x198/0x59c
[0:swapper/4] __irq_exit_rcu+0xdc/0xf0
[0:swapper/4] irq_exit+0x14/0x50
[0:swapper/4] __handle_domain_irq+0xd4/0x19c
[0:swapper/4] gic_handle_irq+0x6c/0x134
[0:swapper/4] el1_irq+0xe4/0x1c0
[0:swapper/4] cpuidle_enter_state+0x1b4/0x5dc
[0:swapper/4] cpuidle_enter+0x3c/0x58
[0:swapper/4] do_idle.llvm.6296834828977863291+0x1f4/0x2e8
[0:swapper/4] cpu_startup_entry+0x28/0x2c
[0:swapper/4] secondary_start_kernel+0x1c8/0x230

Signed-off-by: Kassey Li <[email protected]>
---
kernel/workqueue.c | 8 ++++----
1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/kernel/workqueue.c b/kernel/workqueue.c
index 1ea50f6be843..f23491f373b1 100644
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -1468,10 +1468,10 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
} else {
/* meh... not running there, queue here */
raw_spin_unlock(&last_pool->lock);
- raw_spin_lock(&pwq->pool->lock);
+ raw_spin_lock_irq(&pwq->pool->lock);
}
} else {
- raw_spin_lock(&pwq->pool->lock);
+ raw_spin_lock_irq(&pwq->pool->lock);
}

/*
@@ -1484,7 +1484,7 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
*/
if (unlikely(!pwq->refcnt)) {
if (wq->flags & WQ_UNBOUND) {
- raw_spin_unlock(&pwq->pool->lock);
+ raw_spin_unlock_irq(&pwq->pool->lock);
cpu_relax();
goto retry;
}
@@ -1517,7 +1517,7 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
insert_work(pwq, work, worklist, work_flags);

out:
- raw_spin_unlock(&pwq->pool->lock);
+ raw_spin_unlock_irq(&pwq->pool->lock);
rcu_read_unlock();
}

--
2.17.1


2022-07-27 18:27:58

by Lai Jiangshan

[permalink] [raw]
Subject: Re: [PATCH] workqueue: avoid re-entry of pwq->pool->lock through __queue_work

On Wed, Jul 27, 2022 at 7:04 PM Kassey Li <[email protected]> wrote:
>
> [0:swapper/4]BUG: spinlock recursion on CPU#4, swapper/4/0
> [0:swapper/4]lock: 0xffffff8000c0f400, .magic: dead4ead, .owner:
> swapper/4/0, .owner_cpu: 4
> [0:swapper/4]CPU: 4 PID: 0 Comm: swapper/4 Tainted: G S
> [0:swapper/4]Call trace:
> [0:swapper/4] dump_backtrace.cfi_jt+0x0/0x8
> [0:swapper/4] show_stack+0x1c/0x2c
> [0:swapper/4] dump_stack_lvl+0xd8/0x16c
> [0:swapper/4] spin_dump+0x104/0x278
> [0:swapper/4] do_raw_spin_lock+0xec/0x15c
> [0:swapper/4] _raw_spin_lock+0x28/0x3c
> [0:swapper/4] __queue_work+0x1fc/0x618
> [0:swapper/4] queue_work_on+0x64/0x134
> [0:swapper/4] memlat_hrtimer_handler+0x28/0x3c [memlat]
> [0:swapper/4] __run_hrtimer+0xe8/0x448
> [0:swapper/4] hrtimer_interrupt+0x184/0x40c
> [0:swapper/4] arch_timer_handler_virt+0x5c/0x98
> [0:swapper/4] handle_percpu_devid_irq+0xd8/0x3e0
> [0:swapper/4] __handle_domain_irq+0xd0/0x19c
> [0:swapper/4] gic_handle_irq+0x6c/0x134
> [0:swapper/4] el1_irq+0xe4/0x1c0

It seems it is an unexpected IRQ.

> [0:swapper/4] _raw_spin_unlock_irqrestore+0x2c/0x60
> [0:swapper/4] try_to_wake_up.llvm.14610847381734009831+0x334/0x888
> [0:swapper/4] wake_up_process+0x1c/0x2c
> [0:swapper/4] __queue_work+0x3e8/0x618
> [0:swapper/4] delayed_work_timer_fn+0x24/0x34

delayed_work_timer_fn() should have been invoked with IRQ disabled
since it is TIMER_IRQSAFE.

Could you add some code to check if it is the case if possible, please?

> [0:swapper/4] call_timer_fn+0x58/0x268
> [0:swapper/4] expire_timers+0xe0/0x1c4

Or could you do a "disass expire_timers+0xe0" in GDB?

> [0:swapper/4] __run_timers+0x16c/0x1c4
> [0:swapper/4] run_timer_softirq+0x34/0x60
> [0:swapper/4] efi_header_end+0x198/0x59c
> [0:swapper/4] __irq_exit_rcu+0xdc/0xf0
> [0:swapper/4] irq_exit+0x14/0x50
> [0:swapper/4] __handle_domain_irq+0xd4/0x19c
> [0:swapper/4] gic_handle_irq+0x6c/0x134
> [0:swapper/4] el1_irq+0xe4/0x1c0
> [0:swapper/4] cpuidle_enter_state+0x1b4/0x5dc
> [0:swapper/4] cpuidle_enter+0x3c/0x58
> [0:swapper/4] do_idle.llvm.6296834828977863291+0x1f4/0x2e8
> [0:swapper/4] cpu_startup_entry+0x28/0x2c
> [0:swapper/4] secondary_start_kernel+0x1c8/0x230
>
> Signed-off-by: Kassey Li <[email protected]>
> ---
> kernel/workqueue.c | 8 ++++----
> 1 file changed, 4 insertions(+), 4 deletions(-)
>
> diff --git a/kernel/workqueue.c b/kernel/workqueue.c
> index 1ea50f6be843..f23491f373b1 100644
> --- a/kernel/workqueue.c
> +++ b/kernel/workqueue.c
> @@ -1468,10 +1468,10 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
> } else {
> /* meh... not running there, queue here */
> raw_spin_unlock(&last_pool->lock);
> - raw_spin_lock(&pwq->pool->lock);
> + raw_spin_lock_irq(&pwq->pool->lock);
> }
> } else {
> - raw_spin_lock(&pwq->pool->lock);
> + raw_spin_lock_irq(&pwq->pool->lock);
> }
>
> /*
> @@ -1484,7 +1484,7 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
> */
> if (unlikely(!pwq->refcnt)) {
> if (wq->flags & WQ_UNBOUND) {
> - raw_spin_unlock(&pwq->pool->lock);
> + raw_spin_unlock_irq(&pwq->pool->lock);

The patch is hardly correct, __queue_work() is called with irq-disabled,
this code will enable IRQ imbalanced.

> cpu_relax();
> goto retry;
> }
> @@ -1517,7 +1517,7 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
> insert_work(pwq, work, worklist, work_flags);
>
> out:
> - raw_spin_unlock(&pwq->pool->lock);
> + raw_spin_unlock_irq(&pwq->pool->lock);
> rcu_read_unlock();
> }
>
> --
> 2.17.1
>

2022-07-28 02:53:36

by Kassey Li

[permalink] [raw]
Subject: Re: [PATCH] workqueue: avoid re-entry of pwq->pool->lock through __queue_work



On 7/28/2022 12:51 AM, Lai Jiangshan wrote:
> On Wed, Jul 27, 2022 at 7:04 PM Kassey Li <[email protected]> wrote:
>>
>> [0:swapper/4]BUG: spinlock recursion on CPU#4, swapper/4/0
>> [0:swapper/4]lock: 0xffffff8000c0f400, .magic: dead4ead, .owner:
>> swapper/4/0, .owner_cpu: 4
>> [0:swapper/4]CPU: 4 PID: 0 Comm: swapper/4 Tainted: G S
>> [0:swapper/4]Call trace:
>> [0:swapper/4] dump_backtrace.cfi_jt+0x0/0x8
>> [0:swapper/4] show_stack+0x1c/0x2c
>> [0:swapper/4] dump_stack_lvl+0xd8/0x16c
>> [0:swapper/4] spin_dump+0x104/0x278
>> [0:swapper/4] do_raw_spin_lock+0xec/0x15c
>> [0:swapper/4] _raw_spin_lock+0x28/0x3c
>> [0:swapper/4] __queue_work+0x1fc/0x618
>> [0:swapper/4] queue_work_on+0x64/0x134
>> [0:swapper/4] memlat_hrtimer_handler+0x28/0x3c [memlat]
>> [0:swapper/4] __run_hrtimer+0xe8/0x448
>> [0:swapper/4] hrtimer_interrupt+0x184/0x40c
>> [0:swapper/4] arch_timer_handler_virt+0x5c/0x98
>> [0:swapper/4] handle_percpu_devid_irq+0xd8/0x3e0
>> [0:swapper/4] __handle_domain_irq+0xd0/0x19c
>> [0:swapper/4] gic_handle_irq+0x6c/0x134
>> [0:swapper/4] el1_irq+0xe4/0x1c0
>
> It seems it is an unexpected IRQ.
thanks for your suggest, we will focus on the api usage of spin_lock
where possible broken the irq enable/disable.
currently, abandon this change.
>
>> [0:swapper/4] _raw_spin_unlock_irqrestore+0x2c/0x60
>> [0:swapper/4] try_to_wake_up.llvm.14610847381734009831+0x334/0x888
>> [0:swapper/4] wake_up_process+0x1c/0x2c
>> [0:swapper/4] __queue_work+0x3e8/0x618
>> [0:swapper/4] delayed_work_timer_fn+0x24/0x34
>
> delayed_work_timer_fn() should have been invoked with IRQ disabled
> since it is TIMER_IRQSAFE.
>
> Could you add some code to check if it is the case if possible, please?
the timer flags = 0x15200004, which means TIMER_IRQSAFE is set.
#define TIMER_IRQSAFE 0x00200000

>
>> [0:swapper/4] call_timer_fn+0x58/0x268
>> [0:swapper/4] expire_timers+0xe0/0x1c4
>
> Or could you do a "disass expire_timers+0xe0" in GDB?


0xffffffc01025bf44 <+200>: tbz w8, #5, 0xffffffc01025bee4
<expire_timers+104>
0xffffffc01025bf48 <+204>: bl 0xffffffc0118093bc
<_raw_spin_unlock>
0xffffffc01025bf4c <+208>: mov x0, x23
0xffffffc01025bf50 <+212>: mov x1, x24
0xffffffc01025bf54 <+216>: mov x2, x21
0xffffffc01025bf58 <+220>: bl 0xffffffc01025c040 <call_timer_fn>
0xffffffc01025bf5c <+224>: mov x0, x20 //expire_timers+0xe0
--Type <RET> for more, q to quit, c to continue without paging--
0xffffffc01025bf60 <+228>: bl 0xffffffc011809230 <_raw_spin_lock>
0xffffffc01025bf64 <+232>: b 0xffffffc01025bf00
<expire_timers+132>

>
>> [0:swapper/4] __run_timers+0x16c/0x1c4
>> [0:swapper/4] run_timer_softirq+0x34/0x60
>> [0:swapper/4] efi_header_end+0x198/0x59c
>> [0:swapper/4] __irq_exit_rcu+0xdc/0xf0
>> [0:swapper/4] irq_exit+0x14/0x50
>> [0:swapper/4] __handle_domain_irq+0xd4/0x19c
>> [0:swapper/4] gic_handle_irq+0x6c/0x134
>> [0:swapper/4] el1_irq+0xe4/0x1c0
>> [0:swapper/4] cpuidle_enter_state+0x1b4/0x5dc
>> [0:swapper/4] cpuidle_enter+0x3c/0x58
>> [0:swapper/4] do_idle.llvm.6296834828977863291+0x1f4/0x2e8
>> [0:swapper/4] cpu_startup_entry+0x28/0x2c
>> [0:swapper/4] secondary_start_kernel+0x1c8/0x230
>>
>> Signed-off-by: Kassey Li <[email protected]>
>> ---
>> kernel/workqueue.c | 8 ++++----
>> 1 file changed, 4 insertions(+), 4 deletions(-)
>>
>> diff --git a/kernel/workqueue.c b/kernel/workqueue.c
>> index 1ea50f6be843..f23491f373b1 100644
>> --- a/kernel/workqueue.c
>> +++ b/kernel/workqueue.c
>> @@ -1468,10 +1468,10 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
>> } else {
>> /* meh... not running there, queue here */
>> raw_spin_unlock(&last_pool->lock);
>> - raw_spin_lock(&pwq->pool->lock);
>> + raw_spin_lock_irq(&pwq->pool->lock);
>> }
>> } else {
>> - raw_spin_lock(&pwq->pool->lock);
>> + raw_spin_lock_irq(&pwq->pool->lock);
>> }
>>
>> /*
>> @@ -1484,7 +1484,7 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
>> */
>> if (unlikely(!pwq->refcnt)) {
>> if (wq->flags & WQ_UNBOUND) {
>> - raw_spin_unlock(&pwq->pool->lock);
>> + raw_spin_unlock_irq(&pwq->pool->lock);
>
> The patch is hardly correct, __queue_work() is called with irq-disabled,
> this code will enable IRQ imbalanced.
>
>> cpu_relax();
>> goto retry;
>> }
>> @@ -1517,7 +1517,7 @@ static void __queue_work(int cpu, struct workqueue_struct *wq,
>> insert_work(pwq, work, worklist, work_flags);
>>
>> out:
>> - raw_spin_unlock(&pwq->pool->lock);
>> + raw_spin_unlock_irq(&pwq->pool->lock);
>> rcu_read_unlock();
>> }
>>
>> --
>> 2.17.1
>>

2022-07-28 13:40:38

by Oliver Sang

[permalink] [raw]
Subject: [workqueue] e12ce2b778: kernel_BUG_at_kernel/irq_work.c



Greeting,

FYI, we noticed the following commit (built with gcc-11):

commit: e12ce2b778076211e3a6b1a3ea41320f9bea329e ("[PATCH] workqueue: avoid re-entry of pwq->pool->lock through __queue_work")
url: https://github.com/intel-lab-lkp/linux/commits/Kassey-Li/workqueue-avoid-re-entry-of-pwq-pool-lock-through-__queue_work/20220727-190458
base: https://git.kernel.org/cgit/linux/kernel/git/tj/wq.git for-next
patch link: https://lore.kernel.org/lkml/[email protected]

in testcase: boot

on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+-------------------------------------------------------+------------+------------+
| | 8bee9dd953 | e12ce2b778 |
+-------------------------------------------------------+------------+------------+
| boot_successes | 14 | 0 |
| boot_failures | 0 | 14 |
| kernel_BUG_at_kernel/irq_work.c | 0 | 14 |
| invalid_opcode:#[##] | 0 | 14 |
| RIP:irq_work_run_list | 0 | 14 |
| Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 0 | 14 |
+-------------------------------------------------------+------------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>


[ 0.621292][ C1] ------------[ cut here ]------------
[ 0.621292][ C1] kernel BUG at kernel/irq_work.c:235!
[ 0.621292][ C1] invalid opcode: 0000 [#1] SMP PTI
[ 0.621292][ C1] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.19.0-rc1-00007-ge12ce2b77807 #1
[ 0.621292][ C1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[ 0.621292][ C1] RIP: 0010:irq_work_run_list (kernel/irq_work.c:235 (discriminator 1))
[ 0.621292][ C1] Code: 81 e3 00 02 00 00 75 22 48 8b 07 48 85 c0 74 18 48 87 1f 48 85 db 74 10 48 89 df 48 8b 1b e8 5a ff ff ff 48 85 db 75 f0 5b c3 <0f> 0b 66 66 2e 0f 1f 84 00 00 00 00 00 66 0f 1f 44 00 00 48 c7 c7
All code
========
0: 81 e3 00 02 00 00 and $0x200,%ebx
6: 75 22 jne 0x2a
8: 48 8b 07 mov (%rdi),%rax
b: 48 85 c0 test %rax,%rax
e: 74 18 je 0x28
10: 48 87 1f xchg %rbx,(%rdi)
13: 48 85 db test %rbx,%rbx
16: 74 10 je 0x28
18: 48 89 df mov %rbx,%rdi
1b: 48 8b 1b mov (%rbx),%rbx
1e: e8 5a ff ff ff callq 0xffffffffffffff7d
23: 48 85 db test %rbx,%rbx
26: 75 f0 jne 0x18
28: 5b pop %rbx
29: c3 retq
2a:* 0f 0b ud2 <-- trapping instruction
2c: 66 66 2e 0f 1f 84 00 data16 nopw %cs:0x0(%rax,%rax,1)
33: 00 00 00 00
37: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
3d: 48 rex.W
3e: c7 .byte 0xc7
3f: c7 .byte 0xc7

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 66 66 2e 0f 1f 84 00 data16 nopw %cs:0x0(%rax,%rax,1)
9: 00 00 00 00
d: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
13: 48 rex.W
14: c7 .byte 0xc7
15: c7 .byte 0xc7
[ 0.621292][ C1] RSP: 0000:ffffb2a1000d8f90 EFLAGS: 00010206
[ 0.621292][ C1] RAX: 0000000000000000 RBX: 0000000000000200 RCX: 00000000000006e0
[ 0.621292][ C1] RDX: 0000000000000000 RSI: ffff943cafd1af40 RDI: ffff943cafd275c0
[ 0.621292][ C1] RBP: 0000000000000000 R08: 000000004a98386d R09: ffff943cafd2b5b0
[ 0.621292][ C1] R10: 00000000000002b6 R11: 0000000000000000 R12: 0000000000000001
[ 0.621292][ C1] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 0.621292][ C1] FS: 0000000000000000(0000) GS:ffff943cafd00000(0000) knlGS:0000000000000000
[ 0.621292][ C1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 0.621292][ C1] CR2: 0000000000000000 CR3: 00000002c920a000 CR4: 00000000000406e0
[ 0.621292][ C1] Call Trace:
[ 0.621292][ C1] <IRQ>
[ 0.621292][ C1] update_process_times (kernel/time/timer.c:1844)
[ 0.621292][ C1] tick_periodic (kernel/time/tick-common.c:101)
[ 0.644398][ C1] tick_handle_periodic (kernel/time/tick-common.c:120)
[ 0.644398][ C1] __sysvec_apic_timer_interrupt (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 arch/x86/include/asm/trace/irq_vectors.h:41 arch/x86/kernel/apic/apic.c:1113)
[ 0.644398][ C1] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1106 (discriminator 14))
[ 0.644398][ C1] </IRQ>
[ 0.644398][ C1] <TASK>
[ 0.644398][ C1] asm_sysvec_apic_timer_interrupt (arch/x86/include/asm/idtentry.h:649)
[ 0.644398][ C1] RIP: 0010:setup_object (arch/x86/include/asm/jump_label.h:27 mm/slab.h:408 mm/slab.h:429 mm/slub.c:1268 mm/slub.c:1776)
[ 0.644398][ C1] Code: 00 00 00 00 66 66 2e 0f 1f 84 00 00 00 00 00 66 66 2e 0f 1f 84 00 00 00 00 00 66 90 0f 1f 44 00 00 41 54 49 89 f4 53 48 89 fb <66> 90 48 8b 43 48 48 85 c0 75 37 4c 89 e0 5b 41 5c c3 f7 47 08 00
All code
========
0: 00 00 add %al,(%rax)
2: 00 00 add %al,(%rax)
4: 66 66 2e 0f 1f 84 00 data16 nopw %cs:0x0(%rax,%rax,1)
b: 00 00 00 00
f: 66 66 2e 0f 1f 84 00 data16 nopw %cs:0x0(%rax,%rax,1)
16: 00 00 00 00
1a: 66 90 xchg %ax,%ax
1c: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
21: 41 54 push %r12
23: 49 89 f4 mov %rsi,%r12
26: 53 push %rbx
27: 48 89 fb mov %rdi,%rbx
2a:* 66 90 xchg %ax,%ax <-- trapping instruction
2c: 48 8b 43 48 mov 0x48(%rbx),%rax
30: 48 85 c0 test %rax,%rax
33: 75 37 jne 0x6c
35: 4c 89 e0 mov %r12,%rax
38: 5b pop %rbx
39: 41 5c pop %r12
3b: c3 retq
3c: f7 .byte 0xf7
3d: 47 08 00 rex.RXB or %r8b,(%r8)

Code starting with the faulting instruction
===========================================
0: 66 90 xchg %ax,%ax
2: 48 8b 43 48 mov 0x48(%rbx),%rax
6: 48 85 c0 test %rax,%rax
9: 75 37 jne 0x42
b: 4c 89 e0 mov %r12,%rax
e: 5b pop %rbx
f: 41 5c pop %r12
11: c3 retq
12: f7 .byte 0xf7
13: 47 08 00 rex.RXB or %r8b,(%r8)
[ 0.644398][ C1] RSP: 0000:ffffb2a100013a28 EFLAGS: 00000202
[ 0.644398][ C1] RAX: ffff9439800483c0 RBX: ffff943980042900 RCX: 0000000000000010
[ 0.644398][ C1] RDX: ffff9439800483c0 RSI: ffff943b4a2e7400 RDI: ffff943980042900
[ 0.644398][ C1] RBP: 000000000000000f R08: 00000000a9ccf0d8 R09: 000000001efa677f
[ 0.644398][ C1] R10: 00000000a48ad46d R11: 00000000251747c5 R12: ffff943b4a2e7400
[ 0.644398][ C1] R13: ffff943b4a2e7800 R14: 000000000000000d R15: fffff2f6cb28b9c0
[ 0.644398][ C1] allocate_slab (mm/slub.c:378 mm/slub.c:1902 mm/slub.c:1968)
[ 0.644398][ C1] ___slab_alloc (mm/slub.c:3002)
[ 0.644398][ C1] ? device_add (drivers/base/core.c:3261 drivers/base/core.c:3311)
[ 0.644398][ C1] kmem_cache_alloc_trace (arch/x86/include/asm/preempt.h:85 mm/slub.c:3091 mm/slub.c:3180 mm/slub.c:3222 mm/slub.c:3253)
[ 0.644398][ C1] device_add (drivers/base/core.c:3261 drivers/base/core.c:3311)
[ 0.644398][ C1] ? complete_all (kernel/sched/completion.c:64)
[ 0.644398][ C1] __pnp_add_device (drivers/pnp/core.c:184)
[ 0.644398][ C1] pnp_add_device (drivers/pnp/core.c:210)
[ 0.644398][ C1] ? kfree (mm/slub.c:3448 mm/slub.c:3508 mm/slub.c:4555)
[ 0.644398][ C1] ? decode_irq_flags (drivers/pnp/pnpacpi/rsparser.c:166)
[ 0.644398][ C1] ? acpi_walk_resources (drivers/acpi/acpica/rsxface.c:625 drivers/acpi/acpica/rsxface.c:594)
[ 0.644398][ C1] pnpacpi_add_device+0x207/0x22b
[ 0.644398][ C1] pnpacpi_add_device_handler (drivers/pnp/pnpacpi/core.c:297)
[ 0.644398][ C1] acpi_ns_get_device_callback (drivers/acpi/acpica/nsxfeval.c:938)
[ 0.644398][ C1] ? acpi_os_wait_semaphore (drivers/acpi/osl.c:1269)
[ 0.644398][ C1] acpi_ns_walk_namespace (drivers/acpi/acpica/nswalk.c:233)
[ 0.644398][ C1] ? acpi_ns_get_device_callback (drivers/acpi/acpica/nsxfeval.c:952 drivers/acpi/acpica/nsxfeval.c:926)
[ 0.644398][ C1] ? ispnpidacpi (drivers/pnp/pnpacpi/core.c:301)
[ 0.644398][ C1] acpi_get_devices (drivers/acpi/acpica/nsxfeval.c:810)
[ 0.644398][ C1] ? pnpacpi_add_device+0x22b/0x22b
[ 0.644398][ C1] pnpacpi_init (drivers/pnp/pnpacpi/core.c:309)
[ 0.644398][ C1] do_one_initcall (init/main.c:1295)
[ 0.644398][ C1] do_initcalls (init/main.c:1367 init/main.c:1384)
[ 0.644398][ C1] kernel_init_freeable (init/main.c:1614)
[ 0.644398][ C1] ? rest_init (init/main.c:1491)
[ 0.644398][ C1] kernel_init (init/main.c:1501)
[ 0.644398][ C1] ret_from_fork (arch/x86/entry/entry_64.S:308)
[ 0.644398][ C1] </TASK>
[ 0.644398][ C1] Modules linked in:
[ 0.842511][ C1] ---[ end trace 0000000000000000 ]---
[ 0.842513][ C1] RIP: 0010:irq_work_run_list (kernel/irq_work.c:235 (discriminator 1))
[ 0.842520][ C1] Code: 81 e3 00 02 00 00 75 22 48 8b 07 48 85 c0 74 18 48 87 1f 48 85 db 74 10 48 89 df 48 8b 1b e8 5a ff ff ff 48 85 db 75 f0 5b c3 <0f> 0b 66 66 2e 0f 1f 84 00 00 00 00 00 66 0f 1f 44 00 00 48 c7 c7
All code
========
0: 81 e3 00 02 00 00 and $0x200,%ebx
6: 75 22 jne 0x2a
8: 48 8b 07 mov (%rdi),%rax
b: 48 85 c0 test %rax,%rax
e: 74 18 je 0x28
10: 48 87 1f xchg %rbx,(%rdi)
13: 48 85 db test %rbx,%rbx
16: 74 10 je 0x28
18: 48 89 df mov %rbx,%rdi
1b: 48 8b 1b mov (%rbx),%rbx
1e: e8 5a ff ff ff callq 0xffffffffffffff7d
23: 48 85 db test %rbx,%rbx
26: 75 f0 jne 0x18


To reproduce:

# build kernel
cd linux
cp config-5.19.0-rc1-00007-ge12ce2b77807 .config
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 INSTALL_MOD_PATH=<mod-install-dir> modules_install
cd <mod-install-dir>
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz


git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> -m modules.cgz job-script # job-script is attached in this email

# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.



--
0-DAY CI Kernel Test Service
https://01.org/lkp



Attachments:
(No filename) (11.20 kB)
config-5.19.0-rc1-00007-ge12ce2b77807 (166.29 kB)
job-script (4.90 kB)
dmesg.xz (8.62 kB)
Download all attachments