Date: Tue, 25 Nov 2003 22:34:43 +0100 From: Artur Poplawski <artur@szuruburu.neostrada.pl> To: freebsd-current@freebsd.org Subject: Re: pcm(4) related panic Message-ID: <20031125223443.45cdfae3.artur@szuruburu.neostrada.pl> In-Reply-To: <20031125161723.14260206.artur@szuruburu.neostrada.pl> References: <20031125161723.14260206.artur@szuruburu.neostrada.pl>
next in thread | previous in thread | raw e-mail | index | archive | help
Artur Poplawski <artur@szuruburu.neostrada.pl> wrote:
> Hello, =
=20
> =
=20
> On a 5.1-RELEASE and 5.2-BETA machines I have been able to cause a panic=
=20
> like this:
> =20
> (watch out for folded lines; the stack backtrace below is rewritten by
> hand from ddb)
>=20
> lock order reversal
> 1st 0xc22a45ac vm object (vm object) @ /usr/src/sys/vm/swap_pager.c:1323
> 2nd 0xc06c0420 swap_pager swhash (swap_pager swhash) @ \
> /usr/src/sys/vm/swap_pager.c:1838
> 3rd 0xc0c358c4 vm object (vm object) @ /usr/src/sys/vm/uma_core.c:876
> Stack backtrace:
> backtrace
> witness_lock
> _mtx_lock_flags
> obj_allock
> slab_zalloc
> uma_zone_slab
> uma_zalloc_internal
> uma_zalloc_arg
> swp_pager_meta_build
> swap_pager_putpages
> default_pager_putpages
> vm_pageout_flush
> vm_pageout_clean
> vm_pageout_scan
> vm_pageout
> fork_exit
> fork_trampoline
>=20
> Sleeping on "swread" with the following non-sleepable locks held:
> exclusive sleep mutex pcm0:play:0 (pcm channel) r =3D 0 (0xc1c3d740) lock=
ed @ \ =20
> /usr/src/sys/dev/sound/pcm/dsp.c:146
> panic: sleeping thread (pid 583) owns a non-sleepable lock
> syncing disks, buffers remaining... 1410 1410 panic: mi_switch: \=20
> switch in a critical section
> Uptime: 1m45s
> panic: msleep
> Uptime: 1m45s
> panic: msleep
> Uptime: 1m45s
> panic: msleep
> Uptime: 1m45s
> panic: msleep
> [... repeated few more times]
> Fatal double fault:
> eip =3D 0xc05e3916
> esp =3D 0xc8db8ff4
> ebp =3D 0xc8db9004
> panic: double fault
> Uptime: 1m45s
> panic: msleep
> Uptime: 1m45s=20
> panic: msleep
> Uptime: 1m45s
> panic: msleep
> Uptime: 1m45s
> [...]
> And the machine suddenly reboots, so there is no coredump.
> =20
> eip address points close to:
> c05e3910 T sc_vtb_putc
> =20
> To reproduce this panic just start some audio player app (like xmms),=20
> and launch countless memory-eating applications (like mozilla ;>).
> The machine starts swapping, and it panics.=20
>=20
> % uname -a=20
> FreeBSD kaszanka.domek 5.2-BETA FreeBSD 5.2-BETA #0: Sun Nov 23 01:23:10\=
=20
> CET 2003 artur@kaszanka.domek:/usr/obj/usr/src/sys/KASZANKA i386=20
>=20
> dmesg fragments:
> CPU: AMD Athlon(tm) XP 2000+ (1666.73-MHz 686-class CPU)
> pcm0: <AudioPCI ES1373-B> port 0xec00-0xec3f irq 10 at device 8.0 on pci0=
=20
> pcm0: <Cirrus Logic CS4297A AC97 Codec>
> rl0: <RealTek 8139 10/100BaseTX> port 0xe800-0xe8ff mem \
> 0xdfffff00-0xdfffffff ir
> q 10 at device 10.0 on pci0
> miibus0: <MII bus> on rl0
> rlphy0: <RealTek internal media interface> on miibus0
> rlphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
> rl1: <RealTek 8139 10/100BaseTX> port 0xe400-0xe4ff mem \
> 0xdffffe00-0xdffffeff ir
> q 10 at device 11.0 on pci0
> rlphy1: <RealTek internal media interface> on miibus1
> rlphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
In the meantime I've managed to get a coredump, by directly calling
doadump() from ddb. Results:
root@kaszanka:/usr/obj/usr/src/sys/KASZANKA# gdb -k kernel.debug /var/crash=
/vmcore.0
GNU gdb 5.2.1 (FreeBSD) =20
Copyright 2002 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 "i386-undermydesk-freebsd"...
panic: sleeping thread (pid 568) owns a non-sleepable lock
panic messages:
---
panic: sleeping thread (pid 568) owns a non-sleepable lock
syncing disks, buffers remaining... panic: msleep
Dumping 128 MB
16 32 48 64 80 96 112
---
Reading symbols from /usr/obj/usr/src/sys/KASZANKA/modules/usr/src/sys/modu=
les/linprocfs/linprocfs.ko.debug...done.
Loaded symbols for /usr/obj/usr/src/sys/KASZANKA/modules/usr/src/sys/module=
s/linprocfs/linprocfs.ko.debug
Reading symbols from /usr/obj/usr/src/sys/KASZANKA/modules/usr/src/sys/modu=
les/linux/linux.ko.debug...done.
Loaded symbols for /usr/obj/usr/src/sys/KASZANKA/modules/usr/src/sys/module=
s/linux/linux.ko.debug
Reading symbols from /boot/kernel/netgraph.ko...done.
Loaded symbols for /boot/kernel/netgraph.ko
Reading symbols from /boot/kernel/ng_ether.ko...done.
Loaded symbols for /boot/kernel/ng_ether.ko
Reading symbols from /boot/kernel/ng_pppoe.ko...done.
Loaded symbols for /boot/kernel/ng_pppoe.ko
Reading symbols from /boot/kernel/ng_socket.ko...done.
Loaded symbols for /boot/kernel/ng_socket.ko
Reading symbols from /boot/kernel/mga.ko...done.
Loaded symbols for /boot/kernel/mga.ko
#0 doadump () at /usr/src/sys/kern/kern_shutdown.c:240
240 dumping++;
(kgdb) where
#0 doadump () at /usr/src/sys/kern/kern_shutdown.c:240
#1 0xc04292cd in db_fncall (dummy1=3D0, dummy2=3D0, dummy3=3D0, dummy4=3D0=
xc8dba7bc "=E0=D7h=C0") at /usr/src/sys/ddb/db_command.c:548
#2 0xc042906a in db_command (last_cmdp=3D0xc068ce80, cmd_table=3D0x0, aux_=
cmd_tablep=3D0xc06480c0, aux_cmd_tablep_end=3D0xc06480c4)
at /usr/src/sys/ddb/db_command.c:346
#3 0xc0429178 in db_command_loop () at /usr/src/sys/ddb/db_command.c:472
#4 0xc042beb9 in db_trap (type=3D3, code=3D0) at /usr/src/sys/ddb/db_trap.=
c:73
#5 0xc05f00b3 in kdb_trap (type=3D3, code=3D0, regs=3D0xc8dba8fc) at /usr/=
src/sys/i386/i386/db_interface.c:171
#6 0xc05ff9ee in trap (frame=3D
{tf_fs =3D 24, tf_es =3D 16, tf_ds =3D 16, tf_edi =3D 0, tf_esi =3D -=
1067253613, tf_ebp =3D -925128376, tf_isp =3D -925128408, tf_ebx =3D 0, tf_=
edx =3D 0, tf_ecx =3D 0, tf_eax =3D 18, tf_trapno =3D 3, tf_err =3D 0, tf_e=
ip =3D -1067515059, tf_cs =3D 8, tf_eflags =3D 134, tf_esp =3D -1067175921,=
tf_ss =3D -1067255602}) at /usr/src/sys/i386/i386/trap.c:580
#7 0xc05f1988 in calltrap () at {standard input}:94
#8 0xc04e76fc in panic (fmt=3D0xc0630093 "msleep") at /usr/src/sys/kern/ke=
rn_shutdown.c:534
#9 0xc04ee999 in msleep (ident=3D0xc4461408, mtx=3D0xc06be3a0, priority=3D=
76, wmesg=3D0xc0635f46 "biord", timo=3D0)
at /usr/src/sys/kern/kern_synch.c:262
#10 0xc0532dd6 in bwait (bp=3D0xc4461408, pri=3D76 'L', wchan=3D0xc0635f46 =
"biord") at /usr/src/sys/kern/vfs_bio.c:3762
#11 0xc0531523 in bufwait (bp=3D0xc4461408) at /usr/src/sys/kern/vfs_bio.c:=
3044
#12 0xc052d066 in breadn (vp=3D0xc1cd3000, blkno=3D0, size=3D0, rablkno=3D0=
x0, rabsize=3D0x0, cnt=3D0, cred=3D0x0, bpp=3D0x0)
at /usr/src/sys/kern/vfs_bio.c:747
#13 0xc052cd7c in bread (vp=3D0x0, blkno=3D0, size=3D0, cred=3D0x0, bpp=3D0=
x0) at /usr/src/sys/kern/vfs_bio.c:682
#14 0xc0590087 in ffs_update (vp=3D0xc1daf104, waitfor=3D0) at /usr/src/sys=
/ufs/ffs/ffs_inode.c:108
#15 0xc05a529f in ffs_fsync (ap=3D0xc8dbab68) at /usr/src/sys/ufs/ffs/ffs_v=
nops.c:325
#16 0xc05a4334 in ffs_sync (mp=3D0xc1ccc400, waitfor=3D2, cred=3D0xc0f99e80=
, td=3D0xc06922c0) at vnode_if.h:627
#17 0xc054236b in sync (td=3D0xc06922c0, uap=3D0x0) at /usr/src/sys/kern/vf=
s_syscalls.c:141
#18 0xc04e6f60 in boot (howto=3D256) at /usr/src/sys/kern/kern_shutdown.c:2=
81
#19 0xc04e7767 in panic () at /usr/src/sys/kern/kern_shutdown.c:550
#20 0xc050b4f0 in propagate_priority (td=3D0xc1dc98c0) at /usr/src/sys/kern=
/subr_turnstile.c:176
#21 0xc050bf17 in turnstile_wait (ts=3D0xc0f9e1c0, lock=3D0xc1c3d740, owner=
=3D0xc1dc98c0) at /usr/src/sys/kern/subr_turnstile.c:509
#22 0xc04de21f in _mtx_lock_sleep (m=3D0xc1c3d740, opts=3D0, file=3D0xc0628=
d54 "/usr/src/sys/dev/sound/pcm/channel.c", line=3D440)
at /usr/src/sys/kern/kern_mutex.c:476
#23 0xc04dddd7 in _mtx_lock_flags (m=3D0xc1c3d740, opts=3D0, file=3D0xc0628=
d54 "/usr/src/sys/dev/sound/pcm/channel.c", line=3D440)
at /usr/src/sys/kern/kern_mutex.c:218
#24 0xc049258f in chn_intr (c=3D0xc1c3d740) at /usr/src/sys/dev/sound/pcm/c=
hannel.c:440
#25 0xc047d973 in es_intr (p=3D0xc1bee280) at /usr/src/sys/dev/sound/pci/es=
137x.c:469
#26 0xc04d42c2 in ithread_loop (arg=3D0xc0fa3880) at /usr/src/sys/kern/kern=
_intr.c:544
#27 0xc04d32d4 in fork_exit (callout=3D0xc04d4150 <ithread_loop>, arg=3D0x0=
, frame=3D0x0) at /usr/src/sys/kern/kern_fork.c:793
(kgdb) up 9
#9 0xc04ee999 in msleep (ident=3D0xc4461408, mtx=3D0xc06be3a0, priority=3D=
76, wmesg=3D0xc0635f46 "biord", timo=3D0)
at /usr/src/sys/kern/kern_synch.c:262
262 KASSERT(TD_IS_RUNNING(td), ("running but not TDS_RUNNING"));
(kgdb) l
257 /*
258 * We're awake from voluntary sleep.
259 */
260 CTR3(KTR_PROC, "msleep resume: thread %p (pid %d, %s)", td,=
p->p_pid,
261 p->p_comm);
262 KASSERT(TD_IS_RUNNING(td), ("running but not TDS_RUNNING"));
263 td->td_flags &=3D ~TDF_SINTR;
264 if (td->td_flags & TDF_TIMEOUT) {
265 td->td_flags &=3D ~TDF_TIMEOUT;
266 if (sig =3D=3D 0)
(kgdb) up 1
#10 0xc0532dd6 in bwait (bp=3D0xc4461408, pri=3D76 'L', wchan=3D0xc0635f46 =
"biord") at /usr/src/sys/kern/vfs_bio.c:3762
3762 msleep(bp, &bdonelock, pri, wchan, 0);
(kgdb) l
3757 void
3758 bwait(struct buf *bp, u_char pri, const char *wchan)
3759 {
3760 mtx_lock(&bdonelock);
3761 while ((bp->b_flags & B_DONE) =3D=3D 0)
3762 msleep(bp, &bdonelock, pri, wchan, 0);
3763 mtx_unlock(&bdonelock);
3764 }
3765 =20
3766 #include "opt_ddb.h"
(kgdb) up 8
#18 0xc04e6f60 in boot (howto=3D256) at /usr/src/sys/kern/kern_shutdown.c:2=
81
281 sync(&thread0, NULL);
(kgdb) up 2
#20 0xc050b4f0 in propagate_priority (td=3D0xc1dc98c0) at /usr/src/sys/kern=
/subr_turnstile.c:176
176 KASSERT(!TD_IS_SLEEPING(td),
(kgdb) l
171 * first thread to grab a slock of a sx lock. In t=
hat case
172 * it is possible for us to be at SSLEEP or some ot=
her
173 * weird state. We should probably just return if =
the state
174 * isn't SRUN or SLOCK.
175 */
176 KASSERT(!TD_IS_SLEEPING(td),
177 ("sleeping thread (pid %d) owns a non-sleepable=
lock",
178 td->td_proc->p_pid));
179 =20
180 /*
(kgdb) up 1
#21 0xc050bf17 in turnstile_wait (ts=3D0xc0f9e1c0, lock=3D0xc1c3d740, owner=
=3D0xc1dc98c0) at /usr/src/sys/kern/subr_turnstile.c:509
509 propagate_priority(td);
(kgdb) l
504 =20
505 /* Save who we are blocked on and switch. */
506 td->td_blocked =3D ts;
507 td->td_lockname =3D lock->lo_name;
508 TD_SET_LOCK(td);
509 propagate_priority(td);
510 =20
511 if (LOCK_LOG_TEST(lock, 0))
512 CTR4(KTR_LOCK, "%s: td %p blocked on [%p] %s", __fu=
nc__, td,
513 lock, lock->lo_name);
(kgdb) up 1 =20
#22 0xc04de21f in _mtx_lock_sleep (m=3D0xc1c3d740, opts=3D0, file=3D0xc0628=
d54 "/usr/src/sys/dev/sound/pcm/channel.c", line=3D440)
at /usr/src/sys/kern/kern_mutex.c:476
476 turnstile_wait(ts, &m->mtx_object, mtx_owner(m));
(kgdb) l
471 #endif
472 =20
473 /*
474 * Block on the turnstile.
475 */
476 turnstile_wait(ts, &m->mtx_object, mtx_owner(m));
477 }
478 =20
479 #ifdef KTR
480 if (cont_logged) {
(kgdb) up 1 =20
#23 0xc04dddd7 in _mtx_lock_flags (m=3D0xc1c3d740, opts=3D0, file=3D0xc0628=
d54 "/usr/src/sys/dev/sound/pcm/channel.c", line=3D440)
at /usr/src/sys/kern/kern_mutex.c:218
218 _get_sleep_lock(m, curthread, opts, file, line);
(kgdb) l
213 =20
214 MPASS(curthread !=3D NULL);
215 KASSERT(m->mtx_object.lo_class =3D=3D &lock_class_mtx_sleep,
216 ("mtx_lock() of spin mutex %s @ %s:%d", m->mtx_object.l=
o_name,
217 file, line));
218 _get_sleep_lock(m, curthread, opts, file, line);
219 LOCK_LOG_LOCK("LOCK", &m->mtx_object, opts, m->mtx_recurse,=
file,
220 line);
221 WITNESS_LOCK(&m->mtx_object, opts | LOP_EXCLUSIVE, file, li=
ne);
222 #ifdef MUTEX_PROFILING
(kgdb) up 1
#24 0xc049258f in chn_intr (c=3D0xc1c3d740) at /usr/src/sys/dev/sound/pcm/c=
hannel.c:440
440 CHN_LOCK(c);
(kgdb) l
435 }
436 =20
437 void
438 chn_intr(struct pcm_channel *c)
439 {
440 CHN_LOCK(c);
441 c->interrupts++;
442 if (c->direction =3D=3D PCMDIR_PLAY)
443 chn_wrintr(c);
444 else
(kgdb) up 1
#25 0xc047d973 in es_intr (p=3D0xc1bee280) at /usr/src/sys/dev/sound/pci/es=
137x.c:469
469 if (intsrc & STAT_DAC2) chn_intr(es->pch.channel);
(kgdb) l
464 bus_space_write_4(es->st, es->sh, ES1370_REG_SERIAL_CONTROL=
, sctrl);
465 bus_space_write_4(es->st, es->sh, ES1370_REG_SERIAL_CONTROL=
, es->sctrl);
466 =20
467 if (intsrc & STAT_ADC) chn_intr(es->rch.channel);
468 if (intsrc & STAT_DAC1);
469 if (intsrc & STAT_DAC2) chn_intr(es->pch.channel);
470 }
471 =20
472 /* ES1370 specific */
473 static int
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20031125223443.45cdfae3.artur>