From owner-freebsd-hackers@FreeBSD.ORG Fri Jun 5 14:58:15 2009 Return-Path: Delivered-To: freebsd-hackers@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 35613106564A for ; Fri, 5 Jun 2009 14:58:15 +0000 (UTC) (envelope-from kostjn@peterhost.ru) Received: from mail.z8.ru (mail.z8.ru [80.93.58.56]) by mx1.freebsd.org (Postfix) with ESMTP id A26B78FC0C for ; Fri, 5 Jun 2009 14:58:14 +0000 (UTC) (envelope-from kostjn@peterhost.ru) Received: from [85.235.196.139] (helo=kostjn.pht) by mail.z8.ru with esmtpa (Exim 4.67 (FreeBSD)) (envelope-from ) id 1MCarv-000IsG-No for freebsd-hackers@freebsd.org; Fri, 05 Jun 2009 18:58:07 +0400 Message-ID: <4A293302.5040306@peterhost.ru> Date: Fri, 05 Jun 2009 19:00:18 +0400 From: Menshikov Konstantin User-Agent: Thunderbird 2.0.0.18 (X11/20090328) MIME-Version: 1.0 CC: freebsd-hackers@freebsd.org References: <4A2792B7.5010006@peterhost.ru> <200906040749.17206.jhb@freebsd.org> <4A27C5E8.7020902@peterhost.ru> <200906050938.25706.jhb@freebsd.org> In-Reply-To: <200906050938.25706.jhb@freebsd.org> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit Subject: Re: Inline function (difficult debug) X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 05 Jun 2009 14:58:15 -0000 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
) >>>> 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 , 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 >>>> , 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 , 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 to continue, or q 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 , 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.