Date: Mon, 20 Jan 2014 10:24:01 -0700 From: Warner Losh <imp@bsdimp.com> To: Ian Lepore <ian@FreeBSD.org> Cc: Warner Losh <imp@FreeBSD.org>, current@FreeBSD.org Subject: Re: panic: mtx_lock_spin: recursed on non-recursive mutex uart_hwmtx... Message-ID: <C72A35C5-3CB4-4289-92AF-EA07490E10F3@bsdimp.com> In-Reply-To: <1390238048.1230.75.camel@revolution.hippie.lan> References: <20140120153615.GS1789@albert.catwhisker.org> <1390238048.1230.75.camel@revolution.hippie.lan>
next in thread | previous in thread | raw e-mail | index | archive | help
On Jan 20, 2014, at 10:14 AM, Ian Lepore wrote:
> On Mon, 2014-01-20 at 07:36 -0800, David Wolfskill wrote:
>> I saw this on my "build machine" after updating the "head" slice =
from:
>>=20
>> FreeBSD 11.0-CURRENT #1387 r260875M/260877:1100005: Sun Jan 19 =
11:57:25 PST 2014 =
root@freebeast.catwhisker.org:/common/S4/obj/usr/src/sys/GENERIC i386
>>=20
>> to
>>=20
>> FreeBSD 11.0-CURRENT #1388 r260904M/260904:1100005: Mon Jan 20 =
06:25:53 PST 2014 =
root@freebeast.catwhisker.org:/common/S4/obj/usr/src/sys/GENERIC i386
>>=20
>>=20
>> A bit of context: On this machine and my laptop, it is my practice =
to perform the following on a daily basis:
>> * Ensure the machine is booted from slice 1 (stable/9).
>> * Update the ports tree.
>> * Update the source tree.
>> * Start fetching any ports that are to be updated.
>> * Update stable/9.
>> * Reboot (staying on slice 1 -- stable/9).
>> * Update the installed ports that warrant it ("portmaster -da =
--index").
>> * Update the sources on slice 3 (stable/10).
>> * Remove old libraries for stable/9 ("make delete-old-libs").
>> * Reboot to slice 3 (stable/10).
>> * Update stable/10.
>> * Reboot (staying on slice 3 -- stable/10).
>> * Update the sources on slice 4 (head).
>> * Remove old libraries for stable/10 ("make delete-old-libs").
>> * Reboot to slice 4 (head)
>> * Update head.
>> * Reboot (staying on slice 4 -- head).
>> * Remove old libraries for head ("make delete-old-libs").
>>=20
>> [If a given slice didn't have source updates, I don't try to rebuild
>> FreeBSD on it, though.]
>>=20
>> For my laptop, I then reboot to slice 1 (usually; sometimes slice
>> 3, especially if there were no source updates for stable/9). For
>> the build machine, I set the default boot slice back to 1, then issue
>> "shutdown -p now" to shut it off until just before midnight.
>>=20
>> Today, there were a couple of perturbations from the above:
>> * The only update for stable/10 I had was:
>> U /S3/usr/src/release/doc/en_US.ISO8859-1/errata/article.xml
>>=20
>> so I decided that didn't warrant rebuilding FreeBSD stable/10.
>>=20
>> * The panic in the Subject line -- only on the build machine.
>>=20
>> Here's what I see (cut/paste) on serial console:
>>=20
>> ...
>> Jan 20 07:02:12 freebeast shutdown: power-down by david:=20
>> Stopping cron.
>> Waiting for PIDS: 1090.
>> Stopping sshd.
>> Waiting for PIDS: 1080.
>> Stopping rsyncd.
>> Waiting for PIDS: 1057.
>> Stopping powerd.
>> Waiting for PIDS: 1042.
>> sysctl: dev.cpu.0.freq=3D3600: Device not configured
>> Stopping ntpd.
>> Waiting for PIDS: 1039.
>> Stopping lpd.
>> Waiting for PIDS: 1018.
>> Stopping lockd.
>> Waiting for PIDS: 1001.
>> Stopping statd.
>> Waiting for PIDS: 998.
>> Stopping nfsd.
>> Waiting for PIDS: 994 995.
>> Stopping mountd.
>> Waiting for PIDS: 992.
>> Stopping casperd.
>> Waiting for PIDS: 951.
>> Stopping amd.
>> Waiting for PIDS: 943.
>> Stopping ypbind.
>> Stopping rpcbind.
>> Waiting for PIDS: 916, 916.
>> Stopping devd.
>> Writing entropy file:.
>> Terminated
>> .
>> Jan 20 07:02:16 freebeast syslogd: exiting on signal 15
>> Waiting (max 60 seconds) for system process `vnlru' to stop...done
>> Waiting (max 60 seconds) for system process `syncer' to stop...
>> Syncing disks, vnodes remaining...2 4 4 4 3 3 3 2 1 1 0 0 0 0 done
>> Waiting (max 60 seconds) for system process `bufdaemon' to =
stop...done
>> All buffers synced.
>> lock order reversal:
>> 1st 0xc7336c68 ufs (ufs) @ /usr/src/sys/kern/vfs_mount.c:1237
>> 2nd 0xc76846dc devfs (devfs) @ /usr/src/sys/ufs/ffs/ffs_vfsops.c:1412
>> KDB: stack backtrace:
>> db_trace_self_wrapper(c112d57c,a3231,e1fb9888,c0b1bfe7,1,...) at =
db_trace_self_wrapper+0x2d/frame 0xe1fb9828
>> kdb_backtrace(c1131131,c76846dc,c1124024,c6dad2d0,c1162dc1,...) at =
kdb_backtrace+0x30/frame 0xe1fb9890
>> witness_checkorder(c76846dc,9,c1162dc1,584,0,...) at =
witness_checkorder+0xc8a/frame 0xe1fb98e0
>> __lockmgr_args(c76846dc,80400,c76846fc,0,0,0,c1162dc1,584) at =
__lockmgr_args+0x844/frame 0xe1fb99b4
>> vop_stdlock(e1fb9a28,c6dad3a0,c6dad408,c169bc38,e1fb9a4c,...) at =
vop_stdlock+0x4d/frame 0xe1fb99e4
>> VOP_LOCK1_APV(c13828dc,e1fb9a28,0,0,c13cded0,...) at =
VOP_LOCK1_APV+0x104/frame 0xe1fb9a10
>> _vn_lock(c76846a8,80400,c1162dc1,584,c1393aac,...) at =
_vn_lock+0xa1/frame 0xe1fb9a50
>> ffs_flushfiles(c753f000,a,c6f0a310,e1fb9b38,c0d416e3,...) at =
ffs_flushfiles+0x14c/frame 0xe1fb9a9c
>> softdep_flushfiles(c753f000,2,c6f0a310,0,0,...) at =
softdep_flushfiles+0x6e/frame 0xe1fb9af0
>> ffs_unmount(c753f000,80000,e1fb9b70,518,c6f0a310,...) at =
ffs_unmount+0x194/frame 0xe1fb9b38
>> dounmount(c753f000,80000,c6f0a310,0,e1db3eb0,...) at =
dounmount+0x4dc/frame 0xe1fb9b98
>> vfs_unmountall(e1db4058,0,c112895a,144,c6d8b1a0,...) at =
vfs_unmountall+0x4e/frame 0xe1fb9bb8
>> kern_reboot(4008,0,c112895a,c3,0,...) at kern_reboot+0x5af/frame =
0xe1fb9c20
>> sys_reboot(c6f0a310,e1fb9cc8,14,c112b5b7,7a2,...) at =
sys_reboot+0x6f/frame 0xe1fb9c40
>> syscall(e1fb9d08) at syscall+0x2de/frame 0xe1fb9cfc
>> Xint0x80_syscall() at Xint0x80_syscall+0x21/frame 0xe1fb9cfc
>> --- syscall (55, FreeBSD ELF32, sys_reboot), eip =3D 0x805a9df, esp =3D=
0xbfbfd88c, ebp =3D 0xbfbfd960 ---
>> Uptime: 4m28s
>> panic: mtx_lock_spin: recursed on non-recursive mutex uart_hwmtx @ =
/usr/src/sys/dev/uart/uart_cpu.h:94
>>=20
>> cpuid =3D 0
>> KDB: stack backtrace:
>> =
db_trace_self_wrapper(c112d57c,2f727375,2f637273,2f737973,2f766564,...) =
at db_trace_self_wrapper+0x2d/frame 0xe1fb9a60
>> kdb_backtrace(c12ec1f3,0,c11269a2,e1fb9b38,e1fb9b08,...) at =
kdb_backtrace+0x30/frame 0xe1fb9ac8
>> vpanic(c140d0c8,100,c11269a2,e1fb9b38,e1fb9b38,...) at =
vpanic+0x11f/frame 0xe1fb9b08
>> kassert_panic(c11269a2,c10f66d8,c10f6758,5e,8,...) at =
kassert_panic+0xea/frame 0xe1fb9b2c
>> __mtx_lock_spin_flags(c7291830,0,c10f6758,5e,c137d684,...) at =
__mtx_lock_spin_flags+0x190/frame 0xe1fb9b5c
>> ns8250_bus_grab(c7291800,c7062b28,c137d684,5e,c140b9a4,...) at =
ns8250_bus_grab+0x40/frame 0xe1fb9b78
>> uart_grab(c13fd070) at uart_grab+0x83/frame 0xe1fb9b9c
>> uart_cngrab(c137d69c,88888889,e1fb9c20,c0ac7d43,c1128e43,...) at =
uart_cngrab+0x12/frame 0xe1fb9ba8
>> cngrab(c1128e43,1c,c112895a,144,c6d8b1a0,...) at cngrab+0x33/frame =
0xe1fb9bb8
>> kern_reboot(4008,0,c112895a,c3,0,...) at kern_reboot+0x6d3/frame =
0xe1fb9c20
>> sys_reboot(c6f0a310,e1fb9cc8,14,c112b5b7,7a2,...) at =
sys_reboot+0x6f/frame 0xe1fb9c40
>> syscall(e1fb9d08) at syscall+0x2de/frame 0xe1fb9cfc
>> Xint0x80_syscall() at Xint0x80_syscall+0x21/frame 0xe1fb9cfc
>> --- syscall (55, FreeBSD ELF32, sys_reboot), eip =3D 0x805a9df, esp =3D=
0xbfbfd88c, ebp =3D 0xbfbfd960 ---
>> KDB: enter: panic
>> [ thread pid 1 tid 100002 ]
>> Stopped at kdb_enter+0x3d: movl $0,kdb_why
>> db> show locks
>> exclusive sleep mutex Giant (Giant) r =3D 0 (0xc1724910) locked @ =
/usr/src/sys/vm/swap_pager.c:2365
>> db>=20
>>=20
>>=20
>> When I issued "reset", the machine came back up normally (in slice
>> 1 -- stable/9). I then rebooted to slice 4 (head), and issued the
>> same commands I usually do to set the default boot slice back to 1, =
then
>> "shutdown -p now" -- and re-created the panic.
>>=20
>> I can leave the machine up for a while if anyone has suggestions for =
me
>> to poke around. I have a local private mirror of the FreeBSD SVN =
repos
>> and a spare bootable slice; I'm williing to try patches. The machine
>> isn't especially fast, but it's generally OK.
>>=20
>> If it would be worthwhile, I could reboot my laptop to slice 4 (head) =
&
>> attempt the same reset-to-slice-1-default & power-off.
>>=20
>> This definitely did not happen @r260875, and it appears to be quite
>> repeatable @r260904.
>>=20
>> Peace,
>> david
>=20
> Since you mention serial console, I think r260890 might be a =
candidate.
I'm pretty sure that it is. I'll take a look at it.
Warner=
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?C72A35C5-3CB4-4289-92AF-EA07490E10F3>