syzbot


BUG: soft lockup in smp_call_function

Status: upstream: reported C repro on 2022/04/23 05:26
Reported-by: syzbot+d32133ac1a0d3fa4bd45@syzkaller.appspotmail.com
First crash: 220d, last: 91d

Fix bisection: failed (bisect log)
similar bugs (5):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream BUG: soft lockup in smp_call_function C done 802 27d 869d 0/24 upstream: reported C repro on 2020/07/12 23:02
android-54 BUG: soft lockup in smp_call_function 1 388d 388d 0/2 auto-closed as invalid on 2022/03/05 18:04
linux-4.14 BUG: soft lockup in smp_call_function C 1 32d 220d 0/1 upstream: reported C repro on 2022/04/23 04:43
android-5-15 BUG: soft lockup in smp_call_function 1 4d08h 4d08h 0/2 premoderation: reported on 2022/11/25 06:05
upstream INFO: rcu detected stall in smp_call_function C 107 598d 853d 22/24 fixed on 2021/04/13 06:26

Sample crash report:
clocksource:                       'tsc' cs_now: 2f3c186 cs_last: 13c0c2bdbe mask: ffffffffffffffff
ieee802154 phy0 wpan0: encryption failed: -22
tsc: Marking TSC unstable due to clocksource watchdog
ieee802154 phy1 wpan1: encryption failed: -22
watchdog: BUG: soft lockup - CPU#0 stuck for 3513489127s! [syz-executor201:8361]
Modules linked in:
irq event stamp: 1050
hardirqs last  enabled at (1049): [<ffffffff81587e00>] generic_exec_single+0x2e0/0x490 kernel/smp.c:154
hardirqs last disabled at (1050): [<ffffffff81003d00>] trace_hardirqs_off_thunk+0x1a/0x1c
softirqs last  enabled at (0): [<ffffffff81370d39>] copy_process.part.0+0x15b9/0x8260 kernel/fork.c:1856
softirqs last disabled at (0): [<0000000000000000>]           (null)
CPU: 0 PID: 8361 Comm: syz-executor201 Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:789 [inline]
RIP: 0010:generic_exec_single+0x317/0x490 kernel/smp.c:154
Code: 00 fc ff df 48 c1 e8 03 80 3c 10 00 0f 85 5a 01 00 00 48 83 3d 61 04 99 08 00 0f 84 db 00 00 00 e8 3e 07 0a 00 48 89 df 57 9d <0f> 1f 44 00 00 45 31 e4 e9 39 fe ff ff e8 27 07 0a 00 0f 0b e9 3a
RSP: 0018:ffff888093c4f9e8 EFLAGS: 00000293 ORIG_RAX: ffffffffffffff13
RAX: ffff888093ce6380 RBX: 0000000000000293 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff81587e32 RDI: 0000000000000293
RBP: 0000000000000200 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffff888093c4fa60
R13: ffff888093c4fb28 R14: ffffffff8388f960 R15: 0000000000000010
FS:  00005555558783c0(0000) GS:ffff8880ba000000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fc26e2f9150 CR3: 00000000aba95000 CR4: 00000000003406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 smp_call_function_single+0x1cf/0x420 kernel/smp.c:299
 wrmsr_safe_on_cpu+0x9f/0x100 arch/x86/lib/msr-smp.c:204
 msr_write+0x10c/0x1b0 arch/x86/kernel/msr.c:95
 do_loop_readv_writev fs/read_write.c:704 [inline]
 do_loop_readv_writev fs/read_write.c:688 [inline]
 do_iter_write+0x461/0x5d0 fs/read_write.c:962
 vfs_writev+0x153/0x2e0 fs/read_write.c:1005
 do_pwritev fs/read_write.c:1094 [inline]
 __do_sys_pwritev fs/read_write.c:1141 [inline]
 __se_sys_pwritev fs/read_write.c:1136 [inline]
 __x64_sys_pwritev+0x22b/0x310 fs/read_write.c:1136
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fc26e28be59
Code: 28 00 00 00 75 05 48 83 c4 28 c3 e8 61 18 00 00 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 c0 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fff86b70c98 EFLAGS: 00000246 ORIG_RAX: 0000000000000128
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007fc26e28be59
RDX: 0000000000000002 RSI: 0000000020000100 RDI: 0000000000000004
RBP: 00007fff86b70cb0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000010 R11: 0000000000000246 R12: 00007fff86b70d5c
R13: 00007fff86b70d90 R14: 00007fff86b70d70 R15: 0000000000000001
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 0 Comm: swapper/1 Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:preempt_count arch/x86/include/asm/preempt.h:23 [inline]
RIP: 0010:check_kcov_mode kernel/kcov.c:67 [inline]
RIP: 0010:__sanitizer_cov_trace_pc+0xd/0x50 kernel/kcov.c:101
Code: ff 4c 89 ef e8 04 dd 35 00 e9 23 fe ff ff 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 48 8b 34 24 65 48 8b 04 25 c0 df 01 00 <65> 8b 15 cc 59 9f 7e 81 e2 00 01 1f 00 75 2b 8b 90 60 13 00 00 83
RSP: 0018:ffff8880ba107cb8 EFLAGS: 00000046
RAX: ffff8880b5a863c0 RBX: 00145e780dbea747 RCX: ffffffff8154afeb
RDX: 0000000000000000 RSI: ffffffff8154b00d RDI: 0000000000000006
RBP: ffff8880ba107d80 R08: 0098975d490041c9 R09: 00145e780dbea747
R10: 0000000000000006 R11: ffffffff8c66505b R12: 7452bf963f96c7e9
R13: 00004c4baedd5900 R14: 00000000628682e4 R15: 001dcd6500000000
FS:  0000000000000000(0000) GS:ffff8880ba100000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000021000000 CR3: 00000000973bd000 CR4: 00000000003406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 logarithmic_accumulation kernel/time/timekeeping.c:2032 [inline]
 timekeeping_advance+0x2cd/0x9b0 kernel/time/timekeeping.c:2097
 tick_do_update_jiffies64.part.0+0x188/0x290 kernel/time/tick-sched.c:101
 tick_do_update_jiffies64 kernel/time/tick-sched.c:67 [inline]
 tick_sched_do_timer kernel/time/tick-sched.c:139 [inline]
 tick_sched_timer+0x220/0x290 kernel/time/tick-sched.c:1271
 __run_hrtimer kernel/time/hrtimer.c:1465 [inline]
 __hrtimer_run_queues+0x3f6/0xe60 kernel/time/hrtimer.c:1527
 hrtimer_interrupt+0x326/0x9e0 kernel/time/hrtimer.c:1585
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1071 [inline]
 smp_apic_timer_interrupt+0x10c/0x550 arch/x86/kernel/apic/apic.c:1096
 apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:894
 </IRQ>
RIP: 0010:native_safe_halt+0xe/0x10 arch/x86/include/asm/irqflags.h:61
Code: 48 89 df e8 f4 20 7f f9 e9 2e ff ff ff 48 89 df e8 e7 20 7f f9 eb 82 90 90 90 90 90 e9 07 00 00 00 0f 00 2d 14 43 4e 00 fb f4 <c3> 90 e9 07 00 00 00 0f 00 2d 04 43 4e 00 f4 c3 90 90 41 56 41 55
RSP: 0018:ffff8880b5a9fd40 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff13
RAX: 1ffffffff13e3054 RBX: dffffc0000000000 RCX: 0000000000000000
RDX: dffffc0000000000 RSI: 0000000000000001 RDI: ffff8880b5a86c44
RBP: 0000000000000001 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff89f18290
R13: 1ffff11016b53fb2 R14: 0000000000000000 R15: 0000000000000000
 arch_safe_halt arch/x86/include/asm/paravirt.h:94 [inline]
 default_idle+0x49/0x310 arch/x86/kernel/process.c:557
 cpuidle_idle_call kernel/sched/idle.c:153 [inline]
 do_idle+0x2ec/0x4b0 kernel/sched/idle.c:263
 cpu_startup_entry+0xc5/0xe0 kernel/sched/idle.c:369
 start_secondary+0x435/0x5c0 arch/x86/kernel/smpboot.c:271
 secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:243
----------------
Code disassembly (best guess), 3 bytes skipped:
   0:	df 48 c1             	fisttps -0x3f(%rax)
   3:	e8 03 80 3c 10       	callq  0x103c800b
   8:	00 0f                	add    %cl,(%rdi)
   a:	85 5a 01             	test   %ebx,0x1(%rdx)
   d:	00 00                	add    %al,(%rax)
   f:	48 83 3d 61 04 99 08 	cmpq   $0x0,0x8990461(%rip)        # 0x8990478
  16:	00
  17:	0f 84 db 00 00 00    	je     0xf8
  1d:	e8 3e 07 0a 00       	callq  0xa0760
  22:	48 89 df             	mov    %rbx,%rdi
  25:	57                   	push   %rdi
  26:	9d                   	popfq
* 27:	0f 1f 44 00 00       	nopl   0x0(%rax,%rax,1) <-- trapping instruction
  2c:	45 31 e4             	xor    %r12d,%r12d
  2f:	e9 39 fe ff ff       	jmpq   0xfffffe6d
  34:	e8 27 07 0a 00       	callq  0xa0760
  39:	0f 0b                	ud2
  3b:	e9                   	.byte 0xe9
  3c:	3a                   	.byte 0x3a

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-linux-4-19 2022/04/23 05:25 linux-4.19.y 3f8a27f9e27b 131df97d .config log report syz C BUG: soft lockup in smp_call_function
ci2-linux-4-19 2022/08/30 01:42 linux-4.19.y 3f8a27f9e27b d7593c58 .config log report info BUG: soft lockup in smp_call_function
* Struck through repros no longer work on HEAD.