Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 23 Feb 2001 04:06:58 -0600
From:      jehamby@anobject.com
To:        FreeBSD-gnats-submit@freebsd.org
Subject:   kern/25303: softupdate kernel panics
Message-ID:  <E14WF7q-0000oN-00@cs666838-239.austin.rr.com>

next in thread | raw e-mail | index | archive | help

>Number:         25303
>Category:       kern
>Synopsis:       reproducible panics w/ SOFTUPDATES and SCSI
>Confidential:   no
>Severity:       critical
>Priority:       medium
>Responsible:    freebsd-bugs
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Fri Feb 23 02:10:01 PST 2001
>Closed-Date:
>Last-Modified:
>Originator:     Jake Hamby
>Release:        FreeBSD 4.2-STABLE i386
>Organization:
anObject
>Environment:

Pentium III 600EB on ASUS P3V4X w/ 128MB, 13GB IDE and 18GB SCSI (2940U2W).
Relevant lines from dmesg:

FreeBSD 4.2-STABLE #7: Thu Feb 22 09:02:04 CST 2001
    root@firewall.jehamby.com:/usr/src/sys/compile/MYKERNEL
CPU: Pentium III/Pentium III Xeon/Celeron (602.19-MHz 686-class CPU)
  Origin = "GenuineIntel"  Id = 0x683  Stepping = 3
  Features=0x383f9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PA
T,PSE36,MMX,FXSR,SSE>
atapci0: <VIA 82C596 ATA66 controller> port 0xb800-0xb80f at device 4.1 on pci0
ata0: at 0x1f0 irq 14 on atapci0
ata1: at 0x170 irq 15 on atapci0
ahc0: <Adaptec 2940 Ultra2 SCSI adapter> port 0x9800-0x98ff mem 0xe0000000-0xe00
00fff irq 11 at device 12.0 on pci0
aic7890/91: Wide Channel A, SCSI Id=7, 32/255 SCBs
ad0: 13067MB <SAMSUNG SV1364D> [26550/16/63] at ata0-master UDMA66
acd0: CDROM <TOSHIBA CD-ROM XM-6002B> at ata1-master using PIO3
Waiting 5 seconds for SCSI devices to settle
Mounting root from ufs:/dev/ad0s1a
da0 at ahc0 bus 0 target 0 lun 0
da0: <QUANTUM QM318000TD-SCA N1K0> Fixed Direct Access SCSI-2 device
da0: 40.000MB/s transfers (20.000MHz, offset 31, 16bit), Tagged Queueing Enabled
da0: 17366MB (35566499 512 byte sectors: 255H 63S/T 2213C)

>Description:

I recently added a SCSI controller and drive to my IDE system, and after
discovering and remapping some bad sectors on the old SCSI drive, I wanted
to stress-test it, so I started by running a "tar cf - /usr | tar xf -"
to the new drive, running several Bonnie benchmarks w/ a 1-2GB file
size, rm -r'ing the files I'd copied, and running 'df'.  I discovered
that after 5-10 minutes of this, I could reproducibly panic the
kernel (I'd enabled softupdates w/ tunefs on both /usr (on IDE) and the /scsi
partition):


IdlePTD 3284992
initial pcb at 297bc0
panicstr: ffs_blkfree: freeing free block
---
#0  dumpsys () at ../../kern/kern_shutdown.c:469
469             if (dumping++) {
(kgdb) where
#0  dumpsys () at ../../kern/kern_shutdown.c:469
#1  0xc01587a3 in boot (howto=256) at ../../kern/kern_shutdown.c:309
#2  0xc0158b39 in panic (fmt=0xc0259900 "ffs_blkfree: freeing free block")
    at ../../kern/kern_shutdown.c:556
#3  0xc01cc082 in ffs_blkfree (ip=0xc7e11e0c, bno=4344, size=8192)
    at ../../ufs/ffs/ffs_alloc.c:1349
#4  0xc01d0617 in indir_trunc (ip=0xc7e11e0c, dbn=1572880, level=0, lbn=49164,
    countp=0xc7e11dfc) at ../../ufs/ffs/ffs_softdep.c:2151
#5  0xc01d0600 in indir_trunc (ip=0xc7e11e0c, dbn=65552, level=1, lbn=2060,
    countp=0xc7e11dfc) at ../../ufs/ffs/ffs_softdep.c:2147
#6  0xc01d03e9 in handle_workitem_freeblocks (freeblks=0xc0e71400)
    at ../../ufs/ffs/ffs_softdep.c:2055
#7  0xc01ce963 in process_worklist_item (matchmnt=0x0, flags=0)
    at ../../ufs/ffs/ffs_softdep.c:661
#8  0xc01ce802 in softdep_process_worklist (matchmnt=0x0)
    at ../../ufs/ffs/ffs_softdep.c:562
#9  0xc018417
Cannot access memory at address 0x8000.


I wanted to make sure I could reproduce the problem with a GENERIC
4.2-STABLE kernel, and sure enough:

IdlePTD 4571136
initial pcb at 3ac500
panicstr: ffs_blkfree: bad size
#0  dumpsys () at ../../kern/kern_shutdown.c:469
469             if (dumping++) {
(kgdb) where
#0  dumpsys () at ../../kern/kern_shutdown.c:469
#1  0xc01aac6b in boot (howto=256) at ../../kern/kern_shutdown.c:309
#2  0xc01aafe8 in poweroff_wait (junk=0xc035d755, howto=-1070213344)
    at ../../kern/kern_shutdown.c:556
#3  0xc029d9d3 in ffs_blkfree (ip=0xc8152e0c, bno=1038292562, size=7168)
    at ../../ufs/ffs/ffs_alloc.c:1320
#4  0xc02a1f0a in handle_workitem_freeblocks (freeblks=0xc17bd100)
    at ../../ufs/ffs/ffs_softdep.c:2068
#5  0xc02a03fb in process_worklist_item (matchmnt=0x0, flags=0)
    at ../../ufs/ffs/ffs_softdep.c:661
#6  0xc02a029a in softdep_process_worklist (matchmnt=0x0)
    at ../../ufs/ffs/ffs_softdep.c:562
#7  0xc01d645f in sched_sync () at ../../kern/vfs_subr.c:1035
#8  0xc02fef6c in fork_trampoline ()
Cannot access memory at address 0x8000.

I also captured one other panic w/ softupdates disabled on /scsi (but
enabled on /usr) but I didn't newfs the test drive after the first panic
(I did before the GENERIC kernel crash).  Anyway, here's that trace:

IdlePTD 3284992
initial pcb at 297bc0
panicstr: from debugger
panic messages:
---
panic: ffs_valloc: dup alloc
---
#0  dumpsys () at ../../kern/kern_shutdown.c:469
469             if (dumping++) {
(kgdb) where
#0  dumpsys () at ../../kern/kern_shutdown.c:469
#1  0xc01587a3 in boot (howto=260) at ../../kern/kern_shutdown.c:309
#2  0xc0158b39 in panic (fmt=0xc02443f4 "from debugger")
    at ../../kern/kern_shutdown.c:556
#3  0xc0131c31 in db_panic (addr=-1071507552, have_addr=0, count=-1,
    modif=0xc881aaf0 "") at ../../ddb/db_command.c:433
#4  0xc0131bd1 in db_command (last_cmdp=0xc027693c, cmd_table=0xc027679c,
    aux_cmd_tablep=0xc02930c4) at ../../ddb/db_command.c:333
#5  0xc0131c96 in db_command_loop () at ../../ddb/db_command.c:455
#6  0xc0133da3 in db_trap (type=3, code=0) at ../../ddb/db_trap.c:71
#7  0xc0221542 in kdb_trap (type=3, code=0, regs=0xc881abf8)
    at ../../i386/i386/db_interface.c:158
#8  0xc022d524 in trap (frame={tf_fs = -931069936, tf_es = -1071841264,
      tf_ds = -931069936, tf_edi = 3, tf_esi = 256, tf_ebp = -931025856,
      tf_isp = -931025884, tf_ebx = -1071278591, tf_edx = 0, tf_ecx = 0
      tf_eax = 18, tf_trapno = 3, tf_err = 0, tf_eip = -1071507552, tf_cs = 8,
      tf_eflags = 582, tf_esp = -1071206337, tf_ss = -1071338653})
    at ../../i386/i386/trap.c:569
#9  0xc02217a0 in Debugger (msg=0xc024ab63 "panic") at machine/cpufunc.h:64
#10 0xc0158b30 in panic (fmt=0xc0259601 "ffs_valloc: dup alloc")
    at ../../kern/kern_shutdown.c:554
#11 0xc01cac90 in ffs_valloc (pvp=0xc87c9880, mode=33261, cred=0xc0dce780,
    vpp=0xc881aca4) at ../../ufs/ffs/ffs_alloc.c:609
#12 0xc01dd1a7 in ufs_makeinode (mode=33261, dvp=0xc87c9880, vpp=0xc881aee0,
    cnp=0xc881aef4) at ../../ufs/ufs/ufs_vnops.c:2082
#13 0xc01dab5c in ufs_create (ap=0xc881ae00) at ../../ufs/ufs/ufs_vnops.c:184
#14 0xc01dd361 in ufs_vnoperate (ap=0xc881ae00)
    at ../../ufs/ufs/ufs_vnops.c:2287
#15 0xc018ace0 in vn_open (ndp=0xc881aecc, fmode=2563, cmode=493)
    at vnode_if.h:106
#16 0xc0186f0c in open (p=0xc7e01080, uap=0xc881af80)
    at ../../kern/vfs_syscalls.c:995
#17 0xc022de51 in syscall2 (frame={tf_fs = 47, tf_es = 47, tf_ds = 47,
      tf_edi = 134553607, tf_esi = -1077954604, tf_ebp = -1077958780,
      tf_isp = -931024940, tf_ebx = -1077958644, tf_edx = -1, tf_ecx = 2,
      tf_eax = 5, tf_trapno = 12, tf_err = 2, tf_eip = 134522512, tf_cs = 31,
      tf_eflags = 659, tf_esp = -1077958824, tf_ss = 47})
    at ../../i386/i386/trap.c:1150
#18 0xc0221e85 in Xint0x80_syscall ()
#19 0x804839d in ?? ()
#20 0x8048135 in ?? ()


>How-To-Repeat:

Sadly, I don't have an exact script to reproduce the crash.. it seems to be
extremely timing-dependent.  However, I have saved both kernel.debug files
and the three vmcore files, which I can upload if you need them.

>Fix:

Disable SOFTUPDATES as a workaround.
>Release-Note:
>Audit-Trail:
>Unformatted:

To Unsubscribe: send mail to majordomo@FreeBSD.org
with "unsubscribe freebsd-bugs" in the body of the message




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?E14WF7q-0000oN-00>