* BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
@ 2020-10-13 11:22 syzbot
2020-10-13 13:17 ` Steven Rostedt
` (2 more replies)
0 siblings, 3 replies; 12+ messages in thread
From: syzbot @ 2020-10-13 11:22 UTC (permalink / raw)
To: linux-kernel, mingo, rostedt, syzkaller-bugs
Hello,
syzbot found the following issue on:
HEAD commit: 865c50e1 x86/uaccess: utilize CONFIG_CC_HAS_ASM_GOTO_OUTPUT
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=15112ef0500000
kernel config: https://syzkaller.appspot.com/x/.config?x=c829313274207568
dashboard link: https://syzkaller.appspot.com/bug?extid=53f8ce8bbc07924b6417
compiler: clang version 10.0.0 (https://github.com/llvm/llvm-project/ c2443155a0fb245c8f17f2c1c72b6ea391e86e81)
Unfortunately, I don't have any reproducer for this issue yet.
IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com
BUG: using __this_cpu_read() in preemptible [00000000] code: syz-executor.0/8265
caller is lockdep_hardirqs_on_prepare+0x56/0x620 kernel/locking/lockdep.c:4060
CPU: 0 PID: 8265 Comm: syz-executor.0 Not tainted 5.9.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1d6/0x29e lib/dump_stack.c:118
check_preemption_disabled+0x13c/0x140 lib/smp_processor_id.c:48
lockdep_hardirqs_on_prepare+0x56/0x620 kernel/locking/lockdep.c:4060
trace_hardirqs_on+0x6f/0x80 kernel/trace/trace_preemptirq.c:49
__bad_area_nosemaphore+0x89/0x510 arch/x86/mm/fault.c:797
handle_page_fault arch/x86/mm/fault.c:1429 [inline]
exc_page_fault+0x129/0x240 arch/x86/mm/fault.c:1482
asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:538
RIP: 0033:0x402d28
Code: 00 00 48 89 7c 24 f8 48 89 74 24 f0 48 89 54 24 e8 48 89 4c 24 e0 48 8b 74 24 f8 4c 8b 4c 24 f0 48 8b 4c 24 e8 48 8b 54 24 e0 <8b> 86 0c 01 00 00 44 8b 86 08 01 00 00 c1 e0 04 8d b8 7f 01 00 00
RSP: 002b:00007fce5827ec68 EFLAGS: 00010216
RAX: 0000000000402d00 RBX: 000000000118bfc8 RCX: 0000000020000200
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 000000000118c010 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bfd4
R13: 00007ffea2de495f R14: 00007fce5827f9c0 R15: 000000000118bfd4
BUG: using __this_cpu_read() in preemptible [00000000] code: syz-executor.0/8265
caller is lockdep_hardirqs_on+0x36/0x110 kernel/locking/lockdep.c:4129
CPU: 0 PID: 8265 Comm: syz-executor.0 Not tainted 5.9.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1d6/0x29e lib/dump_stack.c:118
check_preemption_disabled+0x13c/0x140 lib/smp_processor_id.c:48
lockdep_hardirqs_on+0x36/0x110 kernel/locking/lockdep.c:4129
__bad_area_nosemaphore+0x89/0x510 arch/x86/mm/fault.c:797
handle_page_fault arch/x86/mm/fault.c:1429 [inline]
exc_page_fault+0x129/0x240 arch/x86/mm/fault.c:1482
asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:538
RIP: 0033:0x402d28
Code: 00 00 48 89 7c 24 f8 48 89 74 24 f0 48 89 54 24 e8 48 89 4c 24 e0 48 8b 74 24 f8 4c 8b 4c 24 f0 48 8b 4c 24 e8 48 8b 54 24 e0 <8b> 86 0c 01 00 00 44 8b 86 08 01 00 00 c1 e0 04 8d b8 7f 01 00 00
RSP: 002b:00007fce5827ec68 EFLAGS: 00010216
RAX: 0000000000402d00 RBX: 000000000118bfc8 RCX: 0000000020000200
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 000000000118c010 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bfd4
R13: 00007ffea2de495f R14: 00007fce5827f9c0 R15: 000000000118bfd4
---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@googlegroups.com.
syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-13 11:22 BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on syzbot
@ 2020-10-13 13:17 ` Steven Rostedt
2020-10-21 13:17 ` Peter Zijlstra
2020-10-16 17:16 ` syzbot
2020-10-16 20:33 ` syzbot
2 siblings, 1 reply; 12+ messages in thread
From: Steven Rostedt @ 2020-10-13 13:17 UTC (permalink / raw)
To: syzbot; +Cc: linux-kernel, mingo, syzkaller-bugs, Peter Zijlstra
On Tue, 13 Oct 2020 04:22:21 -0700
syzbot <syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com> wrote:
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit: 865c50e1 x86/uaccess: utilize CONFIG_CC_HAS_ASM_GOTO_OUTPUT
> git tree: upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=15112ef0500000
> kernel config: https://syzkaller.appspot.com/x/.config?x=c829313274207568
> dashboard link: https://syzkaller.appspot.com/bug?extid=53f8ce8bbc07924b6417
> compiler: clang version 10.0.0 (https://github.com/llvm/llvm-project/ c2443155a0fb245c8f17f2c1c72b6ea391e86e81)
>
> Unfortunately, I don't have any reproducer for this issue yet.
>
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com
>
> BUG: using __this_cpu_read() in preemptible [00000000] code: syz-executor.0/8265
> caller is lockdep_hardirqs_on_prepare+0x56/0x620 kernel/locking/lockdep.c:4060
> CPU: 0 PID: 8265 Comm: syz-executor.0 Not tainted 5.9.0-syzkaller #0
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
> Call Trace:
> __dump_stack lib/dump_stack.c:77 [inline]
> dump_stack+0x1d6/0x29e lib/dump_stack.c:118
> check_preemption_disabled+0x13c/0x140 lib/smp_processor_id.c:48
> lockdep_hardirqs_on_prepare+0x56/0x620 kernel/locking/lockdep.c:4060
> trace_hardirqs_on+0x6f/0x80 kernel/trace/trace_preemptirq.c:49
> __bad_area_nosemaphore+0x89/0x510 arch/x86/mm/fault.c:797
> handle_page_fault arch/x86/mm/fault.c:1429 [inline]
> exc_page_fault+0x129/0x240 arch/x86/mm/fault.c:1482
> asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:538
> RIP: 0033:0x402d28
> Code: 00 00 48 89 7c 24 f8 48 89 74 24 f0 48 89 54 24 e8 48 89 4c 24 e0 48 8b 74 24 f8 4c 8b 4c 24 f0 48 8b 4c 24 e8 48 8b 54 24 e0 <8b> 86 0c 01 00 00 44 8b 86 08 01 00 00 c1 e0 04 8d b8 7f 01 00 00
> RSP: 002b:00007fce5827ec68 EFLAGS: 00010216
> RAX: 0000000000402d00 RBX: 000000000118bfc8 RCX: 0000000020000200
> RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
> RBP: 000000000118c010 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bfd4
> R13: 00007ffea2de495f R14: 00007fce5827f9c0 R15: 000000000118bfd4
> BUG: using __this_cpu_read() in preemptible [00000000] code: syz-executor.0/8265
> caller is lockdep_hardirqs_on+0x36/0x110 kernel/locking/lockdep.c:4129
> CPU: 0 PID: 8265 Comm: syz-executor.0 Not tainted 5.9.0-syzkaller #0
> Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
> Call Trace:
> __dump_stack lib/dump_stack.c:77 [inline]
> dump_stack+0x1d6/0x29e lib/dump_stack.c:118
> check_preemption_disabled+0x13c/0x140 lib/smp_processor_id.c:48
> lockdep_hardirqs_on+0x36/0x110 kernel/locking/lockdep.c:4129
> __bad_area_nosemaphore+0x89/0x510 arch/x86/mm/fault.c:797
Peter,
I'm guessing the above is:
static void
__bad_area_nosemaphore(struct pt_regs *regs, unsigned long error_code,
unsigned long address, u32 pkey, int si_code)
{
struct task_struct *tsk = current;
/* User mode accesses just cause a SIGSEGV */
if (user_mode(regs) && (error_code & X86_PF_USER)) {
/*
* It's possible to have interrupts off here:
*/
local_irq_enable();
And I'm also guessing that we can call this with interrupts enabled (based
on the comment).
And we have this:
local_irq_enable()
trace_hardirqs_on()
lockdep_hardirqs_on()
__this_cpu_read()
-- Steve
> handle_page_fault arch/x86/mm/fault.c:1429 [inline]
> exc_page_fault+0x129/0x240 arch/x86/mm/fault.c:1482
> asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:538
> RIP: 0033:0x402d28
> Code: 00 00 48 89 7c 24 f8 48 89 74 24 f0 48 89 54 24 e8 48 89 4c 24 e0 48 8b 74 24 f8 4c 8b 4c 24 f0 48 8b 4c 24 e8 48 8b 54 24 e0 <8b> 86 0c 01 00 00 44 8b 86 08 01 00 00 c1 e0 04 8d b8 7f 01 00 00
> RSP: 002b:00007fce5827ec68 EFLAGS: 00010216
> RAX: 0000000000402d00 RBX: 000000000118bfc8 RCX: 0000000020000200
> RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
> RBP: 000000000118c010 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bfd4
> R13: 00007ffea2de495f R14: 00007fce5827f9c0 R15: 000000000118bfd4
>
>
> ---
> This report is generated by a bot. It may contain errors.
> See https://goo.gl/tpsmEJ for more information about syzbot.
> syzbot engineers can be reached at syzkaller@googlegroups.com.
>
> syzbot will keep track of this issue. See:
> https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-13 11:22 BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on syzbot
2020-10-13 13:17 ` Steven Rostedt
@ 2020-10-16 17:16 ` syzbot
2020-10-16 20:33 ` syzbot
2 siblings, 0 replies; 12+ messages in thread
From: syzbot @ 2020-10-16 17:16 UTC (permalink / raw)
To: linux-kernel, mingo, netdev, peterz, rostedt, syzkaller-bugs
syzbot has found a reproducer for the following issue on:
HEAD commit: 9ff9b0d3 Merge tag 'net-next-5.10' of git://git.kernel.org..
git tree: net-next
console output: https://syzkaller.appspot.com/x/log.txt?x=16638607900000
kernel config: https://syzkaller.appspot.com/x/.config?x=d13c3fa80bc4bcc1
dashboard link: https://syzkaller.appspot.com/bug?extid=53f8ce8bbc07924b6417
compiler: gcc (GCC) 10.1.0-syz 20200507
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=15b63310500000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=1565657f900000
IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com
BUG: using __this_cpu_read() in preemptible [00000000] code: syz-executor089/6901
caller is lockdep_hardirqs_on_prepare+0x5e/0x450 kernel/locking/lockdep.c:4060
CPU: 0 PID: 6901 Comm: syz-executor089 Not tainted 5.9.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x198/0x1fb lib/dump_stack.c:118
check_preemption_disabled+0x128/0x130 lib/smp_processor_id.c:48
lockdep_hardirqs_on_prepare+0x5e/0x450 kernel/locking/lockdep.c:4060
trace_hardirqs_on+0x5b/0x1c0 kernel/trace/trace_preemptirq.c:49
__bad_area_nosemaphore+0xc6/0x4f0 arch/x86/mm/fault.c:797
do_user_addr_fault+0x852/0xbf0 arch/x86/mm/fault.c:1335
handle_page_fault arch/x86/mm/fault.c:1429 [inline]
exc_page_fault+0xa8/0x190 arch/x86/mm/fault.c:1482
asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:583
RIP: 0033:0x4241f0
Code: 66 0f ef c0 66 0f ef c9 66 0f ef d2 66 0f ef db 48 89 f8 48 89 f9 48 81 e1 ff 0f 00 00 48 81 f9 cf 0f 00 00 77 74 48 83 e0 f0 <66> 0f 74 00 66 0f 74 48 10 66 0f 74 50 20 66 0f 74 58 30 66 0f d7
RSP: 002b:00007ffcacd310b8 EFLAGS: 00010246
RAX: 0000000000000000 RBX: 00007ffcacd310e0 RCX: 0000000000000000
RDX: 0000000000000010 RSI: 000000000000000f RDI: 0000000000000000
RBP: 0000000000000003 R08: 00000000ffffffff R09: 0000000000000000
R10: 0000000000000000 R11: 000000000000000f R12: 0000000000401d70
R13: 0000000000401e00 R14: 0000000000000000 R15: 0000000000000000
BUG: using __this_cpu_read() in preemptible [00000000] code: syz-executor089/6901
caller is lockdep_hardirqs_on+0x34/0x110 kernel/locking/lockdep.c:4129
CPU: 0 PID: 6901 Comm: syz-executor089 Not tainted 5.9.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x198/0x1fb lib/dump_stack.c:118
check_preemption_disabled+0x128/0x130 lib/smp_processor_id.c:48
lockdep_hardirqs_on+0x34/0x110 kernel/locking/lockdep.c:4129
__bad_area_nosemaphore+0xc6/0x4f0 arch/x86/mm/fault.c:797
do_user_addr_fault+0x852/0xbf0 arch/x86/mm/fault.c:1335
handle_page_fault arch/x86/mm/fault.c:1429 [inline]
exc_page_fault+0xa8/0x190 arch/x86/mm/fault.c:1482
asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:583
RIP: 0033:0x4241f0
Code: 66 0f ef c0 66 0f ef c9 66 0f ef d2 66 0f ef db 48 89 f8 48 89 f9 48 81 e1 ff 0f 00 00 48 81 f9 cf 0f 00 00 77 74 48 83 e0 f0 <66> 0f 74 00 66 0f 74 48 10 66 0f 74 50 20 66 0f 74 58 30 66 0f d7
RSP: 002b:00007ffcacd310b8 EFLAGS: 00010246
RAX: 0000000000000000 RBX: 00007ffcacd310e0 RCX: 0000000000000000
RDX: 0000000000000010 RSI: 000000000000000f RDI: 0000000000000000
RBP: 0000000000000003 R08: 00000000ffffffff R09: 0000000000000000
R10: 0000000000000000 R11: 00000000000
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-13 11:22 BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on syzbot
2020-10-13 13:17 ` Steven Rostedt
2020-10-16 17:16 ` syzbot
@ 2020-10-16 20:33 ` syzbot
2020-10-21 13:09 ` Dmitry Vyukov
2 siblings, 1 reply; 12+ messages in thread
From: syzbot @ 2020-10-16 20:33 UTC (permalink / raw)
To: linux-kernel, mingo, mingo, netdev, peterz, rostedt,
syzkaller-bugs, will
syzbot has bisected this issue to:
commit 4d004099a668c41522242aa146a38cc4eb59cb1e
Author: Peter Zijlstra <peterz@infradead.org>
Date: Fri Oct 2 09:04:21 2020 +0000
lockdep: Fix lockdep recursion
bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=174a766f900000
start commit: 9ff9b0d3 Merge tag 'net-next-5.10' of git://git.kernel.org..
git tree: net-next
final oops: https://syzkaller.appspot.com/x/report.txt?x=14ca766f900000
console output: https://syzkaller.appspot.com/x/log.txt?x=10ca766f900000
kernel config: https://syzkaller.appspot.com/x/.config?x=d13c3fa80bc4bcc1
dashboard link: https://syzkaller.appspot.com/bug?extid=53f8ce8bbc07924b6417
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=15b63310500000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=1565657f900000
Reported-by: syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com
Fixes: 4d004099a668 ("lockdep: Fix lockdep recursion")
For information about bisection process see: https://goo.gl/tpsmEJ#bisection
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-16 20:33 ` syzbot
@ 2020-10-21 13:09 ` Dmitry Vyukov
0 siblings, 0 replies; 12+ messages in thread
From: Dmitry Vyukov @ 2020-10-21 13:09 UTC (permalink / raw)
To: syzbot
Cc: LKML, Ingo Molnar, Ingo Molnar, netdev, Peter Zijlstra,
Steven Rostedt, syzkaller-bugs, Will Deacon
On Fri, Oct 16, 2020 at 10:33 PM syzbot
<syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com> wrote:
>
> syzbot has bisected this issue to:
>
> commit 4d004099a668c41522242aa146a38cc4eb59cb1e
> Author: Peter Zijlstra <peterz@infradead.org>
> Date: Fri Oct 2 09:04:21 2020 +0000
>
> lockdep: Fix lockdep recursion
>
> bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=174a766f900000
> start commit: 9ff9b0d3 Merge tag 'net-next-5.10' of git://git.kernel.org..
> git tree: net-next
> final oops: https://syzkaller.appspot.com/x/report.txt?x=14ca766f900000
> console output: https://syzkaller.appspot.com/x/log.txt?x=10ca766f900000
> kernel config: https://syzkaller.appspot.com/x/.config?x=d13c3fa80bc4bcc1
> dashboard link: https://syzkaller.appspot.com/bug?extid=53f8ce8bbc07924b6417
> syz repro: https://syzkaller.appspot.com/x/repro.syz?x=15b63310500000
> C reproducer: https://syzkaller.appspot.com/x/repro.c?x=1565657f900000
>
> Reported-by: syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com
> Fixes: 4d004099a668 ("lockdep: Fix lockdep recursion")
>
> For information about bisection process see: https://goo.gl/tpsmEJ#bisection
This is now one of top crashers with 190K crashes in the past 12 days:
https://syzkaller.appspot.com/bug?id=e7cbd9d7047a1c4e14bbdc194a7d87de1f168289
This is now almost the only bug syzbot triggers.
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-13 13:17 ` Steven Rostedt
@ 2020-10-21 13:17 ` Peter Zijlstra
2020-10-21 14:34 ` Steven Rostedt
0 siblings, 1 reply; 12+ messages in thread
From: Peter Zijlstra @ 2020-10-21 13:17 UTC (permalink / raw)
To: Steven Rostedt; +Cc: syzbot, linux-kernel, mingo, syzkaller-bugs
On Tue, Oct 13, 2020 at 09:17:43AM -0400, Steven Rostedt wrote:
> On Tue, 13 Oct 2020 04:22:21 -0700
> syzbot <syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com> wrote:
>
> > Hello,
> >
> > syzbot found the following issue on:
> >
> > HEAD commit: 865c50e1 x86/uaccess: utilize CONFIG_CC_HAS_ASM_GOTO_OUTPUT
> > git tree: upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=15112ef0500000
> > kernel config: https://syzkaller.appspot.com/x/.config?x=c829313274207568
> > dashboard link: https://syzkaller.appspot.com/bug?extid=53f8ce8bbc07924b6417
> > compiler: clang version 10.0.0 (https://github.com/llvm/llvm-project/ c2443155a0fb245c8f17f2c1c72b6ea391e86e81)
> >
> > Unfortunately, I don't have any reproducer for this issue yet.
> >
> > IMPORTANT: if you fix the issue, please add the following tag to the commit:
> > Reported-by: syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com
> >
> > BUG: using __this_cpu_read() in preemptible [00000000] code: syz-executor.0/8265
> > caller is lockdep_hardirqs_on_prepare+0x56/0x620 kernel/locking/lockdep.c:4060
> > CPU: 0 PID: 8265 Comm: syz-executor.0 Not tainted 5.9.0-syzkaller #0
> > Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
> > Call Trace:
> > __dump_stack lib/dump_stack.c:77 [inline]
> > dump_stack+0x1d6/0x29e lib/dump_stack.c:118
> > check_preemption_disabled+0x13c/0x140 lib/smp_processor_id.c:48
> > lockdep_hardirqs_on_prepare+0x56/0x620 kernel/locking/lockdep.c:4060
> > trace_hardirqs_on+0x6f/0x80 kernel/trace/trace_preemptirq.c:49
> > __bad_area_nosemaphore+0x89/0x510 arch/x86/mm/fault.c:797
> > handle_page_fault arch/x86/mm/fault.c:1429 [inline]
> > exc_page_fault+0x129/0x240 arch/x86/mm/fault.c:1482
> > asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:538
> > RIP: 0033:0x402d28
> > Code: 00 00 48 89 7c 24 f8 48 89 74 24 f0 48 89 54 24 e8 48 89 4c 24 e0 48 8b 74 24 f8 4c 8b 4c 24 f0 48 8b 4c 24 e8 48 8b 54 24 e0 <8b> 86 0c 01 00 00 44 8b 86 08 01 00 00 c1 e0 04 8d b8 7f 01 00 00
> > RSP: 002b:00007fce5827ec68 EFLAGS: 00010216
> > RAX: 0000000000402d00 RBX: 000000000118bfc8 RCX: 0000000020000200
> > RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
> > RBP: 000000000118c010 R08: 0000000000000000 R09: 0000000000000000
> > R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bfd4
> > R13: 00007ffea2de495f R14: 00007fce5827f9c0 R15: 000000000118bfd4
> > BUG: using __this_cpu_read() in preemptible [00000000] code: syz-executor.0/8265
> > caller is lockdep_hardirqs_on+0x36/0x110 kernel/locking/lockdep.c:4129
> > CPU: 0 PID: 8265 Comm: syz-executor.0 Not tainted 5.9.0-syzkaller #0
> > Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
> > Call Trace:
> > __dump_stack lib/dump_stack.c:77 [inline]
> > dump_stack+0x1d6/0x29e lib/dump_stack.c:118
> > check_preemption_disabled+0x13c/0x140 lib/smp_processor_id.c:48
> > lockdep_hardirqs_on+0x36/0x110 kernel/locking/lockdep.c:4129
> > __bad_area_nosemaphore+0x89/0x510 arch/x86/mm/fault.c:797
>
> Peter,
>
> I'm guessing the above is:
>
> static void
> __bad_area_nosemaphore(struct pt_regs *regs, unsigned long error_code,
> unsigned long address, u32 pkey, int si_code)
> {
> struct task_struct *tsk = current;
>
> /* User mode accesses just cause a SIGSEGV */
> if (user_mode(regs) && (error_code & X86_PF_USER)) {
> /*
> * It's possible to have interrupts off here:
> */
> local_irq_enable();
>
>
> And I'm also guessing that we can call this with interrupts enabled (based
> on the comment).
>
> And we have this:
>
> local_irq_enable()
> trace_hardirqs_on()
> lockdep_hardirqs_on()
> __this_cpu_read()
Moo, two threads..
20201019183355.GS2611@hirez.programming.kicks-ass.net
---
On Tue, Oct 20, 2020 at 12:55:46AM +0800, kernel test robot wrote:
> [ 92.898145] BUG: using __this_cpu_read() in preemptible [00000000] code: trinity-c6/526
> [ 92.903305] Call Trace:
> [ 92.905182] __this_cpu_preempt_check+0xf/0x11
> [ 92.905968] lockdep_hardirqs_on_prepare+0x2c/0x18f
> [ 92.906853] trace_hardirqs_on+0x49/0x53
> [ 92.907578] __bad_area_nosemaphore+0x3a/0x134
Hurph, that's a spurious local_irq_enable(). I suppose this'll fix it.
---
diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 3e99dfef8408..9f818145ef7d 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -4057,9 +4057,6 @@ void lockdep_hardirqs_on_prepare(unsigned long ip)
if (unlikely(in_nmi()))
return;
- if (unlikely(__this_cpu_read(lockdep_recursion)))
- return;
-
if (unlikely(lockdep_hardirqs_enabled())) {
/*
* Neither irq nor preemption are disabled here
@@ -4070,6 +4067,9 @@ void lockdep_hardirqs_on_prepare(unsigned long ip)
return;
}
+ if (unlikely(__this_cpu_read(lockdep_recursion)))
+ return;
+
/*
* We're enabling irqs and according to our state above irqs weren't
* already enabled, yet we find the hardware thinks they are in fact
@@ -4126,9 +4126,6 @@ void noinstr lockdep_hardirqs_on(unsigned long ip)
goto skip_checks;
}
- if (unlikely(__this_cpu_read(lockdep_recursion)))
- return;
-
if (lockdep_hardirqs_enabled()) {
/*
* Neither irq nor preemption are disabled here
@@ -4139,6 +4136,9 @@ void noinstr lockdep_hardirqs_on(unsigned long ip)
return;
}
+ if (unlikely(__this_cpu_read(lockdep_recursion)))
+ return;
+
/*
* We're enabling irqs and according to our state above irqs weren't
* already enabled, yet we find the hardware thinks they are in fact
^ permalink raw reply related [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-21 13:17 ` Peter Zijlstra
@ 2020-10-21 14:34 ` Steven Rostedt
2020-10-21 15:12 ` Peter Zijlstra
0 siblings, 1 reply; 12+ messages in thread
From: Steven Rostedt @ 2020-10-21 14:34 UTC (permalink / raw)
To: Peter Zijlstra; +Cc: syzbot, linux-kernel, mingo, syzkaller-bugs
On Wed, 21 Oct 2020 15:17:33 +0200
Peter Zijlstra <peterz@infradead.org> wrote:
> > And I'm also guessing that we can call this with interrupts enabled (based
> > on the comment).
> >
> > And we have this:
> >
> > local_irq_enable()
> > trace_hardirqs_on()
> > lockdep_hardirqs_on()
> > __this_cpu_read()
>
> Moo, two threads..
>
> 20201019183355.GS2611@hirez.programming.kicks-ass.net
But this one's much older ;-)
>
> ---
>
> On Tue, Oct 20, 2020 at 12:55:46AM +0800, kernel test robot wrote:
> > [ 92.898145] BUG: using __this_cpu_read() in preemptible [00000000] code: trinity-c6/526
>
> > [ 92.903305] Call Trace:
> > [ 92.905182] __this_cpu_preempt_check+0xf/0x11
> > [ 92.905968] lockdep_hardirqs_on_prepare+0x2c/0x18f
> > [ 92.906853] trace_hardirqs_on+0x49/0x53
> > [ 92.907578] __bad_area_nosemaphore+0x3a/0x134
>
> Hurph, that's a spurious local_irq_enable(). I suppose this'll fix it.
>
> ---
> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index 3e99dfef8408..9f818145ef7d 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -4057,9 +4057,6 @@ void lockdep_hardirqs_on_prepare(unsigned long ip)
> if (unlikely(in_nmi()))
> return;
>
> - if (unlikely(__this_cpu_read(lockdep_recursion)))
> - return;
> -
> if (unlikely(lockdep_hardirqs_enabled())) {
Hmm, would moving the recursion check below the check of the
lockdep_hardirqs_enable() cause a large skew in the spurious enable stats?
May not be an issue, but something we should check to make sure that
there's not a path that constantly hits this.
-- Steve
> /*
> * Neither irq nor preemption are disabled here
> @@ -4070,6 +4067,9 @@ void lockdep_hardirqs_on_prepare(unsigned long ip)
> return;
> }
>
> + if (unlikely(__this_cpu_read(lockdep_recursion)))
> + return;
> +
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-21 14:34 ` Steven Rostedt
@ 2020-10-21 15:12 ` Peter Zijlstra
2020-10-21 15:27 ` Steven Rostedt
0 siblings, 1 reply; 12+ messages in thread
From: Peter Zijlstra @ 2020-10-21 15:12 UTC (permalink / raw)
To: Steven Rostedt; +Cc: syzbot, linux-kernel, mingo, syzkaller-bugs
On Wed, Oct 21, 2020 at 10:34:33AM -0400, Steven Rostedt wrote:
> On Wed, 21 Oct 2020 15:17:33 +0200
> Peter Zijlstra <peterz@infradead.org> wrote:
>
> > > And I'm also guessing that we can call this with interrupts enabled (based
> > > on the comment).
> > >
> > > And we have this:
> > >
> > > local_irq_enable()
> > > trace_hardirqs_on()
> > > lockdep_hardirqs_on()
> > > __this_cpu_read()
> >
> > Moo, two threads..
> >
> > 20201019183355.GS2611@hirez.programming.kicks-ass.net
>
> But this one's much older ;-)
Yeah, my mailbox is a trainwreck :/
> >
> > ---
> >
> > On Tue, Oct 20, 2020 at 12:55:46AM +0800, kernel test robot wrote:
> > > [ 92.898145] BUG: using __this_cpu_read() in preemptible [00000000] code: trinity-c6/526
> >
> > > [ 92.903305] Call Trace:
> > > [ 92.905182] __this_cpu_preempt_check+0xf/0x11
> > > [ 92.905968] lockdep_hardirqs_on_prepare+0x2c/0x18f
> > > [ 92.906853] trace_hardirqs_on+0x49/0x53
> > > [ 92.907578] __bad_area_nosemaphore+0x3a/0x134
> >
> > Hurph, that's a spurious local_irq_enable(). I suppose this'll fix it.
> >
> > ---
> > diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> > index 3e99dfef8408..9f818145ef7d 100644
> > --- a/kernel/locking/lockdep.c
> > +++ b/kernel/locking/lockdep.c
> > @@ -4057,9 +4057,6 @@ void lockdep_hardirqs_on_prepare(unsigned long ip)
> > if (unlikely(in_nmi()))
> > return;
> >
> > - if (unlikely(__this_cpu_read(lockdep_recursion)))
> > - return;
> > -
> > if (unlikely(lockdep_hardirqs_enabled())) {
>
> Hmm, would moving the recursion check below the check of the
> lockdep_hardirqs_enable() cause a large skew in the spurious enable stats?
> May not be an issue, but something we should check to make sure that
> there's not a path that constantly hits this.
Anything that sets recursion will have interrupts disabled.
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-21 15:12 ` Peter Zijlstra
@ 2020-10-21 15:27 ` Steven Rostedt
2020-10-22 10:30 ` Peter Zijlstra
0 siblings, 1 reply; 12+ messages in thread
From: Steven Rostedt @ 2020-10-21 15:27 UTC (permalink / raw)
To: Peter Zijlstra; +Cc: syzbot, linux-kernel, mingo, syzkaller-bugs
On Wed, 21 Oct 2020 17:12:37 +0200
Peter Zijlstra <peterz@infradead.org> wrote:
> > > diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> > > index 3e99dfef8408..9f818145ef7d 100644
> > > --- a/kernel/locking/lockdep.c
> > > +++ b/kernel/locking/lockdep.c
> > > @@ -4057,9 +4057,6 @@ void lockdep_hardirqs_on_prepare(unsigned long ip)
> > > if (unlikely(in_nmi()))
> > > return;
> > >
> > > - if (unlikely(__this_cpu_read(lockdep_recursion)))
> > > - return;
> > > -
> > > if (unlikely(lockdep_hardirqs_enabled())) {
> >
> > Hmm, would moving the recursion check below the check of the
> > lockdep_hardirqs_enable() cause a large skew in the spurious enable stats?
> > May not be an issue, but something we should check to make sure that
> > there's not a path that constantly hits this.
>
> Anything that sets recursion will have interrupts disabled.
It may have interrupts disabled, but does it have the hardirqs_enabled
per_cpu variable set? The above check only looks at that, and doesn't check
if interrupts are actually enabled.
For example, if lockdep is processing a mutex, it would set the recursion
variable, but does it ever set the hardirqs_enabled variable to off?
-- Steve
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-21 15:27 ` Steven Rostedt
@ 2020-10-22 10:30 ` Peter Zijlstra
2020-10-22 20:32 ` Steven Rostedt
0 siblings, 1 reply; 12+ messages in thread
From: Peter Zijlstra @ 2020-10-22 10:30 UTC (permalink / raw)
To: Steven Rostedt; +Cc: syzbot, linux-kernel, mingo, syzkaller-bugs
On Wed, Oct 21, 2020 at 11:27:57AM -0400, Steven Rostedt wrote:
> On Wed, 21 Oct 2020 17:12:37 +0200
> Peter Zijlstra <peterz@infradead.org> wrote:
>
> > > > diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> > > > index 3e99dfef8408..9f818145ef7d 100644
> > > > --- a/kernel/locking/lockdep.c
> > > > +++ b/kernel/locking/lockdep.c
> > > > @@ -4057,9 +4057,6 @@ void lockdep_hardirqs_on_prepare(unsigned long ip)
> > > > if (unlikely(in_nmi()))
> > > > return;
> > > >
> > > > - if (unlikely(__this_cpu_read(lockdep_recursion)))
> > > > - return;
> > > > -
> > > > if (unlikely(lockdep_hardirqs_enabled())) {
> > >
> > > Hmm, would moving the recursion check below the check of the
> > > lockdep_hardirqs_enable() cause a large skew in the spurious enable stats?
> > > May not be an issue, but something we should check to make sure that
> > > there's not a path that constantly hits this.
> >
> > Anything that sets recursion will have interrupts disabled.
>
> It may have interrupts disabled, but does it have the hardirqs_enabled
> per_cpu variable set? The above check only looks at that, and doesn't check
> if interrupts are actually enabled.
>
> For example, if lockdep is processing a mutex, it would set the recursion
> variable, but does it ever set the hardirqs_enabled variable to off?
Bah, I can't read. So I was looking at:
if (DEBUG_LOCKS_WARN_ON(!irqs_disabled()))
but that wasn't what I actually moved around. *sigh*..
A well, I'll just remove the __ here. It's not like we super care about
performance here.
Something like so then..
---
Subject: lockdep: Fix preemption WARN for spurious IRQ-enable
From: Peter Zijlstra <peterz@infradead.org>
Date: Thu Oct 22 12:23:02 CEST 2020
It is valid (albeit uncommon) to call local_irq_enable() without first
having called local_irq_disable(). In this case we enter
lockdep_hardirqs_on*() with IRQs enabled and trip a preemption warning
for using __this_cpu_read().
Use this_cpu_read() instead to avoid the warning.
Fixes: 4d004099a6 ("lockdep: Fix lockdep recursion")
Reported-by: syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com
Reported-by: kernel test robot <lkp@intel.com>
Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
---
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -4057,7 +4057,7 @@ void lockdep_hardirqs_on_prepare(unsigne
if (unlikely(in_nmi()))
return;
- if (unlikely(__this_cpu_read(lockdep_recursion)))
+ if (unlikely(this_cpu_read(lockdep_recursion)))
return;
if (unlikely(lockdep_hardirqs_enabled())) {
@@ -4126,7 +4126,7 @@ void noinstr lockdep_hardirqs_on(unsigne
goto skip_checks;
}
- if (unlikely(__this_cpu_read(lockdep_recursion)))
+ if (unlikely(this_cpu_read(lockdep_recursion)))
return;
if (lockdep_hardirqs_enabled()) {
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-22 10:30 ` Peter Zijlstra
@ 2020-10-22 20:32 ` Steven Rostedt
2020-10-23 8:18 ` Peter Zijlstra
0 siblings, 1 reply; 12+ messages in thread
From: Steven Rostedt @ 2020-10-22 20:32 UTC (permalink / raw)
To: Peter Zijlstra; +Cc: syzbot, linux-kernel, mingo, syzkaller-bugs
On Thu, 22 Oct 2020 12:30:28 +0200
Peter Zijlstra <peterz@infradead.org> wrote:
> Subject: lockdep: Fix preemption WARN for spurious IRQ-enable
> From: Peter Zijlstra <peterz@infradead.org>
> Date: Thu Oct 22 12:23:02 CEST 2020
>
> It is valid (albeit uncommon) to call local_irq_enable() without first
> having called local_irq_disable(). In this case we enter
> lockdep_hardirqs_on*() with IRQs enabled and trip a preemption warning
> for using __this_cpu_read().
>
> Use this_cpu_read() instead to avoid the warning.
I was wondering why you were using __this_cpu_read() in the first place.
Reviewed-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
-- Steve
>
> Fixes: 4d004099a6 ("lockdep: Fix lockdep recursion")
> Reported-by: syzbot+53f8ce8bbc07924b6417@syzkaller.appspotmail.com
> Reported-by: kernel test robot <lkp@intel.com>
> Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on
2020-10-22 20:32 ` Steven Rostedt
@ 2020-10-23 8:18 ` Peter Zijlstra
0 siblings, 0 replies; 12+ messages in thread
From: Peter Zijlstra @ 2020-10-23 8:18 UTC (permalink / raw)
To: Steven Rostedt; +Cc: syzbot, linux-kernel, mingo, syzkaller-bugs
On Thu, Oct 22, 2020 at 04:32:47PM -0400, Steven Rostedt wrote:
> On Thu, 22 Oct 2020 12:30:28 +0200
> Peter Zijlstra <peterz@infradead.org> wrote:
>
> > Subject: lockdep: Fix preemption WARN for spurious IRQ-enable
> > From: Peter Zijlstra <peterz@infradead.org>
> > Date: Thu Oct 22 12:23:02 CEST 2020
> >
> > It is valid (albeit uncommon) to call local_irq_enable() without first
> > having called local_irq_disable(). In this case we enter
> > lockdep_hardirqs_on*() with IRQs enabled and trip a preemption warning
> > for using __this_cpu_read().
> >
> > Use this_cpu_read() instead to avoid the warning.
>
> I was wondering why you were using __this_cpu_read() in the first place.
Well, because all other sites are actually with IRQs disabled :/ It's
just this spurious enable thing that's an exception.
> Reviewed-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
Thanks!
^ permalink raw reply [flat|nested] 12+ messages in thread
end of thread, other threads:[~2020-10-23 8:19 UTC | newest]
Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-10-13 11:22 BUG: using __this_cpu_read() in preemptible code in trace_hardirqs_on syzbot
2020-10-13 13:17 ` Steven Rostedt
2020-10-21 13:17 ` Peter Zijlstra
2020-10-21 14:34 ` Steven Rostedt
2020-10-21 15:12 ` Peter Zijlstra
2020-10-21 15:27 ` Steven Rostedt
2020-10-22 10:30 ` Peter Zijlstra
2020-10-22 20:32 ` Steven Rostedt
2020-10-23 8:18 ` Peter Zijlstra
2020-10-16 17:16 ` syzbot
2020-10-16 20:33 ` syzbot
2020-10-21 13:09 ` Dmitry Vyukov
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).