BUG: soft lockup in smp_call_function

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: 15a1c6b6f516 Linux 4.14.276
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1743c9c8f00000
kernel config: https://syzkaller.appspot.com/x/.config?x=3ec12c117082c76f
dashboard link: https://syzkaller.appspot.com/bug?extid=9a524f9e9ff12d5eb182
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=168f2c1f700000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=142d7c44f00000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+9a524f...@syzkaller.appspotmail.com

clocksource: 'kvm-clock' wd_now: 4b0301c7f6 wd_last: 4ae534a60d mask: ffffffffffffffff
clocksource: 'tsc' cs_now: 779ddfc2 cs_last: a4788f0a6e mask: ffffffffffffffff
tsc: Marking TSC unstable due to clocksource watchdog
[Firmware Bug]: TSC ADJUST differs: CPU0 0 --> -705490478624. Restoring
watchdog: BUG: soft lockup - CPU#1 stuck for 303s! [syz-executor402:7994]
Modules linked in:
irq event stamp: 229122
hardirqs last enabled at (229121): [<ffffffff81228be9>] _flat_send_IPI_mask+0x109/0x1a0 arch/x86/kernel/apic/apic_flat_64.c:62
systemd[1]: systemd-journald.service: Main process exited, code=killed, status=6/ABRT
hardirqs last disabled at (229122): [<ffffffff874018ae>] apic_timer_interrupt+0x8e/0xa0 arch/x86/entry/entry_64.S:793
softirqs last enabled at (226806): [<ffffffff8760068b>] __do_softirq+0x68b/0x9ff kernel/softirq.c:314
systemd[1]: systemd-journald.service: Unit entered failed state.
softirqs last disabled at (226795): [<ffffffff81321cf3>] invoke_softirq kernel/softirq.c:368 [inline]
softirqs last disabled at (226795): [<ffffffff81321cf3>] irq_exit+0x193/0x240 kernel/softirq.c:409
CPU: 1 PID: 7994 Comm: syz-executor402 Not tainted 4.14.276-syzkaller #0
systemd[1]: systemd-journald.service: Failed with result 'watchdog'.
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff88809f6183c0 task.stack: ffff888095bf8000
RIP: 0010:__read_once_size include/linux/compiler.h:185 [inline]
RIP: 0010:csd_lock_wait kernel/smp.c:108 [inline]
RIP: 0010:smp_call_function_single+0x181/0x370 kernel/smp.c:302
systemd[1]: systemd-journald.service: Service has no hold-off time, scheduling restart.
RSP: 0018:ffff888095bffaa0 EFLAGS: 00000297 ORIG_RAX: ffffffffffffff10
RAX: ffff88809f6183c0 RBX: 1ffff11012b7ff58 RCX: 0000000000000000
systemd[1]: Stopped Flush Journal to Persistent Storage.
RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000286
RBP: ffff888095bffb48 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
systemd[1]: Stopping Flush Journal to Persistent Storage...
R13: ffff888095bffb78 R14: 0000000000000001 R15: 0000000000000010
FS: 0000555556ab0300(0000) GS:ffff8880ba500000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
systemd[1]: Stopped Journal Service.
CR2: 00007fc592fe7130 CR3: 00000000ac072000 CR4: 00000000003406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
systemd[1]: Starting Journal Service...
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
wrmsr_safe_on_cpu+0x8f/0xd0 arch/x86/lib/msr-smp.c:188
msr_write+0xfc/0x190 arch/x86/kernel/msr.c:95
do_loop_readv_writev fs/read_write.c:698 [inline]
do_loop_readv_writev fs/read_write.c:682 [inline]
do_iter_write+0x3da/0x550 fs/read_write.c:956
vfs_writev+0x125/0x290 fs/read_write.c:999
do_pwritev fs/read_write.c:1088 [inline]
SYSC_pwritev fs/read_write.c:1135 [inline]
SyS_pwritev+0x15a/0x200 fs/read_write.c:1130
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7fc592f763c9
RSP: 002b:00007ffdf0adb548 EFLAGS: 00000246 ORIG_RAX: 0000000000000128
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fc592f763c9
RDX: 0000000000000002 RSI: 0000000020000100 RDI: 0000000000000004
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000010 R11: 0000000000000246 R12: 00007ffdf0adb570
R13: 431bde82d7b634db R14: 0000000000000000 R15: 0000000000000000
Code: cd 08 00 48 8b 54 24 10 4c 89 e9 8b 7c 24 1c 48 8d 74 24 40 e8 71 fa ff ff 41 89 c4 8b 44 24 58 a8 01 74 0f e8 b1 cd 08 00 f3 90 <8b> 44 24 58 a8 01 75 f1 e8 a2 cd 08 00 e8 9d cd 08 00 bf 01 00
----------------
Code disassembly (best guess):
0: cd 08 int $0x8
2: 00 48 8b add %cl,-0x75(%rax)
5: 54 push %rsp
6: 24 10 and $0x10,%al
8: 4c 89 e9 mov %r13,%rcx
b: 8b 7c 24 1c mov 0x1c(%rsp),%edi
f: 48 8d 74 24 40 lea 0x40(%rsp),%rsi
14: e8 71 fa ff ff callq 0xfffffa8a
19: 41 89 c4 mov %eax,%r12d
1c: 8b 44 24 58 mov 0x58(%rsp),%eax
20: a8 01 test $0x1,%al
22: 74 0f je 0x33
24: e8 b1 cd 08 00 callq 0x8cdda
29: f3 90 pause
* 2b: 8b 44 24 58 mov 0x58(%rsp),%eax <-- trapping instruction
2f: a8 01 test $0x1,%al
31: 75 f1 jne 0x24
33: e8 a2 cd 08 00 callq 0x8cdda
38: e8 9d cd 08 00 callq 0x8cdda
3d: bf .byte 0xbf
3e: 01 00 add %eax,(%rax)


---
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 syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this issue, for details see:
https://goo.gl/tpsmEJ#testing-patches

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: 3f8a27f9e27b Linux 4.19.211
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=168ea042f00000
kernel config: https://syzkaller.appspot.com/x/.config?x=9b9277b418617afe
dashboard link: https://syzkaller.appspot.com/bug?extid=d32133ac1a0d3fa4bd45

compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=152a912cf00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=110a2a30f00000

IMPORTANT: if you fix the issue, please add the following tag to the commit:

Reported-by: syzbot+d32133...@syzkaller.appspotmail.com

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