panic: kernel diagnostic assertion "__mp_lock_held(&sched_lock, curcpu()) == 0" failed: file "/syzkaller/managers/multic

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 013d15613728 Merge branch 'master' of https://github.com/o..
git tree: https://github.com/blackgnezdo/src.git multicore
console output: https://syzkaller.appspot.com/x/log.txt?x=1002927d400000
kernel config: https://syzkaller.appspot.com/x/.config?x=f2ee3db928411249
dashboard link: https://syzkaller.appspot.com/bug?extid=2a2a7f45ca9a0bbef604
compiler:

Unfortunately, I don't have any reproducer for this crash yet.

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+2a2a7f...@syzkaller.appspotmail.com

panic: kernel diagnostic assertion "__mp_lock_held(&sched_lock, curcpu())
== 0" failed:
file "/syzkaller/managers/multicore/kernel/sys/kern/kern_lock.c", line 63
Stopped at db_enter+0xa: popq %rbp
TID PID UID PRFLAGS PFLAGS CPU COMMAND
db_enter() at db_enter+0xa
panic() at panic+0x147
__assert(ffffffff81521464,ffff8000211ab3d0,ffff8000210a39e0,ffff800000038e80)
at
__assert+0x24
_kernel_lock(ffff8000210a39e0,ffff8000211a6000) at _kernel_lock+0x125
pageflttrap() at pageflttrap+0x6c
kerntrap(9) at kerntrap+0x8d
alltraps_kern(6,ffff800000ad6000,ffffffffffffffff,0,9,ffff8000210a39e0) at
alltraps_kern+0x7b
ptsignal(2829,ffff8000210a39e0,ffff8000210b7630) at ptsignal+0x115
mi_switch() at mi_switch+0x1fb
sleep_finish(1,ffff8000211ab660) at sleep_finish+0xd3
sleep_finish_all(ffff8000211ab660,32) at sleep_finish_all+0x22
tsleep(ffff8000210a39e0,3,0,ffff8000210b76f8) at tsleep+0x142
single_thread_set(ffff8000210a39e0,ffff8000210a39e0,0) at
single_thread_set+0x28b
exit1(ffff8000210a39e0,9,0) at exit1+0x84
end trace frame: 0xffff8000211ab830, count: 0
https://www.openbsd.org/ddb.html describes the minimum info required in bug
reports. Insufficient info makes it difficult to find and fix bugs.
ddb{1}>
ddb{1}> set $lines = 0
ddb{1}> show panic
kernel diagnostic assertion "__mp_lock_held(&sched_lock, curcpu()) == 0"
failed: file "/syzkaller/managers/multicore/kernel/sys/kern/kern_lock.c",
line 63
ddb{1}> trace
db_enter() at db_enter+0xa
panic() at panic+0x147
__assert(ffffffff81521464,ffff8000211ab3d0,ffff8000210a39e0,ffff800000038e80)
at
__assert+0x24
_kernel_lock(ffff8000210a39e0,ffff8000211a6000) at _kernel_lock+0x125
pageflttrap() at pageflttrap+0x6c
kerntrap(9) at kerntrap+0x8d
alltraps_kern(6,ffff800000ad6000,ffffffffffffffff,0,9,ffff8000210a39e0) at
alltraps_kern+0x7b
ptsignal(2829,ffff8000210a39e0,ffff8000210b7630) at ptsignal+0x115
mi_switch() at mi_switch+0x1fb
sleep_finish(1,ffff8000211ab660) at sleep_finish+0xd3
sleep_finish_all(ffff8000211ab660,32) at sleep_finish_all+0x22
tsleep(ffff8000210a39e0,3,0,ffff8000210b76f8) at tsleep+0x142
single_thread_set(ffff8000210a39e0,ffff8000210a39e0,0) at
single_thread_set+0x28b
exit1(ffff8000210a39e0,9,0) at exit1+0x84
postsig(100,ffff8000210a39e0) at postsig+0x3ea
userret(0) at userret+0x11b
syscall(0) at syscall+0x54d
Xsyscall(6,58,1739cadc000,53,0,1739cad9900) at Xsyscall+0x128
end of kernel
end trace frame: 0x173e57df590, count: -18
ddb{1}> show registers
rdi 0xffffffff81e2ec58 kprintf_mutex
rsi 0xffffffff81b67d99 db_enter+0x9
rbp 0xffff8000211ab330
rbx 0xffff8000211ab3d0
rdx 0xffff800000ad6000
rcx 0x4124 __ALIGN_SIZE+0x3124
rax 0xffff800000ad6000
r8 0xffff8000211ab300
r9 0x8080808080808080
r10 0x60905f3d72fffdb2
r11 0xffffffff819e6130 x86_bus_space_io_read_1
r12 0x3000000008
r13 0xffff8000211ab340
r14 0x100
r15 0xffffffff81bf400f cmd0646_9_tim_udma+0x20bde
rip 0xffffffff81b67d9a db_enter+0xa
cs 0x8
rflags 0x206
rsp 0xffff8000211ab330
ss 0x10
db_enter+0xa: popq %rbp
ddb{1}> show proc
PROC (syz-executor0) pid=411107 stat=sleep
flags process=1000<SINGLEEXIT> proc=4002000<WEXIT,THREAD>
pri=50, usrpri=59, nice=20
forw=0x0, list=0xffff8000210a32d8,0xffff8000210a24d8
process=0xffff8000210b7630 user=0xffff8000211a6000,
vmspace=0xffffff007f124d68
estcpu=36, cpticks=0, pctcpu=0.0
user=0, sys=0, intr=0
ddb{1}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
*63176 411107 5161 0 3 0x4003000 suspend syz-executor0
63176 384693 5161 0 2 0x4081000 syz-executor0
80245 76884 15514 0 3 0x80 nanosleep syz-executor1
80245 506280 15514 0 3 0x4000080 nanosleep syz-executor1
18695 379545 1 0 3 0x100083 ttyin getty
11848 240477 0 0 3 0x14200 bored sosplice
15514 493056 35592 0 3 0x82 nanosleep syz-executor1
5161 353797 35592 0 3 0x82 nanosleep syz-executor0
35592 459283 27952 0 3 0x82 thrsleep syz-fuzzer
35592 469380 27952 0 3 0x4000082 thrsleep syz-fuzzer
35592 271747 27952 0 3 0x4000082 thrsleep syz-fuzzer
35592 87539 27952 0 3 0x4000082 thrsleep syz-fuzzer
35592 108039 27952 0 3 0x4000082 thrsleep syz-fuzzer
35592 174212 27952 0 3 0x4000082 thrsleep syz-fuzzer
35592 376433 27952 0 3 0x4000082 kqread syz-fuzzer
35592 474160 27952 0 3 0x4000082 thrsleep syz-fuzzer
35592 18539 27952 0 3 0x4000082 thrsleep syz-fuzzer
35592 320118 27952 0 3 0x4000082 thrsleep syz-fuzzer
27952 412649 39976 0 3 0x10008a pause ksh
39976 341993 46564 0 3 0x92 select sshd
46564 390952 1 0 3 0x80 select sshd
12 138312 84757 73 3 0x100010 ffs_fsync syslogd
84757 187478 1 0 3 0x100082 netio syslogd
73032 156183 1 77 3 0x100090 poll dhclient
25587 305141 1 0 3 0x80 poll dhclient
63865 460955 0 0 3 0x14200 pgzero zerothread
9351 322180 0 0 3 0x14200 aiodoned aiodoned
8149 230041 0 0 3 0x14200 syncer update
96043 40529 0 0 3 0x14200 cleaner cleaner
83691 163811 0 0 3 0x14200 reaper reaper
22208 349244 0 0 3 0x14200 pgdaemon pagedaemon
90218 346453 0 0 3 0x14200 bored crynlk
87434 256645 0 0 3 0x14200 bored crypto
52891 329123 0 0 3 0x40014200 acpi0 acpi0
55548 293949 0 0 3 0x40014200 idle1
14051 499727 0 0 3 0x14200 bored softnet
65358 487762 0 0 3 0x14200 bored systqmp
53237 460659 0 0 3 0x14200 bored systq
6554 243268 0 0 3 0x40014200 bored softclock
27780 517001 0 0 3 0x40014200 idle0
1 279078 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper


---
This bug 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 bug report. See:
https://goo.gl/tpsmEJ#bug-status-tracking for how to communicate with
syzbot.

[Greg Steuck]

Anton, this is still with the previous version of your patch (the link to the git tree can confirm it)

--
You received this message because you are subscribed to the Google Groups "syzkaller-openbsd-bugs" group.
To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-openbsd...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-openbsd-bugs/0000000000000a898b057c7edcab%40google.com.
For more options, visit https://groups.google.com/d/optout.

[syzbot]

syzbot has found a reproducer for the following crash on:

HEAD commit: 918267856206 document show-indexed
git tree: https://github.com/openbsd/src.git master
console output: https://syzkaller.appspot.com/x/log.txt?x=1256cf05400000

kernel config: https://syzkaller.appspot.com/x/.config?x=f2ee3db928411249
dashboard link: https://syzkaller.appspot.com/bug?extid=2a2a7f45ca9a0bbef604
compiler:

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=11f876db400000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+2a2a7f...@syzkaller.appspotmail.com

panic: kernel diagnostic assertion "__mp_lock_held(&sched_lock, curcpu())
== 0" failed:
file "/syzkaller/managers/multicore/kernel/sys/kern/kern_lock.c", line 63
Stopped at db_enter+0xa: popq %rbp
TID PID UID PRFLAGS PFLAGS CPU COMMAND

db_enter() at db_enter+0xa sys/arch/amd64/amd64/db_interface.c:399
panic() at panic+0x147 sys/kern/subr_prf.c:208
__assert(ffffffff819ccee4,ffff80002119cf50,ffff8000210b6978,ffff80000002f180)
at
__assert+0x24 sys/kern/subr_prf.c:155
_kernel_lock(ffff8000210b6978,ffff800021198000) at _kernel_lock+0x125
sys/kern/kern_lock.c:63
pageflttrap() at pageflttrap+0x6c sys/arch/amd64/amd64/trap.c:163
kerntrap(9) at kerntrap+0x8d sys/arch/amd64/amd64/trap.c:294
alltraps_kern(6,82000,ffffffffffffffff,0,9,ffff8000210b6978) at
alltraps_kern+0x7b
ptsignal(2253,ffff8000210b6978,ffff800021070008) at ptsignal+0x115
sys/kern/kern_sig.c:944
mi_switch() at mi_switch+0x1fb sys/kern/sched_bsd.c:392
sleep_finish(1,ffff80002119d1e0) at sleep_finish+0xd3
sys/kern/kern_synch.c:312
sleep_finish_all(ffff80002119d1e0,32) at sleep_finish_all+0x22
sleep_finish_timeout sys/kern/kern_synch.c:336 [inline]
sleep_finish_all(ffff80002119d1e0,32) at sleep_finish_all+0x22
sys/kern/kern_synch.c:157
tsleep(ffff8000210b6978,3,0,ffff8000210700d0) at tsleep+0x142
single_thread_set(ffff8000210b6978,ffff8000210b6978,0) at
single_thread_set+0x28b single_thread_wait sys/kern/kern_sig.c:2051 [inline]
single_thread_set(ffff8000210b6978,ffff8000210b6978,0) at
single_thread_set+0x28b sys/kern/kern_sig.c:2042
exit1(ffff8000210b6978,9,0) at exit1+0x84 sys/kern/kern_exit.c:137
end trace frame: 0xffff80002119d3b0, count: 0

https://www.openbsd.org/ddb.html describes the minimum info required in bug
reports. Insufficient info makes it difficult to find and fix bugs.

ddb{0}>
ddb{0}> set $lines = 0
ddb{0}> show panic

kernel diagnostic assertion "__mp_lock_held(&sched_lock, curcpu()) == 0"
failed: file "/syzkaller/managers/multicore/kernel/sys/kern/kern_lock.c",
line 63

ddb{0}> trace
db_enter() at db_enter+0xa sys/arch/amd64/amd64/db_interface.c:399
panic() at panic+0x147 sys/kern/subr_prf.c:208
__assert(ffffffff819ccee4,ffff80002119cf50,ffff8000210b6978,ffff80000002f180)
at
__assert+0x24 sys/kern/subr_prf.c:155
_kernel_lock(ffff8000210b6978,ffff800021198000) at _kernel_lock+0x125
sys/kern/kern_lock.c:63
pageflttrap() at pageflttrap+0x6c sys/arch/amd64/amd64/trap.c:163
kerntrap(9) at kerntrap+0x8d sys/arch/amd64/amd64/trap.c:294
alltraps_kern(6,82000,ffffffffffffffff,0,9,ffff8000210b6978) at
alltraps_kern+0x7b
ptsignal(2253,ffff8000210b6978,ffff800021070008) at ptsignal+0x115
sys/kern/kern_sig.c:944
mi_switch() at mi_switch+0x1fb sys/kern/sched_bsd.c:392
sleep_finish(1,ffff80002119d1e0) at sleep_finish+0xd3
sys/kern/kern_synch.c:312
sleep_finish_all(ffff80002119d1e0,32) at sleep_finish_all+0x22
sleep_finish_timeout sys/kern/kern_synch.c:336 [inline]
sleep_finish_all(ffff80002119d1e0,32) at sleep_finish_all+0x22
sys/kern/kern_synch.c:157
tsleep(ffff8000210b6978,3,0,ffff8000210700d0) at tsleep+0x142
single_thread_set(ffff8000210b6978,ffff8000210b6978,0) at
single_thread_set+0x28b single_thread_wait sys/kern/kern_sig.c:2051 [inline]
single_thread_set(ffff8000210b6978,ffff8000210b6978,0) at
single_thread_set+0x28b sys/kern/kern_sig.c:2042
exit1(ffff8000210b6978,9,0) at exit1+0x84 sys/kern/kern_exit.c:137
postsig(100,ffff8000210b6978) at postsig+0x3ea sigexit
sys/kern/kern_sig.c:1500 [inline]
postsig(100,ffff8000210b6978) at postsig+0x3ea sys/kern/kern_sig.c:1432
userret(0) at userret+0x11b sys/kern/kern_sig.c:1882
syscall(0) at syscall+0x54d mi_syscall_return sys/sys/syscall_mi.h:122
[inline]
syscall(0) at syscall+0x54d sys/arch/amd64/amd64/trap.c:605
Xsyscall(6,58,e4c78aeaa00,53,0,e4bffdf0c20) at Xsyscall+0x128
end of kernel
end trace frame: 0xe4c0cbe6590, count: -18
ddb{0}> show registers
rdi 0xffffffff81e4ccd8 kprintf_mutex
rsi 0x5
rbp 0xffff80002119ceb0
rbx 0xffff80002119cf50
rdx 0x3fd
rcx 0
rax 0x1
r8 0xffff80002119ce80
r9 0x8080808080808080
r10 0
r11 0xffffffff811311c0 x86_bus_space_io_read_1
r12 0x3000000008
r13 0xffff80002119cec0
r14 0x100
r15 0xffffffff81bf41d6 cmd0646_9_tim_udma+0x205dc
rip 0xffffffff811dd9ba db_enter+0xa
cs 0x8
rflags 0x202
rsp 0xffff80002119ceb0

ss 0x10
db_enter+0xa: popq %rbp

ddb{0}> show proc
PROC (syz-executor1) pid=176179 stat=sleep

flags process=1000<SINGLEEXIT> proc=4002000<WEXIT,THREAD>

pri=50, usrpri=70, nice=20
forw=0x0, list=0xffff8000210844b8,0xffff8000210b7c48
process=0xffff800021070008 user=0xffff800021198000,
vmspace=0xffffff007f125c60

estcpu=36, cpticks=0, pctcpu=0.0
user=0, sys=0, intr=0

ddb{0}> ps

PID TID PPID UID S FLAGS WAIT COMMAND

*21344 176179 85943 0 3 0x4003000 suspend syz-executor1
21344 197598 85943 0 2 0x4081080 syz-executor1
85943 314179 10398 0 3 0x82 nanosleep syz-executor1
15616 266325 10398 0 3 0x82 nanosleep syz-executor0
10398 503759 11244 0 3 0x82 thrsleep syz-execprog
10398 80677 11244 0 3 0x4000082 thrsleep syz-execprog
10398 77282 11244 0 3 0x4000082 thrsleep syz-execprog
10398 198075 11244 0 3 0x4000082 thrsleep syz-execprog
10398 68203 11244 0 3 0x4000082 thrsleep syz-execprog
10398 511845 11244 0 3 0x4000082 thrsleep syz-execprog
10398 49636 11244 0 3 0x4000082 thrsleep syz-execprog
10398 214767 11244 0 3 0x4000082 thrsleep syz-execprog
10398 1182 11244 0 3 0x4000082 thrsleep syz-execprog
10398 270896 11244 0 3 0x4000082 kqread syz-execprog
11244 233329 65666 0 3 0x10008a pause ksh
65666 391579 40941 0 3 0x92 select sshd
40792 410818 1 0 3 0x100083 ttyin getty
40941 122764 1 0 3 0x80 select sshd
31826 151817 44156 73 3 0x100090 kqread syslogd
44156 340788 1 0 3 0x100082 netio syslogd
61712 304078 1 77 3 0x100090 poll dhclient
25102 44827 1 0 3 0x80 poll dhclient
33544 298902 0 0 2 0x14200 zerothread
62239 234113 0 0 3 0x14200 aiodoned aiodoned
11736 365367 0 0 3 0x14200 syncer update
22313 96673 0 0 3 0x14200 cleaner cleaner
35985 473901 0 0 3 0x14200 reaper reaper
98186 232706 0 0 3 0x14200 pgdaemon pagedaemon
24241 40158 0 0 3 0x14200 bored crynlk
17010 156809 0 0 3 0x14200 bored crypto
52434 347356 0 0 3 0x40014200 acpi0 acpi0
72501 481015 0 0 3 0x40014200 idle1
1932 224219 0 0 3 0x14200 bored softnet
76063 177337 0 0 3 0x14200 bored systqmp
2846 66321 0 0 3 0x14200 bored systq
95433 471085 0 0 3 0x40014200 bored softclock
31311 445124 0 0 3 0x40014200 idle0
1 488101 0 0 3 0x82 wait init

[Greg Steuck]

#syz dup: panic: kernel diagnostic assertion

"__mp_lock_held(&sched_lock, curcpu()) == 0" failed: file

"/syzkaller/managers/setuid

--
nest.cx is Gmail hosted, use PGP for anything private. Key: http://goo.gl/6dMsr
Fingerprint: 5E2B 2D0E 1E03 2046 BEC3 4D50 0B15 42BD 8DF5 A1B0

[Greg Steuck]

#syz dup: panic: kernel diagnostic assertion
"__mp_lock_held(&sched_lock, curcpu())
== 0" failed:

file "/syzkaller/managers/setuid/kernel/sys/kern/kern_lock.c", line 63

[Dmitry Vyukov]

Perhaps we need to improve bug title extraction. E.g. strip part after
": file". E.g. today slight source change that shuffles line numbers
will lead to a new bug being created.

[Greg Steuck]

I think Anton's https://github.com/google/syzkaller/pull/886 is a step
in this direction, though it doesn't deal with line numbers. In
practice, OpenBSD churns much slower than Linux.

Thanks
Greg

[Anton Lindqvist]

#syz dup: assert "__mp_lock_held(&sched_lock, curcpu()) == 0" failed in kern_lock.c