Re: LOR during boot (if_sis.c/kbdmux.c - Giant after non-sleepable)

2008/10/9 Maksim Yevmenkin <maksim.yevmenkin_at_gmail.com>:
> On 10/8/08, Bruce Cran <bruce_at_cran.org.uk> wrote:
>> During boot I pressed Scroll Lock at the wrong time and got a LOR.
>> Switching between consoles became really slow once the system was running,
>> taking a couple of seconds each time.
>>  I'm running -current from a few days ago.
>>
>>  lock order reversal: (Giant after non-sleepable)
>>  1st 0xc4283e84 sis0 (network driver) _at_
>> /usr/src/sys/dev/sis/if_sis.c:2106
>>  2nd 0xc0d0d430 Giant (Giant) _at_
>> /usr/src/sys/dev/kbdmux/kbdmux.c:1103
>>  KDB: stack backtrace:
>> db_trace_self_wrapper(c0bc49d7,c3ee27f0,c0837e85,4,c0bc0367,...)
>> at db_trace_self_wrapper+0x26
>> kdb_backtrace(4,c0bc0367,c0b9b6f1,c411d1a0,c3ee2848,...)
>> at kdb_backtrace+0x29
>> _witness_debugger(c0bc728c,c0d0d430,c0be0869,c411d1a0,c0b9b6f1,...)
>> at _witness_debugger+0x25
>>  witness_checkorder(c0d0d430,9,c0b9b6f1,44f,0,...) at
>> witness_checkorder+0x800
>>  _mtx_lock_flags(c0d0d430,0,c0b9b6f1,44f,c4167d20,...) at
>> _mtx_lock_flags+0xc4
>> kbdmux_ioctl(c4221b00,40044b13,c3ee28c8,100202,7,...)
>> at kbdmux_ioctl+0x76e
>> update_kbd_state(c0bc0367,c0bbaf86,2,c44b08c0,c0c577a0,...)
>> at update_kbd_state+0x44
>>  sc_cnputc(c0c577a0,73,c3ee2a94,5,73,...) at sc_cnputc+0x39
>>  cnputc(73,c3ee2a94,c3ee2944,c082a2a1,c0be63cd,...) at
>> cnputc+0x5f
>>  putcons(c0be63cd,c0bbaf86,1000001,c41d9d6d,c082a240,...)
>> at putcons+0x17
>>  putchar(73,c3ee2a94,c0d11900,1,c41d9d6f,...) at
>> putchar+0x61
>>  kvprintf(c0b668aa,c082a240,c3ee2a94,a,c3ee2ac0,...) at
>> kvprintf+0xa27
>>  printf(c0b668aa,c41d9d6c,0,c4283e00,c4283e00,...) at
>> printf+0x4e
>> device_print_prettyname(c4277c80,c4289800,c4283e00,c4283e00,c3ee2b24,...)
>> at device_print_prettyname+0x4c
>>  device_printf(c4277c80,c0bab5be,f4,0,c06da240,...) at
>> device_printf+0x12
>>  sis_initl(c4283e84,0,c0bab5a0,83a,80206910,...) at
>> sis_initl+0x99d
>>  sis_ioctl(c428cc00,80206910,c45ab740,628,c428cc00,...) at
>> sis_ioctl+0xa8
>> ifhwioctl(c44b08c0,c452122c,c0e4d6d0,c44b0964,c0e4d6d0,...)
>> at ifhwioctl+0x3eb
>> ifioctl(c4555ab8,80206910,c45ab740,c44b08c0,80206910,...)
>> at ifioctl+0x305
>> soo_ioctl(c449f3b8,80206910,c45ab740,c4169400,c44b08c0,...)
>> at soo_ioctl+0x397
>>  kern_ioctl(c44b08c0,5,80206910,c45ab740,8318c0,...) at
>> kern_ioctl+0x1dd
>>  ioctl(c44b08c0,c3ee2cf8,c,c0bf8ba3,c0c9b110,...) at
>> ioctl+0x134
>>  syscall(c3ee2d38) at syscall+0x2a3
>>  Xint0x80_syscall() at Xint0x80_syscall+0x20
>>  --- syscall (54, FreeBSD ELF32, ioctl), eip = 0x281a9a23, esp = 0xbfbfe5bc,
>> ebp = 0xbfbfe618 ---
>
> well, this particular lor is caused by the fact that sc_cnputc() wants
> to muck around kbd state. i do not know syscons code very well, but
> this looks rather strange to me. i really do not know why the function
> that really should just put a char on screen wants to do something
> with kbd. i see the code tries to deal with scroll lock, so that is
> consistent with your report.
>
> kbdmux was recently changed to use Giant based locking (as an attempt
> to work around other problems). when update_kbd_state() uses ioctl()
> on kbd device, kbdmux will try to grab Giant. the whole thing was
> started by device_printf() that is called from sis_initl() with
> another mutex held.
>
> so, to me, sc_cnputc() is broken and should be fixed.
>

Just to confirm it still exists. A bit different LOR though.
CURRENT from December.

lock order reversal: (Giant after non-sleepable)
 1st 0xc5e08074 vnode interlock (vnode interlock) _at_
/usr/src/sys/vm/vnode_pager.c:1201
 2nd 0xc087f9d0 Giant (Giant) _at_ /usr/src/sys/dev/kbdmux/kbdmux.c:1103
KDB: stack backtrace:
db_trace_self_wrapper(c07f3714,e7cc564c,c05d7425,4,c07eec87,...) at
db_trace_self_wrapper+0x26
kdb_backtrace(4,c07eec87,c54f50a8,c54f41a0,e7cc56a8,...) at kdb_backtrace+0x29
_witness_debugger(c07f639f,c087f9d0,c0807a3d,c54f41a0,c07df81e,...) at
_witness_debugger+0x25
witness_checkorder(c087f9d0,9,c07df81e,44f,0,...) at witness_checkorder+0x839
_mtx_lock_flags(c087f9d0,0,c07df81e,44f,e7cc5700,...) at _mtx_lock_flags+0xc4
kbdmux_ioctl(c5608600,40044b13,e7cc5728,100202,c083e324,...) at
kbdmux_ioctl+0x76e
update_kbd_state(c0589e3c,c5df3e10,4,c07eec87,c0831bc0,...) at
update_kbd_state+0x44
sc_cnputc(c0831bc0,6c,e7cc58f4,5,6c,...) at sc_cnputc+0x39
cnputc(6c,e7cc58f4,e7cc57a4,c05c9871,c07fd19d,...) at cnputc+0x5f
putcons(c07fd19d,c07eec87,100009a,c09bfd80,c05c9810,...) at putcons+0x17
putchar(6c,e7cc58f4,246,c07e9e46,c59b0900,...) at putchar+0x61
kvprintf(c07f633c,c05c9810,e7cc58f4,a,e7cc5920,...) at kvprintf+0x9e
printf(c07f633c,0,c07f55e7,4e3,e7cc5944,...) at printf+0x4e
witness_checkorder(c5e08058,9,c07fd19d,81f,0,...) at witness_checkorder+0x6a1
__lockmgr_args(c5e08058,200501,c5e08074,0,0,...) at __lockmgr_args+0x797
vop_stdlock(e7cc5a78,c05d71cb,c0810948,200501,c5e08000,...) at vop_stdlock+0x62
VOP_LOCK1_APV(c5a2a000,e7cc5a78,c59b09a4,c0867bc0,c5e08000,...) at
VOP_LOCK1_APV+0xa5
_vn_lock(c5e08000,200501,c07fd19d,81f,4,...) at _vn_lock+0x5e
vget(c5e08000,200501,c59b0900,4b2,0,...) at vget+0xc9
vnode_pager_lock(c5e1a744,0,c080df26,127,e7cc5c18,...) at vnode_pager_lock+0x1e0
vm_fault(c5b91000,281a0000,1,0,281a0000,...) at vm_fault+0x1df
trap_pfault(5,0,c08195a4,2e7,c59b0900,...) at trap_pfault+0xf9
trap(e7cc5d38) at trap+0x289
calltrap() at calltrap+0x6
--- trap 0xc, eip = 0x80496d0, esp = 0xbfbfec80, ebp = 0xbfbfed58 ---

--
wbr,
pluknet