syzbot


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

Status: fixed on 2019/01/06 22:58
Reported-by: syzbot+2f5d62256e3280634623@syzkaller.appspotmail.com
Fix commit: ec412da11be4 Fix unsafe use of ptsignal() in mi_switch().
First crash: 1433d, last: 1422d
duplicates (2):
Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
panic: kernel diagnostic assertion "__mp_lock_held(&sched_lock, curcpu()) == 0" failed: file "/syzkaller/managers/multic syz 9 1435d 1450d 0/3 closed as dup on 2018/12/25 11:08
panic: kernel diagnostic assertion "__mp_lock_held(&sched_lock, curcpu()) == 0" failed: file "/syzkaller/managers/setuid C 30 1434d 1449d 0/3 closed as dup on 2018/12/25 11:10

Sample crash report:
panic: kernel diagnostic assertion "__mp_lock_held(&sched_lock, curcpu()) == 0" failed: file "/syzkaller/managers/setuid/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(ffffffff813b6fb4,ffff800021125780,ffff8000210844b8,ffff80000002f180) at __assert+0x24 sys/kern/subr_prf.c:155
_kernel_lock(ffff8000210844b8,ffff800021120000) 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,4082000,ffffffffffffffff,0,9,ffff800021084008) at alltraps_kern+0x7b
ptsignal(25ef,ffff8000210844b8,ffff800021070008) at ptsignal+0x115 sys/kern/kern_sig.c:932
mi_switch() at mi_switch+0x1fb sys/kern/sched_bsd.c:392
sleep_finish(1,ffff800021125a10) at sleep_finish+0xd3 sys/kern/kern_synch.c:312
sleep_finish_all(ffff800021125a10,32) at sleep_finish_all+0x22 sleep_finish_timeout sys/kern/kern_synch.c:336 [inline]
sleep_finish_all(ffff800021125a10,32) at sleep_finish_all+0x22 sys/kern/kern_synch.c:157
tsleep(ffff8000210844b8,3,0,ffff8000210700d0) at tsleep+0x142
single_thread_set(ffff8000210844b8,ffff8000210844b8,0) at single_thread_set+0x28b single_thread_wait sys/kern/kern_sig.c:2039 [inline]
single_thread_set(ffff8000210844b8,ffff8000210844b8,0) at single_thread_set+0x28b sys/kern/kern_sig.c:2030
exit1(ffff8000210844b8,9,0) at exit1+0x84 sys/kern/kern_exit.c:137
end trace frame: 0xffff800021125be0, 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/setuid/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(ffffffff813b6fb4,ffff800021125780,ffff8000210844b8,ffff80000002f180) at __assert+0x24 sys/kern/subr_prf.c:155
_kernel_lock(ffff8000210844b8,ffff800021120000) 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,4082000,ffffffffffffffff,0,9,ffff800021084008) at alltraps_kern+0x7b
ptsignal(25ef,ffff8000210844b8,ffff800021070008) at ptsignal+0x115 sys/kern/kern_sig.c:932
mi_switch() at mi_switch+0x1fb sys/kern/sched_bsd.c:392
sleep_finish(1,ffff800021125a10) at sleep_finish+0xd3 sys/kern/kern_synch.c:312
sleep_finish_all(ffff800021125a10,32) at sleep_finish_all+0x22 sleep_finish_timeout sys/kern/kern_synch.c:336 [inline]
sleep_finish_all(ffff800021125a10,32) at sleep_finish_all+0x22 sys/kern/kern_synch.c:157
tsleep(ffff8000210844b8,3,0,ffff8000210700d0) at tsleep+0x142
single_thread_set(ffff8000210844b8,ffff8000210844b8,0) at single_thread_set+0x28b single_thread_wait sys/kern/kern_sig.c:2039 [inline]
single_thread_set(ffff8000210844b8,ffff8000210844b8,0) at single_thread_set+0x28b sys/kern/kern_sig.c:2030
exit1(ffff8000210844b8,9,0) at exit1+0x84 sys/kern/kern_exit.c:137
postsig(100,ffff8000210844b8) at postsig+0x3ea sigexit sys/kern/kern_sig.c:1488 [inline]
postsig(100,ffff8000210844b8) at postsig+0x3ea sys/kern/kern_sig.c:1420
userret(4) at userret+0x11b sys/kern/kern_sig.c:1870
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(0,4,0,5b,8aa50de50f8,8ac9bfb3000) at Xsyscall+0x128
end of kernel
end trace frame: 0x7f7ffffe4bf0, count: -18
ddb{0}> show registers
rdi               0xffffffff81e27fd8    kprintf_mutex
rsi                              0x5
rbp               0xffff8000211256e0
rbx               0xffff800021125780
rdx                            0x3fd
rcx                                0
rax                              0x1
r8                0xffff8000211256b0
r9                0x8080808080808080
r10                                0
r11               0xffffffff812b1590    x86_bus_space_io_read_1
r12                     0x3000000008
r13               0xffff8000211256f0
r14                            0x100
r15               0xffffffff81bf6fef    cmd0646_9_tim_udma+0x1ccc6
rip               0xffffffff8180d0ca    db_enter+0xa
cs                               0x8
rflags                         0x202
rsp               0xffff8000211256e0
ss                              0x10
db_enter+0xa:   popq    %rbp
ddb{0}> show proc
PROC (syz-executor5188) pid=278464 stat=sleep
    flags process=1000<SINGLEEXIT> proc=2000<WEXIT>
    pri=50, usrpri=86, nice=20
    forw=0x0, list=0xffff8000210a4268,0xffff800021084bd0
    process=0xffff800021070008 user=0xffff800021120000, vmspace=0xffffff007f125d68
    estcpu=36, cpticks=6, pctcpu=0.0
    user=0, sys=0, intr=0
ddb{0}> ps
   PID     TID   PPID    UID  S       FLAGS  WAIT          COMMAND
 66853    3188  82214      0  2           0                syz-executor5188
 66853  285753  82214      0  2   0x4000000                syz-executor5188
 66853  409970  82214      0  2   0x4000000                syz-executor5188
* 2227  278464  22754      0  3      0x3000  suspend       syz-executor5188
  2227  378103  22754      0  2   0x4081000                syz-executor5188
 82214  434144  97786      0  3        0x80  nanosleep     syz-executor5188
 22754  291231  97786      0  3        0x80  nanosleep     syz-executor5188
 97786  326636  76596      0  3        0x82  nanosleep     syz-executor5188
 76596  404328  44335      0  3    0x10008a  pause         ksh
 44335  213151  20627      0  3        0x92  select        sshd
 48486  317805      1      0  3    0x100083  ttyin         getty
 20627  454646      1      0  3        0x80  select        sshd
 24814  143825  21834     73  3    0x100090  kqread        syslogd
 21834  128170      1      0  3    0x100082  netio         syslogd
 11078  282038      1     77  3    0x100090  poll          dhclient
 32570  485575      1      0  3        0x80  poll          dhclient
 62157  435882      0      0  2     0x14200                zerothread
 77651  227550      0      0  3     0x14200  aiodoned      aiodoned
 33305  442185      0      0  3     0x14200  syncer        update
 18223  156886      0      0  3     0x14200  cleaner       cleaner
 32030  317104      0      0  3     0x14200  reaper        reaper
 12306   73830      0      0  3     0x14200  pgdaemon      pagedaemon
 85352   70320      0      0  3     0x14200  bored         crynlk
 88717   35408      0      0  3     0x14200  bored         crypto
 72092  404617      0      0  3  0x40014200  acpi0         acpi0
 36610  288976      0      0  3  0x40014200                idle1
 77393  268240      0      0  3     0x14200  bored         softnet
 45317  512453      0      0  3     0x14200  bored         systqmp
 97032  238928      0      0  3     0x14200  bored         systq
 95893  166655      0      0  3  0x40014200  bored         softclock
 55700  432381      0      0  3  0x40014200                idle0
     1  444557      0      0  3        0x82  wait          init
     0       0     -1      0  3     0x10200  scheduler     swapper

Crashes (17):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-openbsd-setuid 2018/12/26 05:50 openbsd 65e1198b816d 8a41a0ad .config log report syz C
ci-openbsd-setuid 2018/12/25 10:27 openbsd d55171694444 8a41a0ad .config log report syz
ci-openbsd-setuid 2019/01/05 23:08 openbsd 810d6e19cd5f 53be0a37 .config log report
ci-openbsd-setuid 2019/01/05 21:17 openbsd 810d6e19cd5f 53be0a37 .config log report
ci-openbsd-setuid 2019/01/04 16:34 openbsd 4f234a09dcd1 0127e3ba .config log report
ci-openbsd-setuid 2019/01/04 09:37 openbsd 3139a193289d 7da23925 .config log report
ci-openbsd-setuid 2019/01/04 07:59 openbsd 3139a193289d 7da23925 .config log report
ci-openbsd-multicore 2019/01/03 21:26 openbsd 5112d5d939be 66fcd29b .config log report
ci-openbsd-setuid 2019/01/02 11:05 openbsd 3756733c7afe f0491811 .config log report
ci-openbsd-setuid 2019/01/02 02:06 openbsd bbeffd043972 3d85f48c .config log report
ci-openbsd-multicore 2018/12/31 19:49 openbsd 1838c31d434f 70b2a9e8 .config log report
ci-openbsd-multicore 2018/12/31 01:30 openbsd ef327be8754b 2b42fdc8 .config log report
ci-openbsd-setuid 2018/12/30 21:27 openbsd ef327be8754b 2b42fdc8 .config log report
ci-openbsd-setuid 2018/12/26 15:25 openbsd aad1a0fbcad3 8a41a0ad .config log report
ci-openbsd-setuid 2018/12/26 04:19 openbsd 65e1198b816d 8a41a0ad .config log report
ci-openbsd-setuid 2018/12/25 11:41 openbsd d55171694444 8a41a0ad .config log report
ci-openbsd-setuid 2018/12/25 10:09 openbsd d55171694444 8a41a0ad .config log report
* Struck through repros no longer work on HEAD.