From owner-freebsd-current@FreeBSD.ORG Sun Apr 10 13:53:18 2011 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id AE379106566C for ; Sun, 10 Apr 2011 13:53:18 +0000 (UTC) (envelope-from freebsd-listen@fabiankeil.de) Received: from smtprelay02.ispgateway.de (smtprelay02.ispgateway.de [80.67.31.25]) by mx1.freebsd.org (Postfix) with ESMTP id F01E98FC0A for ; Sun, 10 Apr 2011 13:53:17 +0000 (UTC) Received: from [87.78.60.163] (helo=fabiankeil.de) by smtprelay02.ispgateway.de with esmtpsa (TLSv1:AES128-SHA:128) (Exim 4.68) (envelope-from ) id 1Q8uq8-0003w9-Sr for freebsd-current@freebsd.org; Sun, 10 Apr 2011 15:38:13 +0200 Date: Sun, 10 Apr 2011 15:37:59 +0200 From: Fabian Keil To: FreeBSD Current Message-ID: <20110410153759.025aa4e2@fabiankeil.de> X-PGP-KEY-URL: http://www.fabiankeil.de/gpg-keys/freebsd-listen-2008-08-18.asc Mime-Version: 1.0 Content-Type: multipart/signed; micalg=PGP-SHA1; boundary="Sig_/4Y4l7W31jqEr+83ZrQmmKDx"; protocol="application/pgp-signature" X-Df-Sender: 775067 Subject: panic: _mtx_lock_sleep: recursed on non-recursive mutex process lock @ /usr/src/sys/kern/kern_exit.c:912 X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 10 Apr 2011 13:53:18 -0000 --Sig_/4Y4l7W31jqEr+83ZrQmmKDx Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: quoted-printable The following panic seems to be reliably reproducible with sources from yesterday (and today) by running claws-mail in X, switching to the console and trying to attach gdb to it with 'gdb -p $(pgrep claws-mail)= '. gdb somehow fails to attach, and after leaving gdb the panic occurs. fk@r500 /usr/crash $cat info.0=20 Dump header from device /dev/ada0s1b Architecture: amd64 =20 Architecture Version: 2 =20 Dump Length: 347676672B (331 MB) Blocksize: 512 =20 Dumptime: Sat Apr 9 22:48:15 2011 Hostname: r500.local =20 Magic: FreeBSD Kernel Dump =20 Version String: FreeBSD 9.0-CURRENT #284 r+1c500d9: Sat Apr 9 15:44:51 C= EST 2011 fk@r500.local:/usr/obj/usr/src/sys/ZOEY Panic String: _mtx_lock_sleep: recursed on non-recursive mutex process lo= ck @ /usr/src/sys/kern/kern_exit.c:912 Dump Parity: 1557143341 Bounds: 0 Dump Status: good fk@r500 /usr/crash $kgdb /boot/kernel/kernel vmcore.0=20 GNU gdb 6.1.1 [FreeBSD] Copyright 2004 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or distribute copies of it under certain condition= s. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. This GDB was configured as "amd64-marcel-freebsd"... Unread portion of the kernel message buffer: panic: _mtx_lock_sleep: recursed on non-recursive mutex process lock @ /usr= /src/sys/kern/kern_exit.c:912 cpuid =3D 0 KDB: enter: panic panic: from debugger cpuid =3D 0 Uptime: 3m48s Physical memory: 1974 MB Dumping 331 MB: 316 300 284 268 252 236 220 204 188 172 156 140 124 108 92 = 76 60 44 28 12 Reading symbols from /boot/kernel/zfs.ko...Reading symbols from /boot/kerne= l/zfs.ko.symbols...done. done. [...] Loaded symbols for /boot/kernel/drm.ko #0 doadump () at /usr/src/sys/kern/kern_shutdown.c:250 250 if (textdump_pending) (kgdb) where #0 doadump () at /usr/src/sys/kern/kern_shutdown.c:250 #1 0xffffffff80531fb7 in kern_reboot (howto=3D260) at /usr/src/sys/kern/ke= rn_shutdown.c:418 #2 0xffffffff80531a51 in panic (fmt=3DVariable "fmt" is not available. ) at /usr/src/sys/kern/kern_shutdown.c:591 #3 0xffffffff803202b7 in db_panic (addr=3DVariable "addr" is not available. ) at /usr/src/sys/ddb/db_command.c:478 #4 0xffffffff80320761 in db_command (last_cmdp=3D0xffffffff80c9fb60, cmd_t= able=3DVariable "cmd_table" is not available. ) at /usr/src/sys/ddb/db_command.c:445 #5 0xffffffff803209b0 in db_command_loop () at /usr/src/sys/ddb/db_command= .c:498 #6 0xffffffff80322a99 in db_trap (type=3DVariable "type" is not available. ) at /usr/src/sys/ddb/db_main.c:229 #7 0xffffffff80567ba1 in kdb_trap (type=3D3, code=3D0, tf=3D0xffffff800001= 7740) at /usr/src/sys/kern/subr_kdb.c:533 #8 0xffffffff807cee06 in trap (frame=3D0xffffff8000017740) at /usr/src/sys= /amd64/amd64/trap.c:590 #9 0xffffffff807b9303 in calltrap () at /usr/src/sys/amd64/amd64/exception= .S:228 #10 0xffffffff805679fb in kdb_enter (why=3D0xffffffff80955faf "panic", msg= =3D0xa
) at cpufunc.h:63 #11 0xffffffff80531a60 in panic (fmt=3DVariable "fmt" is not available. ) at /usr/src/sys/kern/kern_shutdown.c:574 #12 0xffffffff805222f9 in _mtx_lock_sleep (m=3DVariable "m" is not availabl= e. ) at /usr/src/sys/kern/kern_mutex.c:341 #13 0xffffffff805223a5 in _mtx_lock_flags (m=3DVariable "m" is not availabl= e. ) at /usr/src/sys/kern/kern_mutex.c:203 #14 0xffffffff80503789 in proc_reparent (child=3D0xfffffe001290a000, parent= =3D0xfffffe0012e48900) at /usr/src/sys/kern/kern_exit.c:912 #15 0xffffffff80503ed8 in kern_wait (td=3D0xffffff8000017adc, pid=3DVariabl= e "pid" is not available. ) at /usr/src/sys/kern/kern_exit.c:708 #16 0xffffffff805043e5 in wait4 (td=3DVariable "td" is not available. ) at /usr/src/sys/kern/kern_exit.c:653 #17 0xffffffff805751ab in syscallenter (td=3D0xfffffe00028838c0, sa=3D0xfff= fff8000017bb0) at /usr/src/sys/kern/subr_trap.c:344 #18 0xffffffff807ce8bc in syscall (frame=3D0xffffff8000017c50) at /usr/src/= sys/amd64/amd64/trap.c:910 #19 0xffffffff807b95cd in Xfast_syscall () at /usr/src/sys/amd64/amd64/exce= ption.S:384 #20 0x000000000040cb8c in ?? () Previous frame inner to this frame (corrupt stack?) (kgdb) f 14 #14 0xffffffff80503789 in proc_reparent (child=3D0xfffffe001290a000, parent= =3D0xfffffe0012e48900) at /usr/src/sys/kern/kern_exit.c:912 912 PROC_LOCK(parent); (kgdb) p *child $2 =3D {p_list =3D {le_next =3D 0x0, le_prev =3D 0xffffffff80cba328}, p_thr= eads =3D {tqh_first =3D 0xfffffe001287c000, tqh_last =3D 0xfffffe001287c010= }, p_slock =3D {lock_object =3D { lo_name =3D 0xffffffff80954527 "process slock", lo_flags =3D 720896, = lo_data =3D 0, lo_witness =3D 0x0}, mtx_lock =3D 4}, p_ucred =3D 0xfffffe00= 427b5a00, p_fd =3D 0x0,=20 p_fdtol =3D 0x0, p_stats =3D 0xfffffe0005d82800, p_limit =3D 0x0, p_limco= =3D {c_links =3D {sle =3D {sle_next =3D 0x0}, tqe =3D {tqe_next =3D 0x0, t= qe_prev =3D 0x0}}, c_time =3D 0, c_arg =3D 0x0,=20 c_func =3D 0, c_lock =3D 0xfffffe001290a0f8, c_flags =3D 0, c_cpu =3D 0= }, p_sigacts =3D 0xfffffe0042634000, p_flag =3D 268460034, p_state =3D PRS_= ZOMBIE, p_pid =3D 3515, p_hash =3D { le_next =3D 0x0, le_prev =3D 0xffffff8000222dd8}, p_pglist =3D {le_next= =3D 0x0, le_prev =3D 0xfffffe004a876790}, p_pptr =3D 0xfffffe0002881900, p= _sibling =3D { le_next =3D 0xfffffe0042640900, le_prev =3D 0xfffffe00028819f0}, p_chil= dren =3D {lh_first =3D 0x0}, p_mtx =3D {lock_object =3D {lo_name =3D 0xffff= ffff8095451a "process lock",=20 lo_flags =3D 21168128, lo_data =3D 0, lo_witness =3D 0x0}, mtx_lock = =3D 18446741874728777920}, p_ksi =3D 0xfffffe0005c60150, p_sigqueue =3D {sq= _signals =3D {__bits =3D {0, 0, 0, 0}},=20 sq_kill =3D {__bits =3D {0, 0, 0, 0}}, sq_list =3D {tqh_first =3D 0x0, = tqh_last =3D 0xfffffe001290a140}, sq_proc =3D 0xfffffe001290a000, sq_flags = =3D 1}, p_oppid =3D 0,=20 p_vmspace =3D 0xffffffff80cb7760, p_swtick =3D 21105, p_realtimer =3D {it= _interval =3D {tv_sec =3D 0, tv_usec =3D 0}, it_value =3D {tv_sec =3D 0, tv= _usec =3D 0}}, p_ru =3D {ru_utime =3D { tv_sec =3D 0, tv_usec =3D 0}, ru_stime =3D {tv_sec =3D 0, tv_usec =3D= 0}, ru_maxrss =3D 21044, ru_ixrss =3D 544640, ru_idrss =3D 334244, ru_isrs= s =3D 27264, ru_minflt =3D 2745,=20 ru_majflt =3D 2158, ru_nswap =3D 0, ru_inblock =3D 3, ru_oublock =3D 0,= ru_msgsnd =3D 134, ru_msgrcv =3D 103, ru_nsignals =3D 0, ru_nvcsw =3D 473,= ru_nivcsw =3D 533}, p_rux =3D { rux_runtime =3D 2346291660, rux_uticks =3D 119, rux_sticks =3D 29, rux_= iticks =3D 0, rux_uu =3D 948699, rux_su =3D 223223, rux_tu =3D 1171923}, p_= crux =3D {rux_runtime =3D 0,=20 rux_uticks =3D 0, rux_sticks =3D 0, rux_iticks =3D 0, rux_uu =3D 0, rux= _su =3D 0, rux_tu =3D 0}, p_profthreads =3D 0, p_exitthreads =3D 0, p_trace= flag =3D 0, p_tracevp =3D 0x0,=20 p_tracecred =3D 0x0, p_textvp =3D 0x0, p_lock =3D 0, p_sigiolst =3D {slh_= first =3D 0x0}, p_sigparent =3D 20, p_sig =3D 0, p_code =3D 0, p_stops =3D = 0, p_stype =3D 0, p_step =3D 0 '\0',=20 p_pfsflags =3D 0 '\0', p_nlminfo =3D 0x0, p_aioinfo =3D 0x0, p_singlethre= ad =3D 0x0, p_suspcount =3D 0, p_xthread =3D 0xfffffe001287c000, p_boundary= _count =3D 0, p_pendingcnt =3D 0,=20 p_itimers =3D 0x0, p_magic =3D 3203398350, p_osrel =3D 900034, p_comm =3D= "claws-mail\000\000\000\000\000\000\000\000\000", p_pgrp =3D 0xfffffe004a8= 76780,=20 p_sysent =3D 0xffffffff80c6b320, p_args =3D 0xfffffe0005c8b3c0, p_cpulimi= t =3D 9223372036854775807, p_nice =3D 0 '\0', p_fibnum =3D 0, p_xstat =3D 9= , p_klist =3D {kl_list =3D { slh_first =3D 0x0}, kl_lock =3D 0, kl_unlock =3D 0, kl_assert_locked = =3D 0xffffffff804fd960 ,=20 kl_assert_unlocked =3D 0xffffffff804fd940 ,= kl_lockarg =3D 0x0}, p_numthreads =3D 1, p_md =3D {md_ldt =3D 0x0, md_ldt_= sd =3D {sd_lolimit =3D 0,=20 sd_lobase =3D 0, sd_type =3D 0, sd_dpl =3D 0, sd_p =3D 0, sd_hilimit = =3D 0, sd_xx0 =3D 0, sd_gran =3D 0, sd_hibase =3D 0, sd_xx1 =3D 0, sd_mbz = =3D 0, sd_xx2 =3D 0}}, p_itcallout =3D { c_links =3D {sle =3D {sle_next =3D 0x0}, tqe =3D {tqe_next =3D 0x0, tqe= _prev =3D 0x0}}, c_time =3D 0, c_arg =3D 0x0, c_func =3D 0, c_lock =3D 0x0,= c_flags =3D 16, c_cpu =3D 0}, p_acflag =3D 16,=20 p_peers =3D 0x0, p_leader =3D 0xfffffe001290a000, p_emuldata =3D 0x0, p_l= abel =3D 0x0, p_sched =3D 0xfffffe001290a480, p_ktr =3D {stqh_first =3D 0x0= , stqh_last =3D 0xfffffe001290a430},=20 p_mqnotifier =3D {lh_first =3D 0x0}, p_dtrace =3D 0xfffffe0005c7a740, p_p= wait =3D {cv_description =3D 0xffffffff80954fbe "ppwait", cv_waiters =3D 0}= , p_dbgwait =3D { cv_description =3D 0xffffffff80954fc5 "dbgwait", cv_waiters =3D 0}, p_p= rev_runtime =3D 0, p_racct =3D 0x0} (kgdb) p *parent $3 =3D {p_list =3D {le_next =3D 0xfffffe004261b000, le_prev =3D 0xffffffff8= 0cba320}, p_threads =3D {tqh_first =3D 0xfffffe0005e0d8c0, tqh_last =3D 0xf= ffffe0005e0d8d0}, p_slock =3D { lock_object =3D {lo_name =3D 0xffffffff80954527 "process slock", lo_fla= gs =3D 720896, lo_data =3D 0, lo_witness =3D 0x0}, mtx_lock =3D 4}, p_ucred= =3D 0xfffffe00427b5a00,=20 p_fd =3D 0xfffffe00128b1c00, p_fdtol =3D 0x0, p_stats =3D 0xfffffe001290c= 800, p_limit =3D 0xfffffe00427b5300, p_limco =3D {c_links =3D {sle =3D {sle= _next =3D 0x0}, tqe =3D {tqe_next =3D 0x0,=20 tqe_prev =3D 0x0}}, c_time =3D 0, c_arg =3D 0x0, c_func =3D 0, c_lo= ck =3D 0xfffffe0012e489f8, c_flags =3D 0, c_cpu =3D 0}, p_sigacts =3D 0xfff= ffe0012e9c000, p_flag =3D 268451842,=20 p_state =3D PRS_NORMAL, p_pid =3D 3407, p_hash =3D {le_next =3D 0x0, le_p= rev =3D 0xffffff8000222a78}, p_pglist =3D {le_next =3D 0x0, le_prev =3D 0xf= ffffe0005e59310},=20 p_pptr =3D 0xfffffe004261b000, p_sibling =3D {le_next =3D 0x0, le_prev = =3D 0xfffffe004261b0f0}, p_children =3D {lh_first =3D 0x0}, p_mtx =3D {lock= _object =3D { lo_name =3D 0xffffffff8095451a "process lock", lo_flags =3D 21168128,= lo_data =3D 0, lo_witness =3D 0x0}, mtx_lock =3D 18446741874728777920}, p_= ksi =3D 0xfffffe0005c5eb60,=20 p_sigqueue =3D {sq_signals =3D {__bits =3D {0, 0, 0, 0}}, sq_kill =3D {__= bits =3D {0, 0, 0, 0}}, sq_list =3D {tqh_first =3D 0x0, tqh_last =3D 0xffff= fe0012e48a40},=20 sq_proc =3D 0xfffffe0012e48900, sq_flags =3D 1}, p_oppid =3D 0, p_vmspa= ce =3D 0xfffffe00128c5310, p_swtick =3D 12384, p_realtimer =3D {it_interval= =3D {tv_sec =3D 0, tv_usec =3D 0},=20 it_value =3D {tv_sec =3D 0, tv_usec =3D 0}}, p_ru =3D {ru_utime =3D {tv= _sec =3D 0, tv_usec =3D 0}, ru_stime =3D {tv_sec =3D 0, tv_usec =3D 0}, ru_= maxrss =3D 0, ru_ixrss =3D 0, ru_idrss =3D 0,=20 ru_isrss =3D 0, ru_minflt =3D 0, ru_majflt =3D 0, ru_nswap =3D 0, ru_in= block =3D 0, ru_oublock =3D 0, ru_msgsnd =3D 0, ru_msgrcv =3D 0, ru_nsignal= s =3D 0, ru_nvcsw =3D 0, ru_nivcsw =3D 0},=20 p_rux =3D {rux_runtime =3D 1633285860, rux_uticks =3D 63, rux_sticks =3D = 44, rux_iticks =3D 0, rux_uu =3D 482021, rux_su =3D 336649, rux_tu =3D 8186= 71}, p_crux =3D {rux_runtime =3D 770335510,=20 rux_uticks =3D 11, rux_sticks =3D 39, rux_iticks =3D 0, rux_uu =3D 8494= 7, rux_su =3D 301176, rux_tu =3D 386124}, p_profthreads =3D 0, p_exitthread= s =3D 0, p_traceflag =3D 0,=20 p_tracevp =3D 0x0, p_tracecred =3D 0x0, p_textvp =3D 0xfffffe00427ae780, = p_lock =3D 0, p_sigiolst =3D {slh_first =3D 0x0}, p_sigparent =3D 20, p_sig= =3D 0, p_code =3D 0, p_stops =3D 0,=20 p_stype =3D 0, p_step =3D 0 '\0', p_pfsflags =3D 0 '\0', p_nlminfo =3D 0x= 0, p_aioinfo =3D 0x0, p_singlethread =3D 0x0, p_suspcount =3D 0, p_xthread = =3D 0x0, p_boundary_count =3D 0,=20 p_pendingcnt =3D 0, p_itimers =3D 0x0, p_magic =3D 3203398350, p_osrel = =3D 900025, p_comm =3D "bash", '\0' , p_pgrp =3D 0xfffffe= 0005e59300,=20 p_sysent =3D 0xffffffff80c6b320, p_args =3D 0xfffffe0002ba2880, p_cpulimi= t =3D 9223372036854775807, p_nice =3D 0 '\0', p_fibnum =3D 0, p_xstat =3D 0= , p_klist =3D {kl_list =3D { slh_first =3D 0x0}, kl_lock =3D 0xffffffff804fd660 ,= kl_unlock =3D 0xffffffff804fd680 ,=20 kl_assert_locked =3D 0xffffffff804fd960 , kl_= assert_unlocked =3D 0xffffffff804fd940 , kl_loc= karg =3D 0xfffffe0012e489f8},=20 p_numthreads =3D 1, p_md =3D {md_ldt =3D 0x0, md_ldt_sd =3D {sd_lolimit = =3D 0, sd_lobase =3D 0, sd_type =3D 0, sd_dpl =3D 0, sd_p =3D 0, sd_hilimit= =3D 0, sd_xx0 =3D 0, sd_gran =3D 0,=20 sd_hibase =3D 0, sd_xx1 =3D 0, sd_mbz =3D 0, sd_xx2 =3D 0}}, p_itcall= out =3D {c_links =3D {sle =3D {sle_next =3D 0x0}, tqe =3D {tqe_next =3D 0x0= , tqe_prev =3D 0x0}}, c_time =3D 0,=20 c_arg =3D 0x0, c_func =3D 0, c_lock =3D 0x0, c_flags =3D 16, c_cpu =3D = 0}, p_acflag =3D 0, p_peers =3D 0x0, p_leader =3D 0xfffffe0012e48900, p_emu= ldata =3D 0x0, p_label =3D 0x0,=20 p_sched =3D 0xfffffe0012e48d80, p_ktr =3D {stqh_first =3D 0x0, stqh_last = =3D 0xfffffe0012e48d30}, p_mqnotifier =3D {lh_first =3D 0x0}, p_dtrace =3D = 0xfffffe0005d85b80, p_pwait =3D { cv_description =3D 0xffffffff80954fbe "ppwait", cv_waiters =3D 0}, p_db= gwait =3D {cv_description =3D 0xffffffff80954fc5 "dbgwait", cv_waiters =3D = 0}, p_prev_runtime =3D 0,=20 p_racct =3D 0x0} I'm not sure if switching to the console first matters. Before the panic, the states of gdb and claws-mail were: fk@r500 ~ $procstat -kk $(pgrep claws-mail) PID TID COMM TDNAME KSTACK = =20 15813 100528 claws-mail initial thread mi_switch+0x21d thread_suspe= nd_switch+0x103 ptracestop+0x7a cursig+0x4af ast+0x198 doreti_ast+0x1f=20 fk@r500 ~ $procstat -kk $(pgrep gdb) PID TID COMM TDNAME KSTACK = =20 15823 100928 gdb - mi_switch+0x21d sleepq_switc= h+0x123 sleepq_catch_signals+0x2a2 sleepq_wait_sig+0x16 _cv_wait_sig+0x14c = tty_wait+0x48 ttydisc_read+0xd4 ttydev_read+0xab devfs_read_f+0x88 dofilere= ad+0xa1 kern_readv+0x60 read+0x55 syscallenter+0x1cb syscall+0x4c Xfast_sys= call+0xdd=20 I believe I also reproduced the problem with a kernel from Tuesday, but dumping core from ddb failed so I can't check. I cannot reproduce the panic with a kernel from 2011-03-12 which I haven't deleted yet, but didn't try to bisect it further. gdb can't attach to claws-mail either, but the panic doesn't occur: fk@r500 ~ $gdb -p $(pgrep claws-mail) GNU gdb 6.1.1 [FreeBSD] Copyright 2004 Free Software Foundation, Inc. GDB is free software, covered by the GNU General Public License, and you are welcome to change it and/or distribute copies of it under certain condition= s. Type "show copying" to see the conditions. There is absolutely no warranty for GDB. Type "show warranty" for details. This GDB was configured as "amd64-marcel-freebsd". Attaching to process 3432 /usr/src/gnu/usr.bin/gdb/libgdb/../../../../contrib/gdb/gdb/solib-svr4.c:14= 44: i nternal-error: legacy_fetch_link_map_offsets called without legacy link_map= supp ort enabled. A problem internal to GDB has been detected, further debugging may prove unreliable. Quit this debugging session? (y or n) y /usr/src/gnu/usr.bin/gdb/libgdb/../../../../contrib/gdb/gdb/solib-svr4.c:14= 44: i nternal-error: legacy_fetch_link_map_offsets called without legacy link_map= supp ort enabled. A problem internal to GDB has been detected, further debugging may prove unreliable. Create a core file of GDB? (y or n) n In related news, the kernel from yesterday also seems to panic/hang/whatever when claws-mail segfaults due to an invalid memory access, but as I was run= ning X, I got no core dumps for those problems either. Fabian --Sig_/4Y4l7W31jqEr+83ZrQmmKDx Content-Type: application/pgp-signature; name=signature.asc Content-Disposition: attachment; filename=signature.asc -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.17 (FreeBSD) iEYEARECAAYFAk2hssMACgkQBYqIVf93VJ0bJQCeJwg50nhOvOXneJOKmkSHwlR5 b/QAnAhWDnDvo45HlOe+wpGcKGixfp9m =Epdi -----END PGP SIGNATURE----- --Sig_/4Y4l7W31jqEr+83ZrQmmKDx--