ZFS testing problems

From: Alexey Tarasov <master_at_preved.cn>
Date: Wed, 23 May 2007 22:54:48 +0400
Hello.

I have installed recent FreeBSD 7-CURRENT on test P4 machine. I have  
created the following zpool:

krivetko# zpool status tank
   pool: tank
state: ONLINE
scrub: none requested
config:

         NAME        STATE     READ WRITE CKSUM
         tank        ONLINE       0     0     0
           raidz1    ONLINE       0     0     0
             da0     ONLINE       0     0     0
             da1     ONLINE       0     0     0
             da2     ONLINE       0     0     0
             da3     ONLINE       0     0     0
             da4     ONLINE       0     0     0
             da5     ONLINE       0     0     0
             da6     ONLINE       0     0     0
         spares
           da7       AVAIL

errors: No known data errors

All hard disks are 300 GB SATA disks attached to 3Ware 9550SX-8LP  
raid controller.

During performance tests with IOzone there were a lot of lock order  
reversal messages in dmesg:

lock order reversal:
1st 0xc5c55cd0 zfs:&db->db_mtx (zfs:&db->db_mtx) _at_ /usr/src/sys/ 
modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/dbuf.c:1681
2nd 0xc629cde4 zfs:&zp->z_lock (zfs:&zp->z_lock) _at_ /usr/src/sys/ 
modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/zfs_znode.c:75
KDB: stack backtrace:
db_trace_self_wrapper 
(c0a1b31c,e59988a0,c076eaae,c0a1d745,c629cde4,...) at  
db_trace_self_wrapper+0x26
kdb_backtrace(c0a1d745,c629cde4,c5690826,c5690826,c56908a0,...) at  
kdb_backtrace+0x29
witness_checkorder(c629cde4,9,c56908a0,4b,c5c55c94,...) at  
witness_checkorder+0x6de
_sx_xlock(c629cde4,c56908a0,4b,c568bf82,c0b80180,...) at _sx_xlock+0x7a
znode_pageout_func(c5c55c94,c629cdd4,c55bf410,e5998940,c5625f52,...)  
at znode_pageout_func+0x2d
dbuf_evict_user(c5c55cec,ffffffff,ffffffff,c52395d4,0,...) at  
dbuf_evict_user+0x38
dbuf_rele(c5c55c94,0,0,e5998ad4,c6607380,...) at dbuf_rele+0x172
zfs_rmnode(c629cdd4,c52a33c0,2ad,2a4,c52395d4,...) at zfs_rmnode+0x263
zfs_zinactive(c629cdd4,c5691ae7,b85,252,c5239048,...) at zfs_zinactive 
+0x184
zfs_inactive(c6673dd0,c660e500,e5998b74,c0999035,e5998b8c,...) at  
zfs_inactive+0x5a
zfs_freebsd_inactive 
(e5998b8c,c6673e58,c6673dd0,c6673e58,e5998ba4,...) at  
zfs_freebsd_inactive+0x21
VOP_INACTIVE_APV(c5694ba0,e5998b8c,c0a2382a,8e4,c0aedbc0,...) at  
VOP_INACTIVE_APV+0xa5
vinactive(c5694ba0,e5998bc0,c0a2382a,870,c07a8198,...) at vinactive+0x91
vput(c6673dd0,ffffffdf,2,c54efe58,c0aedac0,...) at vput+0x1e6
kern_unlink(c52a33c0,8145b00,0,e5998d2c,c0984218,...) at kern_unlink 
+0x1ba
unlink(c52a33c0,e5998cfc,4,c0a2fbe6,c0abf470,...) at unlink+0x22
syscall(e5998d38) at syscall+0x288
Xint0x80_syscall() at Xint0x80_syscall+0x20
--- syscall (10, FreeBSD ELF32, unlink), eip = 0x2818c3ff, esp =  
0xbfbfe44c, ebp = 0xbfbfe5f8 ---
lock order reversal:
1st 0xc59ac420 zfs:&dr->dt.di.dr_mtx (zfs:&dr->dt.di.dr_mtx) _at_ /usr/ 
src/sys/modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/ 
dbuf.c:1866
2nd 0xc5c54154 zfs:&db->db_mtx (zfs:&db->db_mtx) _at_ /usr/src/sys/ 
modules/zfs/../../contrib/opensolaris/uts/common/fs/zfs/dbuf.c:1837
KDB: stack backtrace:
db_trace_self_wrapper 
(c0a1b31c,e7cc85a0,c076eaae,c0a1d745,c5c54154,...) at  
db_trace_self_wrapper+0x26
kdb_backtrace(c0a1d745,c5c54154,c568c0a5,c568c0a5,c568bf82,...) at  
kdb_backtrace+0x29
witness_checkorder(c5c54154,9,c568bf82,72d,c5c54118,...) at  
witness_checkorder+0x6de
_sx_xlock(c5c54154,c568bf82,72d,c1474788,c5c53570,...) at _sx_xlock+0x7a
dbuf_sync_list(c59ac438,c5c56b00,74a,e7cc8a24,c5c53570,...) at  
dbuf_sync_list+0x70
dbuf_sync_list(c5c53640,c5c56b00,257,3,2,...) at dbuf_sync_list+0x107
dnode_sync(c5c53570,c5c56b00,7,3,2,...) at dnode_sync+0x1cd
dmu_objset_sync(c59df400,c5adcac8,c5c56b00,0,c59df098,...) at  
dmu_objset_sync+0x130
dsl_pool_sync(c59df000,38f,0,0,0,...) at dsl_pool_sync+0x98
spa_sync(c54f8000,38f,0,c59df140,c59df11c,...) at spa_sync+0x3f8
txg_sync_thread(c59df000,e7cc8d38,c0a153b6,324,c598ed80,...) at  
txg_sync_thread+0x15a
fork_exit(c5654db0,c59df000,e7cc8d38) at fork_exit+0xf1
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xe7cc8d70, ebp = 0 ---

If I run tw_cli during tests, machine goes into GDB prompt.

Here is dmesg:

Copyright (c) 1992-2007 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
         The Regents of the University of California. All rights  
reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 7.0-CURRENT #0: Wed May 23 12:15:59 EDT 2007
     root_at_:/usr/obj/usr/src/sys/KRIVETKO
WARNING: WITNESS option enabled, expect reduced performance.
ACPI APIC Table: <IntelR AWRDACPI>
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Intel(R) Pentium(R) 4 CPU 3.40GHz (3394.22-MHz 686-class CPU)
   Origin = "GenuineIntel"  Id = 0xf34  Stepping = 4
    
Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE 
,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
   Features2=0x441d<SSE3,RSVD2,MON,DS_CPL,CNXT-ID,xTPR>
   Logical CPUs per core: 2
real memory  = 2146304000 (2046 MB)
avail memory = 2090790912 (1993 MB)
FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
cpu0 (BSP): APIC ID:  0
cpu1 (AP): APIC ID:  1
ioapic0: Changing APIC ID to 2
ioapic0 <Version 2.0> irqs 0-23 on motherboard
ioapic1 <Version 2.0> irqs 24-47 on motherboard
kbd1 at kbdmux0
ath_hal: 0.9.20.3 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413,  
RF5413)
acpi0: <IntelR AWRDACPI> on motherboard
acpi0: [ITHREAD]
acpi0: Power Button (fixed)
acpi0: reservation of 0, a0000 (3) failed
acpi0: reservation of 100000, 7fde0000 (3) failed
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
cpu0: <ACPI CPU> on acpi0
cpu1: <ACPI CPU> on acpi0
acpi_button0: <Power Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
pcib1: <ACPI PCI-PCI bridge> at device 3.0 on pci0
pci1: <ACPI PCI bus> on pcib1
em0: <Intel(R) PRO/1000 Network Connection Version - 6.5.2> port  
0xb000-0xb01f mem 0xf6000000-0xf601ffff irq 18 at device 1.0 on pci1
em0: Ethernet address: 00:30:48:87:34:9a
em0: [FILTER]
pcib2: <ACPI PCI-PCI bridge> at device 28.0 on pci0
pci2: <ACPI PCI bus> on pcib2
3ware device driver for 9000 series storage controllers, version:  
3.70.03.007
twa0: <3ware 9000 series Storage Controller> port 0xc000-0xc03f mem  
0xf0000000-0xf1ffffff,0xf2020000-0xf2020fff irq 25 at device 2.0 on pci2
twa0: [GIANT-LOCKED]
twa0: [ITHREAD]
twa0: INFO: (0x15: 0x1300): Controller details:: Model 9550SX-8LP, 8  
ports, Firmware FE9X 3.04.00.005, BIOS BE9X 3.04.00.002
uhci0: <UHCI (generic) USB controller> port 0xe100-0xe11f irq 16 at  
device 29.0 on pci0
uhci0: [GIANT-LOCKED]
uhci0: [ITHREAD]
usb0: <UHCI (generic) USB controller> on uhci0
usb0: USB revision 1.0
uhub0: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb0
uhub0: 2 ports with 2 removable, self powered
uhci1: <UHCI (generic) USB controller> port 0xe000-0xe01f irq 19 at  
device 29.1 on pci0
uhci1: [GIANT-LOCKED]
uhci1: [ITHREAD]
usb1: <UHCI (generic) USB controller> on uhci1
usb1: USB revision 1.0
uhub1: <Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1> on usb1
uhub1: 2 ports with 2 removable, self powered
pci0: <base peripheral> at device 29.4 (no driver attached)
ehci0: <Intel 6300ESB USB 2.0 controller> mem 0xf6100000-0xf61003ff  
irq 23 at device 29.7 on pci0
ehci0: [GIANT-LOCKED]
ehci0: [ITHREAD]
usb2: EHCI version 1.0
usb2: companion controllers, 2 ports each: usb0 usb1
usb2: <Intel 6300ESB USB 2.0 controller> on ehci0
usb2: USB revision 2.0
uhub2: <Intel EHCI root hub, class 9/0, rev 2.00/1.00, addr 1> on usb2
uhub2: 4 ports with 4 removable, self powered
pcib3: <ACPI PCI-PCI bridge> at device 30.0 on pci0
pci3: <ACPI PCI bus> on pcib3
fxp0: <Intel 82551 Pro/100 Ethernet> port 0xd000-0xd03f mem  
0xf5081000-0xf5081fff,0xf5020000-0xf503ffff irq 20 at device 1.0 on pci3
miibus0: <MII bus> on fxp0
inphy0: <i82555 10/100 media interface> PHY 1 on miibus0
inphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
fxp0: Ethernet address: 00:0e:0c:cf:9b:11
fxp0: [ITHREAD]
fxp1: <Intel 82551 Pro/100 Ethernet> port 0xd100-0xd13f mem  
0xf5082000-0xf5082fff,0xf5000000-0xf501ffff irq 21 at device 2.0 on pci3
miibus1: <MII bus> on fxp1
inphy1: <i82555 10/100 media interface> PHY 1 on miibus1
inphy1:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
fxp1: Ethernet address: 00:0e:0c:cf:97:3b
fxp1: [ITHREAD]
vgapci0: <VGA-compatible display> port 0xd200-0xd2ff mem  
0xf4000000-0xf4ffffff,0xf5080000-0xf5080fff irq 16 at device 9.0 on pci3
em1: <Intel(R) PRO/1000 Network Connection Version - 6.5.2> port  
0xd300-0xd33f mem 0xf5040000-0xf505ffff irq 19 at device 10.0 on pci3
em1: Ethernet address: 00:30:48:87:34:9b
em1: [FILTER]
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel 6300ESB UDMA100 controller> port  
0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xf000-0xf00f at device 31.1 on pci0
ata0: <ATA channel 0> on atapci0
ata0: [ITHREAD]
ata1: <ATA channel 1> on atapci0
ata1: [ITHREAD]
atapci1: <Intel 6300ESB SATA150 controller> port  
0xe200-0xe207,0xe300-0xe303,0xe400-0xe407,0xe500-0xe503,0xe600-0xe60f  
at device 31.2 on pci0
atapci1: [ITHREAD]
ata2: <ATA channel 0> on atapci1
ata2: [ITHREAD]
ata3: <ATA channel 1> on atapci1
ata3: [ITHREAD]
pci0: <serial bus, SMBus> at device 31.3 (no driver attached)
acpi_tz0: <Thermal Zone> on acpi0
fdc0: <floppy drive controller> port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on  
acpi0
fdc0: [FILTER]
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10  
on acpi0
sio0: type 16550A
sio0: [FILTER]
sio1: <16550A-compatible COM port> port 0x2f8-0x2ff irq 3 on acpi0
sio1: type 16550A
sio1: [FILTER]
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
atkbd0: [ITHREAD]
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: [ITHREAD]
psm0: model IntelliMouse Explorer, device ID 4
pmtimer0 on isa0
orm0: <ISA Option ROMs> at iomem 0xc0000-0xc7fff,0xc8000-0xc8fff, 
0xc9000-0xca7ff,0xcb000-0xcc7ff,0xcd000-0xce7ff,0xcf000-0xcffff pnpid  
ORM0000 on isa0
ppc0: <Parallel port> at port 0x378-0x37f irq 7 on isa0
ppc0: Generic chipset (NIBBLE-only) in COMPATIBLE mode
ppbus0: <Parallel port bus> on ppc0
plip0: <PLIP network interface> on ppbus0
lpt0: <Printer> on ppbus0
lpt0: Interrupt-driven port
ppi0: <Parallel I/O> on ppbus0
ppc0: [GIANT-LOCKED]
ppc0: [ITHREAD]
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on  
isa0
Timecounters tick every 1.000 msec
acd0: CDROM <SR244W/T01A> at ata0-slave UDMA33
ad4: 152627MB <WDC WD1600JS-56MHB1 10.02E01> at ata2-master SATA150
da0 at twa0 bus 0 target 0 lun 0
da0: <AMCC 9550SX-8LP DISK 3.04> Fixed Direct Access SCSI-3 device
da0: 100.000MB/s transfers
da0: 305165MB (624977920 512 byte sectors: 255H 63S/T 38903C)
da1 at twa0 bus 0 target 1 lun 0
da1: <AMCC 9550SX-8LP DISK 3.04> Fixed Direct Access SCSI-3 device
da1: 100.000MB/s transfers
da1: 305165MB (624977920 512 byte sectors: 255H 63S/T 38903C)
da2 at twa0 bus 0 target 2 lun 0
da2: <AMCC 9550SX-8LP DISK 3.04> Fixed Direct Access SCSI-3 device
da2: 100.000MB/s transfers
da2: 305165MB (624977920 512 byte sectors: 255H 63S/T 38903C)
da3 at twa0 bus 0 target 3 lun 0
da3: <AMCC 9550SX-8LP DISK 3.04> Fixed Direct Access SCSI-3 device
da3: 100.000MB/s transfers
da3: 305165MB (624977920 512 byte sectors: 255H 63S/T 38903C)
da4 at twa0 bus 0 target 4 lun 0
da4: <AMCC 9550SX-8LP DISK 3.04> Fixed Direct Access SCSI-3 device
da4: 100.000MB/s transfers
da4: 305165MB (624977920 512 byte sectors: 255H 63S/T 38903C)
da5 at twa0 bus 0 target 5 lun 0
da5: <AMCC 9550SX-8LP DISK 3.04> Fixed Direct Access SCSI-3 device
da5: 100.000MB/s transfers
da5: 305165MB (624977920 512 byte sectors: 255H 63S/T 38903C)
da6 at twa0 bus 0 target 6 lun 0
da6: <AMCC 9550SX-8LP DISK 3.04> Fixed Direct Access SCSI-3 device
da6: 100.000MB/s transfers
da6: 305165MB (624977920 512 byte sectors: 255H 63S/T 38903C)
da7 at twa0 bus 0 target 7 lun 0
da7: <AMCC 9550SX-8LP DISK 3.04> Fixed Direct Access SCSI-3 device
da7: 100.000MB/s transfers
da7: 305165MB (624977920 512 byte sectors: 255H 63S/T 38903C)
SMP: AP CPU #1 Launched!
Trying to mount root from ufs:/dev/ad4s1a
WARNING: / was not properly dismounted
WARNING: /tmp was not properly dismounted
WARNING: /usr was not properly dismounted
WARNING: /var was not properly dismounted
WARNING: ZFS is considered to be an experimental feature in FreeBSD.
ZFS filesystem version 6
ZFS storage pool version 6
rtfree: 0xc63d6d20 has 1 refs
em0: link state changed to UP



--
Alexey Tarasov
master_at_preved.cn
Received on Wed May 23 2007 - 16:55:03 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:10 UTC