Date: Fri, 05 Jun 2009 19:00:18 +0400 From: Menshikov Konstantin <kostjn@peterhost.ru> Cc: freebsd-hackers@freebsd.org Subject: Re: Inline function (difficult debug) Message-ID: <4A293302.5040306@peterhost.ru> In-Reply-To: <200906050938.25706.jhb@freebsd.org> References: <4A2792B7.5010006@peterhost.ru> <200906040749.17206.jhb@freebsd.org> <4A27C5E8.7020902@peterhost.ru> <200906050938.25706.jhb@freebsd.org>
next in thread | previous in thread | raw e-mail | index | archive | help
John Baldwin wrote:
> On Thursday 04 June 2009 9:02:32 am Menshikov Konstantin wrote:
>
>> John Baldwin wrote:
>>
>>> On Thursday 04 June 2009 5:24:07 am Menshikov Konstantin wrote:
>>>
>>>
>>>> Hi.
>>>> My system FreeBSD 7.1 RELEASE periodically freeze.
>>>>
>>>> I`m compiling kernel with WITNESS and get backtrace.
>>>>
>>>> #0 doadump () at pcpu.h:195
>>>> #1 0xffffffff801a899c in db_fncall (dummy1=Variable "dummy1" is not
>>>> available.
>>>> ) at /usr/src/sys/ddb/db_command.c:516
>>>> #2 0xffffffff801a8ecf in db_command (last_cmdp=0xffffffff80825688,
>>>> cmd_table=0x0, dopager=1)
>>>> at /usr/src/sys/ddb/db_command.c:413
>>>> #3 0xffffffff801a90e0 in db_command_loop () at
>>>> /usr/src/sys/ddb/db_command.c:466
>>>> #4 0xffffffff801aaa19 in db_trap (type=Variable "type" is not available.
>>>> ) at /usr/src/sys/ddb/db_main.c:228
>>>> #5 0xffffffff803d5e55 in kdb_trap (type=3, code=0,
>>>> tf=0xffffffffabf284c0) at /usr/src/sys/kern/subr_kdb.c:524
>>>> #6 0xffffffff8059a0e5 in trap (frame=0xffffffffabf284c0) at
>>>> /usr/src/sys/amd64/amd64/trap.c:538
>>>> #7 0xffffffff8057f60e in calltrap () at
>>>> /usr/src/sys/amd64/amd64/exception.S:209
>>>> #8 0xffffffff803d602d in kdb_enter_why (why=0xffffffff80628137
>>>> "witness", msg=0xa <Address 0xa out of bounds>)
>>>> at cpufunc.h:63
>>>> #9 0xffffffff803e70c3 in witness_checkorder (lock=Variable "lock" is not
>>>> available.
>>>> ) at /usr/src/sys/kern/subr_witness.c:1126
>>>> #10 0xffffffff8039e341 in _mtx_lock_spin_flags (m=0xffffffff8084fad0,
>>>> opts=0, file=dwarf2_read_address: Corrupted DWARF expression.
>>>> ) at /usr/src/sys/kern/kern_mutex.c:227
>>>> #11 0xffffffff80319838 in sc_puts (scp=0xffffffff8084f980,
>>>> buf=0xffffffffabf286a7 "a@\az\200ЪЪЪЪ", len=1)
>>>> at /usr/src/sys/dev/syscons/syscons.c:2519
>>>> #12 0xffffffff8031b3da in sc_cnputc (cd=Variable "cd" is not available.
>>>> ) at /usr/src/sys/dev/syscons/syscons.c:1561
>>>> #13 0xffffffff803f9d89 in cnputc (c=97)
>>>>
> at /usr/src/sys/kern/tty_cons.c:632
>
>>>> #14 0xffffffff803d993b in putchar (c=97, arg=Variable "arg" is not
>>>> available.
>>>> ) at /usr/src/sys/kern/subr_prf.c:421
>>>> #15 0xffffffff803d7f22 in kvprintf (fmt=0xffffffff80628b89 "cquiring
>>>> duplicate lock of same type: \"%s\"\n",
>>>> func=0xffffffff803d98d0 <putchar>, arg=0xffffffffabf28890, radix=10,
>>>> ap=Variable "ap" is not available.
>>>> ) at /usr/src/sys/kern/subr_prf.c:674
>>>> #16 0xffffffff803d9384 in printf (fmt=Variable "fmt" is not available.
>>>> ) at /usr/src/sys/kern/subr_prf.c:314
>>>> #17 0xffffffff803e705d in witness_checkorder (lock=0xffffffff808668f8,
>>>> flags=0,
>>>> file=0xffffffff80626cf8 "/usr/src/sys/kern/subr_sleepqueue.c", line=232)
>>>> at /usr/src/sys/kern/subr_witness.c:948
>>>> #18 0xffffffff8039e341 in _mtx_lock_spin_flags (m=0xffffffff808668f8,
>>>> opts=0, file=dwarf2_read_address: Corrupted DWARF expression.
>>>> ) at /usr/src/sys/kern/kern_mutex.c:227
>>>> #19 0xffffffff803b2271 in wakeup (ident=0xffffffff80850ac0) at
>>>> /usr/src/sys/kern/kern_synch.c:341
>>>> #20 0xffffffff803aed95 in tdsignal (p=0xffffff00017978f0,
>>>> td=0xffffff000146a6e0, sig=14, ksi=Variable "ksi" is not available.
>>>> )
>>>> at /usr/src/sys/kern/kern_sig.c:2292
>>>> #21 0xffffffff803ba2de in realitexpire (arg=Variable "arg" is not
>>>>
> available.
>
>>>> ) at /usr/src/sys/kern/kern_time.c:669
>>>> #22 0xffffffff803bbe1a in softclock (dummy=Variable "dummy" is not
>>>> available.
>>>> ) at /usr/src/sys/kern/kern_timeout.c:274
>>>> #23 0xffffffff8038c120 in ithread_loop (arg=0xffffff00010ebc00) at
>>>> /usr/src/sys/kern/kern_intr.c:1088
>>>> #24 0xffffffff8038978a in fork_exit (callout=0xffffffff8038c040
>>>> <ithread_loop>, arg=0xffffff00010ebc00,
>>>> frame=0xffffffffabf28c80) at /usr/src/sys/kern/kern_fork.c:804
>>>> #25 0xffffffff8057f9de in fork_trampoline () at
>>>> /usr/src/sys/amd64/amd64/exception.S:455
>>>>
>>>> But file /usr/src/sys/kern/kern_sig.c:2292
>>>> hasn`t run function wake up on string 2292
>>>> I`m think, what compiler use inline function, therefore code and trace
>>>> differ.
>>>> Tell me please, how compile kernel without any inline function.
>>>>
>
>
> Where did you get the pointer values from? I meant doing 'frame 17', 'p
> i', 'p *lock', 'p *lock1', 'p *lock2'
>
>
Excuse I has not understood you.
Disable optimization -O0, disable inline function.
I`m get new backtrace
#0 doadump () at /usr/src/sys/kern/kern_shutdown.c:244
#1 0xffffffff801c58fc in db_fncall_generic (addr=-2142879744,
rv=0xffffffffac0f9d88, nargs=0, args=0xffffffffac0f9d90)
at /usr/src/sys/ddb/db_command.c:516
#2 0xffffffff801c5805 in db_fncall (dummy1=-2136396608, dummy2=0,
dummy3=-1408262592,
dummy4=0xffffffffac0f9e30 "`\224\224\200ЪЪЪЪЪЪЪЪ\r") at
/usr/src/sys/ddb/db_command.c:568
#3 0xffffffff801c5546 in db_command (last_cmdp=0xffffffff809d14c0,
cmd_table=0x0, dopager=1)
at /usr/src/sys/ddb/db_command.c:413
#4 0xffffffff801c5644 in db_command_loop () at
/usr/src/sys/ddb/db_command.c:466
#5 0xffffffff801c81e9 in db_trap (type=3, code=0) at
/usr/src/sys/ddb/db_main.c:228
#6 0xffffffff8049d629 in kdb_trap (type=3, code=0,
tf=0xffffffffac0fa0f0) at /usr/src/sys/kern/subr_kdb.c:524
#7 0xffffffff807180d2 in trap (frame=0xffffffffac0fa0f0) at
/usr/src/sys/amd64/amd64/trap.c:538
#8 0xffffffff806f7cee in calltrap () at
/usr/src/sys/amd64/amd64/exception.S:209
#9 0xffffffff8049d0c5 in breakpoint () at cpufunc.h:63
#10 0xffffffff8049d0b2 in kdb_enter_why (why=0xffffffff807c9140
"witness", msg=0xffffffff807c97f0 "witness_checkorder")
at /usr/src/sys/kern/subr_kdb.c:315
#11 0xffffffff804b3db8 in witness_checkorder (lock=0xffffffff809fb8b0,
flags=9,
file=0xffffffff807aeb30 "/usr/src/sys/dev/syscons/syscons.c",
line=2519) at /usr/src/sys/kern/subr_witness.c:1126
#12 0xffffffff80453ead in _mtx_lock_spin_flags (m=0xffffffff809fb8b0,
opts=0,
file=0xffffffff807aeb30 "/usr/src/sys/dev/syscons/syscons.c",
line=2519) at /usr/src/sys/kern/kern_mutex.c:227
#13 0xffffffff803a0d4d in sc_puts (scp=0xffffffff809fb760,
buf=0xffffffffac0fa337 "a`╥\237\200ЪЪЪЪ\200д)\001", len=1)
at /usr/src/sys/dev/syscons/syscons.c:2519
#14 0xffffffff8039f063 in sc_cnputc (cd=0xffffffff80949460, c=97) at
/usr/src/sys/dev/syscons/syscons.c:1561
#15 0xffffffff804cf82f in cnputc (c=97) at /usr/src/sys/kern/tty_cons.c:632
#16 0xffffffff804a0864 in putcons (c=97, ap=0xffffffffac0fa6b0) at
/usr/src/sys/kern/subr_prf.c:372
#17 0xffffffff804a09a4 in putchar (c=97, arg=0xffffffffac0fa6b0) at
/usr/src/sys/kern/subr_prf.c:413
#18 0xffffffff804a0ee9 in kvprintf (fmt=0xffffffff807c9911 "cquiring
duplicate lock of same type: \"%s\"\n",
func=0xffffffff804a0920 <putchar>, arg=0xffffffffac0fa6b0, radix=10,
ap=0xffffffffac0fa6e0)
at /usr/src/sys/kern/subr_prf.c:599
#19 0xffffffff804a07a4 in printf (fmt=0xffffffff807c9910 "acquiring
duplicate lock of same type: \"%s\"\n")
at /usr/src/sys/kern/subr_prf.c:314
#20 0xffffffff804b374e in witness_checkorder (lock=0xffffffff80a13448,
flags=9,
file=0xffffffff807c7a38 "/usr/src/sys/kern/subr_sleepqueue.c",
line=232) at /usr/src/sys/kern/subr_witness.c:948
#21 0xffffffff80453ead in _mtx_lock_spin_flags (m=0xffffffff80a13448,
opts=0,
file=0xffffffff807c7a38 "/usr/src/sys/kern/subr_sleepqueue.c",
line=232) at /usr/src/sys/kern/kern_mutex.c:227
#22 0xffffffff804a8472 in sleepq_lock (wchan=0xffffffff809fc8a0) at
/usr/src/sys/kern/subr_sleepqueue.c:232
#23 0xffffffff80470175 in wakeup (ident=0xffffffff809fc8a0) at
/usr/src/sys/kern/kern_synch.c:341
#24 0xffffffff806cf110 in kick_proc0 () at /usr/src/sys/vm/vm_glue.c:761
#25 0xffffffff8046aa16 in tdsigwakeup (td=0xffffff000172a000, sig=14,
action=0x2, intrval=4)
at /usr/src/sys/kern/kern_sig.c:2422
#26 0xffffffff8046a5d1 in do_tdsignal (p=0xffffff0001727000,
td=0xffffff000172a000, sig=14, ksi=0xffffff00017dfd68)
at /usr/src/sys/kern/kern_sig.c:2292
#27 0xffffffff80469d48 in tdsignal (p=0xffffff0001727000, td=0x0,
sig=14, ksi=0xffffff00017dfd68)
at /usr/src/sys/kern/kern_sig.c:2029
#28 0xffffffff80469cd9 in psignal_event (p=0xffffff0001727000,
sigev=0xffffff00017dfcd8, ksi=0xffffff00017dfd68)
at /usr/src/sys/kern/kern_sig.c:2017
#29 0xffffffff8047c036 in itimer_fire (it=0xffffff00017dfca8) at
/usr/src/sys/kern/kern_time.c:1419
#30 0xffffffff8047be84 in realtimer_expire (arg=0xffffff00017dfca8) at
/usr/src/sys/kern/kern_time.c:1396
#31 0xffffffff8047c9a6 in softclock (dummy=0x0) at
/usr/src/sys/kern/kern_timeout.c:274
#32 0xffffffff8043c057 in ithread_execute_handlers
(p=0xffffff0001105000, ie=0xffffff000110c000)
---Type <return> to continue, or q <return> to quit---
at /usr/src/sys/kern/kern_intr.c:1088
#33 0xffffffff8043c28f in ithread_loop (arg=0xffffff00010ecbe0) at
/usr/src/sys/kern/kern_intr.c:1175
#34 0xffffffff8043a3d7 in fork_exit (callout=0xffffffff8043c1d0
<ithread_loop>, arg=0xffffff00010ecbe0,
frame=0xffffffffac0fac80) at /usr/src/sys/kern/kern_fork.c:804
#35 0xffffffff806f80be in fork_trampoline () at
/usr/src/sys/amd64/amd64/exception.S:455
Frame 20
(kgdb) f 20
#20 0xffffffff804b374e in witness_checkorder (lock=0xffffffff80a13448,
flags=9,
file=0xffffffff807c7a38 "/usr/src/sys/kern/subr_sleepqueue.c",
line=232) at /usr/src/sys/kern/subr_witness.c:948
948 printf("acquiring duplicate lock of same type: \"%s\"\n",
(kgdb) p *lock
$1 = {lo_name = 0xffffffff807c7a20 "sleepq chain", lo_type =
0xffffffff807c7a20 "sleepq chain", lo_flags = 720896,
lo_witness_data = {lod_list = {stqe_next = 0xffffffff80a251a0},
lod_witness = 0xffffffff80a251a0}}
(kgdb) p *lock1
$2 = {li_lock = 0xffffffff80a12db8, li_file = 0xffffffff807c22f5
"/usr/src/sys/kern/kern_sig.c", li_line = 2291,
li_flags = 65536}
(kgdb) p *lock2
$3 = {li_lock = 0xffffffff80a10d40, li_file = 0xffffff0001105000
"xT\020\001", li_line = 0, li_flags = 0}
(kgdb) p i
$4 = -2139345904
Frame 11
(kgdb) f 11
#11 0xffffffff804b3db8 in witness_checkorder (lock=0xffffffff809fb8b0,
flags=9,
file=0xffffffff807aeb30 "/usr/src/sys/dev/syscons/syscons.c",
line=2519) at /usr/src/sys/kern/subr_witness.c:1126
1126 kdb_enter_why(KDB_WHY_WITNESS, __func__);
(kgdb) p *lock
$6 = {lo_name = 0xffffffff807aebc5 "scrlock", lo_type =
0xffffffff807aebc5 "scrlock", lo_flags = 8585216,
lo_witness_data = {lod_list = {stqe_next = 0xffffffff80a25320},
lod_witness = 0xffffffff80a25320}}
(kgdb) p *lock1
$7 = {li_lock = 0xffffffff80a12db8, li_file = 0xffffffff807c22f5
"/usr/src/sys/kern/kern_sig.c", li_line = 2291,
li_flags = 65536}
(kgdb) p *lock2
$8 = {li_lock = 0xffffff0001727030, li_file = 0xffffffff807c22f5
"/usr/src/sys/kern/kern_sig.c", li_line = 2176,
li_flags = 65536}
(kgdb) p i
$9 = -1
Thanks.
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?4A293302.5040306>