Date: Mon, 28 Jun 2004 22:36:36 -0400 (EDT) From: Bryan Liesner <bryan@kishka.net> To: Lukas Ertl <le@freebsd.org> Cc: freebsd-current@freebsd.org Subject: Re: Panic: EHCI and umass Message-ID: <20040628223536.D530@gravy.kishka.net> In-Reply-To: <20040628190253.U658@korben.in.tern> References: <20040626115242.X570@gravy.kishka.net> <20040628190253.U658@korben.in.tern>
next in thread | previous in thread | raw e-mail | index | archive | help
This message is in MIME format. The first part should be readable text,
while the remaining parts are likely unreadable without MIME-aware tools.
--0-64659921-1088476596=:530
Content-Type: TEXT/PLAIN; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: QUOTED-PRINTABLE
On Mon, 28 Jun 2004, Lukas Ertl wrote:
> On Sat, 26 Jun 2004, Bryan Liesner wrote:
>
>> Large transfers like dumping a filesystem or a tar of a filesystem cause=
s=20
>> the transfer to grind to a halt and eventually panic. No dump is=20
>> available, here is the transcribed DDB output:
>>=20
>> Fatal trap 12: page fault while in kernel mode
>> fault virtual address =3D 0x53425355
>> fault code =3D supervisor read, page not present
>> instruction pointer =3D 0x8:0xc05147d2
>> stack pointer =3D 0x10:0xd4294b6c
>> frame pointer =3D 0x10:0xd4294b8c
>> code segment =3D base 0x0 limit 0xffff, type 0x1b
>> =3D DPL0, pres 1, def32 1, gran1
>> processor eflags =3D interrupt enabled, resume, IOPL=3D0
>> current process =3D 20 (irq10: pcm0 ehci0)
>> kernel: type 12 trap,code=3D0
>>=20
>> Stopped at usb_allocmem+0x82: cmpl %esi, 0(%eax)
>
> Could you try to get a vmcore and a backtrace from it?
>
Here it is:
panic messages:
---
Fatal trap 12: page fault while in kernel mode
fault virtual address=09=3D 0x53425355
fault code=09=09=3D supervisor read, page not present
instruction pointer=09=3D 0x8:0xc051c117
stack pointer=09 =3D 0x10:0xd4294ab0
frame pointer=09 =3D 0x10:0xd4294ad0
code segment=09=09=3D base 0x0, limit 0xfffff, type 0x1b
=09=09=09=3D DPL 0, pres 1, def32 1, gran 1
processor eflags=09=3D interrupt enabled, resume, IOPL =3D 0
current process=09=09=3D 20 (irq10: pcm0 ehci0)
kernel: type 12 trap, code=3D0
Dumping 511 MB
16 32 48 64 80 96 112 128 144 160 176 192 208 224 240 256 272 288 304 320=
336 352 368 384 400 416 432 448 464 480 496
---
#0 doadump () at ../../../kern/kern_shutdown.c:236
236=09=09dumping++;
doadump () at ../../../kern/kern_shutdown.c:236
236=09=09dumping++;
(kgdb) bt
#0 doadump () at ../../../kern/kern_shutdown.c:236
#1 0xc0467ecd in db_fncall (dummy1=3D0, dummy2=3D0, dummy3=3D0, dummy4=3D0=
xd42948cc "@=DFu=C0\f") at ../../../ddb/db_command.c:551
#2 0xc0467c6a in db_command (last_cmdp=3D0xc075d650, cmd_table=3D0x0, aux_=
cmd_tablep=3D0xc070fd78, aux_cmd_tablep_end=3D0xc070fd7c)
at ../../../ddb/db_command.c:348
#3 0xc0467d78 in db_command_loop () at ../../../ddb/db_command.c:475
#4 0xc046ac79 in db_trap (type=3D12, code=3D0) at ../../../ddb/db_trap.c:7=
3
#5 0xc069b3ee in kdb_trap (type=3D12, code=3D0, regs=3D0xd4294a70) at ../.=
=2E/../i386/i386/db_interface.c:159
#6 0xc06ac118 in trap_fatal (frame=3D0xd4294a70, eva=3D0) at ../../../i386=
/i386/trap.c:810
#7 0xc06abe39 in trap_pfault (frame=3D0xd4294a70, usermode=3D0, eva=3D1396=
855637) at ../../../i386/i386/trap.c:733
#8 0xc06ab9d8 in trap (frame=3D
{tf_fs =3D 24, tf_es =3D 16, tf_ds =3D 16, tf_edi =3D 0, tf_esi =3D =
13, tf_ebp =3D -735491376, tf_isp =3D -735491428, tf_ebx =3D 1, tf_edx =3D =
-1066176724, tf_ecx =3D -1046045248, tf_eax =3D 1396855637, tf_trapno =3D 1=
2, tf_err =3D 0, tf_eip =3D -1068383977, tf_cs =3D 8, tf_eflags =3D 66182, =
tf_esp =3D 52, tf_ss =3D -1067889552}) at ../../../i386/i386/trap.c:420
#9 0xc069ccea in calltrap () at ../../../i386/i386/exception.s:140
#10 0x00000018 in ?? ()
#11 0x00000010 in ?? ()
#12 0x00000010 in ?? ()
#13 0x00000000 in ?? ()
#14 0x0000000d in ?? ()
#15 0xd4294ad0 in ?? ()
#16 0xd4294a9c in ?? ()
#17 0x00000001 in ?? ()
#18 0xc0736f2c in sysctl___hw_usb_ehci_debug ()
#19 0xc05012fa in ehci_allocm (bus=3D0x0, dma=3D0x0, size=3D0) at ../../../=
dev/usb/ehci.c:1022
#20 0xc05012fa in ehci_allocm (bus=3D0x0, dma=3D0x0, size=3D0) at ../../../=
dev/usb/ehci.c:1022
#21 0xc051ec50 in usbd_transfer (xfer=3D0xd) at ../../../dev/usb/usbdi.c:30=
9
#22 0xc0515fb7 in umass_setup_transfer (sc=3D0xc1bc5600, pipe=3D0x0, buffer=
=3D0x0, buflen=3D0, flags=3D0, xfer=3D0xc1bc6c00)
at ../../../dev/usb/umass.c:1167
#23 0xc0516722 in umass_bbb_state (xfer=3D0xc1bc6900, priv=3D0xc1bc5600, er=
r=3DUSBD_NORMAL_COMPLETION)
at ../../../dev/usb/umass.c:1533
#24 0xc051f60a in usb_transfer_complete (xfer=3D0xc1bc6900) at ../../../dev=
/usb/usbdi.c:834
#25 0xc0501105 in ehci_idone (ex=3D0xc1bc6900) at ../../../dev/usb/ehci.c:8=
18
#26 0xc0500ed2 in ehci_check_intr (sc=3D0xc1a53400, ex=3D0xc1bc6900) at ../=
=2E./../dev/usb/ehci.c:718
#27 0xc0500dda in ehci_softintr (v=3D0xc1a53400) at ../../../dev/usb/ehci.c=
:659
#28 0xc051b929 in usb_schedsoftintr (bus=3D0xc1a53400) at ../../../dev/usb/=
usb.c:842
#29 0xc0500b0b in ehci_intr1 (sc=3D0xc1a53400) at ../../../dev/usb/ehci.c:5=
59
#30 0xc050098f in ehci_intr (v=3D0xc1a53400) at ../../../dev/usb/ehci.c:517
#31 0xc055f0f9 in ithread_loop (arg=3D0xc196a880) at ../../../kern/kern_int=
r.c:557
#32 0xc055df08 in fork_exit (callout=3D0xc055ef60 <ithread_loop>, arg=3D0x0=
, frame=3D0x0) at ../../../kern/kern_fork.c:815
#33 0xc069cd4c in fork_trampoline () at ../../../i386/i386/exception.s:209
(kgdb) list *0xc05012fa
0xc05012fa is in ehci_allocm (../../../dev/usb/ehci.c:1022).
1017=09usbd_status
1018=09ehci_allocm(struct usbd_bus *bus, usb_dma_t *dma, u_int32_t size)
1019=09{
1020=09=09usbd_status err;
1021=20
1022=09=09err =3D usb_allocmem(bus, size, 0, dma);
1023=09#ifdef EHCI_DEBUG
1024=09=09if (err)
1025=09=09=09printf("ehci_allocm: usb_allocmem()=3D%d\n", err);
1026=09#endif
(kgdb) list *0xc051ec50
0xc051ec50 is in usbd_transfer (../../../dev/usb/usbdi.c:310).
305=09#ifdef DIAGNOSTIC
306=09=09=09if (xfer->rqflags & URQ_AUTO_DMABUF)
307=09=09=09=09printf("usbd_transfer: has old buffer!\n");
308=09#endif
309=09=09=09err =3D bus->methods->allocm(bus, dmap, size);
310=09=09=09if (err)
311=09=09=09=09return (err);
312=09=09=09xfer->rqflags |=3D URQ_AUTO_DMABUF;
313=09=09}
314=20
(kgdb) list *0xc0515fb7
0xc0515fb7 is in umass_setup_transfer (../../../dev/usb/umass.c:1167).
1162=09=09/* Initialise a USB transfer and then schedule it */
1163=20
1164=09=09(void) usbd_setup_xfer(xfer, pipe, (void *) sc, buffer, buflen, f=
lags,
1165=09=09=09=09sc->timeout, sc->state);
1166=20
1167=09=09err =3D usbd_transfer(xfer);
1168=09=09if (err && err !=3D USBD_IN_PROGRESS) {
1169=09=09=09DPRINTF(UDMASS_BBB, ("%s: failed to setup transfer, %s\n",
1170=09=09=09=09USBDEVNAME(sc->sc_dev), usbd_errstr(err)));
1171=09=09=09return(err);
(kgdb) list *0xc0516722
0xc0516722 is in umass_bbb_state (../../../dev/usb/umass.c:1533).
1528=09=09=09=09sc->transfer_state =3D TSTATE_BBB_STATUS2;
1529=09=09=09=09next_xfer =3D sc->transfer_xfer[XFER_BBB_CSW2];
1530=09=09=09}
1531=20
1532=09=09=09/* Read the Command Status Wrapper via bulk-in endpoint. */
1533=09=09=09if (umass_setup_transfer(sc, sc->bulkin_pipe,
1534=09=09=09=09=09&sc->csw, UMASS_BBB_CSW_SIZE, 0,
1535=09=09=09=09=09next_xfer)) {
1536=09=09=09=09umass_bbb_reset(sc, STATUS_WIRE_FAILED);
1537=09=09=09=09return;
(kgdb) list *0xc051f60a
0xc051f60a is in usb_transfer_complete (../../../dev/usb/usbdi.c:834).
829=09=09=09=09 xfer->actlen, xfer->length));
830=09=09=09xfer->status =3D USBD_SHORT_XFER;
831=09=09}
832=20
833=09=09if (xfer->callback)
834=09=09=09xfer->callback(xfer, xfer->priv, xfer->status);
835=20
836=09#ifdef DIAGNOSTIC
837=09=09if (pipe->methods->done !=3D NULL)
838=09=09=09pipe->methods->done(xfer);
(kgdb) list *0xc0501105
0xc0501105 is in ehci_idone (../../../dev/usb/ehci.c:819).
814=09=09} else {
815=09=09=09xfer->status =3D USBD_NORMAL_COMPLETION;
816=09=09}
817=20
818=09=09usb_transfer_complete(xfer);
819=09=09DPRINTFN(/*12*/2, ("ehci_idone: ex=3D%p done\n", ex));
820=09}
821=20
822=09/*
823=09 * Wait here until controller claims to have an interrupt.
(kgdb) list *=07~=08 =080xc0500ed2
0xc0500ed2 is in ehci_check_intr (../../../dev/usb/ehci.c:719).
714=09=09}
715=09 done:
716=09=09DPRINTFN(12, ("ehci_check_intr: ex=3D%p done\n", ex));
717=09=09usb_uncallout(ex->xfer.timeout_handle, ehci_timeout, ex);
718=09=09ehci_idone(ex);
719=09}
720=20
721=09void
722=09ehci_idone(struct ehci_xfer *ex)
723=09{
(kgdb) list *0xc0500dda
0xc0500dda is in ehci_softintr (../../../dev/usb/ehci.c:657).
652=09=09 * The only explanation I can think of for why EHCI is as brain de=
ad
653=09=09 * as UHCI interrupt-wise is that Intel was involved in both.
654=09=09 * An interrupt just tells us that something is done, we have no
655=09=09 * clue what, so we need to scan through all active transfers. :-(
656=09=09 */
657=09=09for (ex =3D LIST_FIRST(&sc->sc_intrhead); ex; ex =3D nextex) {
658=09=09=09nextex =3D LIST_NEXT(ex, inext);
659=09=09=09ehci_check_intr(sc, ex);
660=09=09}
661=20
(kgdb) lisy =08 =08=08 =08t *0xc051b929
0xc051b929 is in usb_schedsoftintr (../../../dev/usb/usb.c:844).
839=09#endif /* __HAVE_GENERIC_SOFT_INTERRUPTS */
840=09=09}
841=09#else
842=09 bus->methods->soft_intr(bus);
843=09#endif /* USB_USE_SOFTINTR */
844=09}
845=20
846=09#if defined(__NetBSD__) || defined(__OpenBSD__)
847=09int
848=09usb_activate(device_ptr_t self, enum devact act)
(kgdb) list *0xc050098f
0xc050098f is in ehci_intr (../../../dev/usb/ehci.c:517).
512=09=09=09printf("ehci_intr: ignored interrupt while polling\n");
513=09#endif
514=09=09=09return (0);
515=09=09}
516=20
517=09=09return (ehci_intr1(sc));
518=09}
519=20
520=09Static int
521=09ehci_intr1(ehci_softc_t *sc)
--0-64659921-1088476596=:530--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20040628223536.D530>