Re: RELENG_5: ata interrupt problems

On 2004.08.20 10:53:23 +0200, Simon L. Nielsen wrote:
> [CC'ing Mr. ATA]
>
> On 2004.08.19 16:32:25 -1000, Kent Hauser wrote:
>
> > I updated my IBM T41 from a May -CURRENT to -RELENG_5 & am now getting
> > "READ_DMA interrupt but timeout fired" (also WRITE_DMA). After a minute or so
> > it drops into the debugger. Kernel is unmodified GENERIC.
>
> I have seen something similar the last couple of days when I boot with
> my DVD/CDRW drive attached in my Thinkpad R40.  I can't get to the
> dmesg of the errors that occour before the panic, but I can get that
> tonight.

The actual errors from a 5.3-BETA from today (hand transcribed):

ad0: 73863MB <HTS548080M9AT00/MG40A50A> [150071/16/63] at ata0-master UDMA100
ATAPI_RESET time = 150us
ata1-slave: FAILURE - ATAPI_IDENTIFY timed out
ATAPI_RESET time = 150us
acd0: CDRW <UJDA740 DVD/CDRW/1.04> at ata1-master UDMA33
Mounting root from ufs:/dev/ad0s2a
[...]
ad0: WARNING - READ_DME interupt was seen but timeout fired LBA=41574224
[...]
ad0: WARNING - READ_DME interupt was seen but timeout fired LBA=41562160
ad0: WARNING - READ_DME interupt was seen but timeout fired LBA=41562160
ad0: WARNING - READ_DME interupt was seen but taskqueue stalled LBA=41562160
Slab at 0xc1c3ff70, freei 3 = 0

The "[...]" is just normal startup.  It goes as far as the script that
attaches my GDBE partition before it panics.

And then it panics like below:

> panic: Duplicate free of item 0xc1c3f18c from zone 0xc198e160(g_bio)
>
> panic messages:
> ---
> panic: Duplicate free of item 0xc1c3f18c from zone 0xc198e160(g_bio)
>
> cpuid = 0;
> KDB: enter: panic
> 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
> ---
> Reading symbols from /boot/kernel/mac_portacl.ko...done.
> Loaded symbols for /boot/kernel/mac_portacl.ko
> Reading symbols from /boot/kernel/acpi.ko...done.
> Loaded symbols for /boot/kernel/acpi.ko
> #0  doadump () at pcpu.h:159
> 159     pcpu.h: No such file or directory.
>         in pcpu.h
> (kgdb) bt
> #0  doadump () at pcpu.h:159
> #1  0xc0455929 in db_fncall (dummy1=0, dummy2=0, dummy3=1999, dummy4=0xd41dc9c4 "`\016}_at_")
>     at /usr/src/sys/ddb/db_command.c:531
> #2  0xc04556d8 in db_command (last_cmdp=0xc07d0564, cmd_table=0x0, aux_cmd_tablep=0xc0791d44, 
>     aux_cmd_tablep_end=0xc0791d48) at /usr/src/sys/ddb/db_command.c:349
> #3  0xc04557c9 in db_command_loop () at /usr/src/sys/ddb/db_command.c:455
> #4  0xc0457631 in db_trap (type=3, code=0) at /usr/src/sys/ddb/db_main.c:221
> #5  0xc056e846 in kdb_trap (type=0, code=0, tf=0x1) at /usr/src/sys/kern/subr_kdb.c:417
> #6  0xc071bb53 in trap (frame=
>       {tf_fs = 24, tf_es = 16, tf_ds = -736296944, tf_edi = 256, tf_esi = 1, tf_ebp = -736244900, tf_isp = -736244928, tf_ebx = -736244848, tf_edx = 1, tf_ecx = -1056882688, tf_eax = 18, tf_trapno = 3, tf_err = 0, tf_eip = -1068046953, tf_cs = 8, tf_eflags = 646, tf_esp = -1065960684, tf_ss = -1065968875})
>     at /usr/src/sys/i386/i386/trap.c:576
> #7  0xc0707ffa in calltrap () at /usr/src/sys/i386/i386/exception.s:140
> #8  0xc0554cb5 in panic (fmt=0xc0787482 "Duplicate free of item %p from zone %p(%s)\n")
>     at /usr/src/sys/kern/kern_shutdown.c:542
> #9  0xc06de677 in uma_dbg_free (zone=0xc198e160, slab=0xc1c3ff70, item=0xc1c3f18c)
>     at /usr/src/sys/vm/uma_dbg.c:276
> #10 0xc06dd0ac in uma_zfree_arg (zone=0xc196d640, item=0xc1c3f18c, udata=0x0)
>     at /usr/src/sys/vm/uma_core.c:2228
> #11 0xc0519147 in g_destroy_bio (bp=0x0) at uma.h:302
> #12 0xc0516fe0 in g_dev_done (bp2=0xc1c3f18c) at /usr/src/sys/geom/geom_dev.c:328
> #13 0xc05a4244 in biodone (bp=0xc1c3f18c) at /usr/src/sys/kern/vfs_bio.c:3002
> #14 0xc0472f16 in ad_done (request=0xc1c3b438) at /usr/src/sys/dev/ata/ata-disk.c:322
> #15 0xc0462ac0 in ata_completed (context=0xc1c3b438, dummy=0) at /usr/src/sys/dev/ata/ata-queue.c:404
> #16 0xc0462c0e in ata_timeout (request=0xc1c3b438) at /usr/src/sys/dev/ata/ata-queue.c:442
> #17 0xc0562417 in softclock (dummy=0x0) at /usr/src/sys/kern/kern_timeout.c:259
> #18 0xc053c5b4 in ithread_loop (arg=0xc19b2580) at /usr/src/sys/kern/kern_intr.c:546
> #19 0xc053b6d1 in fork_exit (callout=0xc053c455 <ithread_loop>, arg=0x0, frame=0x0)
>     at /usr/src/sys/kern/kern_fork.c:820

-- 
Simon L. Nielsen
FreeBSD Documentation Team