FreeBSD 8.2-RELEASE panic with zfs

peetaur

peetaur

My system with a ZFS root file system crashed.

There is no crash dump. I assume the dump failed because the root system is ZFS, and ZFS crashed, making the file system unavailable. The only other time I caused a panic was during boot with no disks writeable, and so I don't know if dump ever works (dumps and reboots).

What can I do about it so I can rely on FreeBSD? The only thing that came to mind is that I should run memtest. (Should I?)


Here is what I could read off the screen while it was hung.

Code: 
cpuid = 2
KDB: stack backtrace:
#0 0xffffffff805f4e0e at kdb_backtrace+0x5e
#1 0xffffffff805c2d07 at panic+0x187
#2 0xffffffff80816830 at kmem_alloc+0
#3 0xffffffff8080e3ba at uma_large_malloc+0x4a
#4 0xffffffff805b0167 at malloc+0xd7
#5 0xffffffff80db7f66 at arc_get_data_buf+0x486
#6 0xffffffff80dba1bc at arc_read_nolock+0x1dc
#7 0xffffffff80dba8ec at arc_read+0x7c
#8 0xffffffff80dbd9a3 at dbuf_read+0x503
#9 0xffffffff80dc952a at dmu_tx_check_ioerr+0x9a
#10 0xffffffff80dc9f55 at dmu_tx_hold_free+0x145
#11 0xffffffff80dc0b66 at dmu_free_long_range_impl+0x106
#12 0xffffffff80dc0ddf at dmu_free_long_range+0x4f
#13 0xffffffff80e1405e at zfs_rmnode+0x5e
#14 0xffffffff80e25af6 at zfs_inactive+0x66
#15 0xffffffff80e25c9a at zfs_freebsd_inactive+0x1a
#16 0xffffffff8064e1a1 at vinactive+0x71
#17 0xffffffff80653ef8 at vputx+0x2d8
Uptime: 6d8h41m39s
Cannot dump. Device not defined or unavailable.
Automatic reboot in 15 seconds - press a key on the console to abort


Code: 
uname -a
FreeBSD bcnas1.bc.local 8.2-RELEASE FreeBSD 8.2-RELEASE #0: Thu Feb 17 02:41:51 UTC 2011     
[email]root@mason.cse.buffalo.edu[/email]:/usr/obj/usr/src/sys/GENERIC  amd64

(next command done after reboot)
Code: 
kldstat 
Id Refs Address            Size     Name
 1   15 0xffffffff80100000 c9fe20   kernel
 2    1 0xffffffff80da0000 1ad0e0   zfs.ko
 3    2 0xffffffff80f4e000 3a68     opensolaris.ko
 4    1 0xffffffff80f52000 c800     if_ixgb.ko
 5    1 0xffffffff80f61000 19400    mps.ko
 
I had something similar with ZFS root on FreeBSD 8.2-RELEASE, would kernel panic about once a week usually under heavy load. Can't say if it's exactly the same issue as no crash dump etc.

There have been alot of changes to the ZFS code since 8.2-RELEASE I would strongly recommend moving the 8-STABLE and upgrading your pools to v28. Doing this fixed my issues now the server is as solid as a rock.
 
jake,

Previously, I tried FreeBSD-8.2-STABLE-201105 (which I got from ftp://ftp.freebsd.org/pub/FreeBSD/snapshots/201105/) because I wanted the mps driver. Then later I just added the mps.ko into the FreeBSD-8.2-RELEASE (as described here: http://blog.eracks.com/2011/08/lsi-logic-6gbps-mps-driver-for-freebsd-8-2-release/).

When I tested the FreeBSD-8.2-STABLE-201105 version, I think the zfs version was still only v15. How did you get v28? Did you compile it yourself, or download an ISO?

And thank you very much for your help.
 
Okay. I tested that out, and it seemed to work.

But how stable will my system be running on an 8-STABLE cvs pull done at any random time? Am I pulling from a branch that is only committed(/tagged/merged) after testing?

Or is there a unit test suite I can run?

And how do I get reproducable results, say if I want to install a second system, with the same exact source code as another system I already installed a few months ago.

How did you determine that what you checked out was good enough for your server?

Thanks again,
Peter
 
The code in STABLE has first been tested in CURRENT before merging, yes you're right this means no guarantees STABLE is still a development branch. More information on the differences can be found here http://www.freebsd.org/doc/handbook/current-stable.html

If you are happy with the revision you have and want to have the same code running on a different server, I guess you have a few options, copy the /usr/src to the other server and build it, read up on csvup and see if you can check out the exact same revision again more info here or dump the working server and restore it, but this is zfs so zfs send | zfs receive.

There were no known bugs that affected me when I checked out my copy of STABLE and haven't run into any others yet, if I do I will find out if it's been fixed in the latest STABLE and update. Really though I will be putting this box on 8.3-RELEASE when it comes out.
 
So I used "date=" in my cvsup, and upgraded (2 servers), and things went smoothly (other than a broken disk preventing the boot on the server with the cheap disks).

So far, the file system runs faster, scrub runs faster, etc.. But only time will tell if it crashes again.

Thanks again for your help.
 
I don't know if I should post this here or start a new thread, but running with 8-STABLE, I got another kernel panic, and before that, a disk issue that doesn't seem to be the hardware's fault.

It may simply be the mps driver's fault. The mps driver is not a very mature piece of software... so surely it isn't perfect, but what can I do to prevent such problems?


Here is the story...

First it looked like a disk failed...

zfs showed "FAULTED" for a disk.
Code: 
        NAME               STATE     READ WRITE CKSUM
        tank               DEGRADED     0     0     0
          raidz2-0         ONLINE       0     0     0
            ...
        logs
          mirror-2         DEGRADED     0     0     0
            gpt/log0       FAULTED      0 3.35K     0  too many errors
            gpt/log1       ONLINE       0     0     0
        cache
          gpt/cache0       ONLINE   7.74K 75.8K     0
          gpt/cache1       ONLINE       0     0     0

        NAME           STATE     READ WRITE CKSUM
        zroot          DEGRADED     0     0     0
          mirror-0     DEGRADED     0     0     0
            gpt/root0  FAULTED      5   340     0  too many errors
            gpt/root1  ONLINE       0     0     0

(strange that cache0 is online even though the whole disk is unreadable)



/var/log/messages showed lots of errors for the disk.
Code: 
    Sep 29 15:30:58 bcnas1 kernel: mps0: <LSI SAS2008> port 0xf800-0xf8ff mem 0xf8f3c000-0xf8f3ffff,0xf8f40000-0xf8f7ffff irq 54 at device 0.0 on pci133
    Sep 29 15:30:58 bcnas1 kernel: mps0: Firmware: 10.00.02.00
    Sep 29 15:30:58 bcnas1 kernel: mps0: IOCCapabilities: 185c<ScsiTaskFull,DiagTrace,SnapBuf,EEDP,TransRetry,IR>
    Sep 29 15:30:58 bcnas1 kernel: mps0: [ITHREAD]
Code: 
    Oct  1 18:06:12 bcnas1 kernel: (da3:mps0:0:0:0): SCSI command timeout on device handle 0x000a SMID 632
    Oct  1 23:15:01 bcnas1 kernel: : SCSI command timeout on device handle 0x000a SMID 1010
    Oct  1 23:15:01 bcnas1 kernel: (da3:mps0:0:0:0): SCSI command timeout on device handle 0x000a SMID 174
    ...
    Oct  1 23:15:01 bcnas1 kernel: mps0: (0:0:0) terminated ioc 804b scsi 0 state c xfer 0
    Oct  1 23:15:01 bcnas1 last message repeated 6 times
    Oct  1 23:15:01 bcnas1 kernel: mps0: mpssas_abort_complete: abort request on handle 0x0a SMID 931 complete
    Oct  1 23:15:01 bcnas1 kernel: mps0: mpssas_complete_tm_request: sending deferred task management request for handle 0x0a SMID 191

    (things like the above repeated 100s of times)

So, I tried replacing the disk:
removed it

put a new one in

# gpart show
-to my surprise, saw the new disk had the slices on it already... that doesn't make sense
Code: 
        root@bcnas1:~/zfsstatus# gpart show
        =>       34  500118125  da3  GPT  (238G)
                 34        128    1  freebsd-boot  (64k)
                162    1048576    2  freebsd-swap  (512M)
            1048738  167772160    3  freebsd-zfs  (80G)
          168820898    8388608    4  freebsd-zfs  (4.0G)
          177209506  322908653    5  freebsd-zfs  (154G)

        =>       34  500118125  da10  GPT  (238G)
                 34        128     1  freebsd-boot  (64k)
                162    1048576     2  freebsd-swap  (512M)
            1048738  167772160     3  freebsd-zfs  (80G)
          168820898    8388608     4  freebsd-zfs  (4.0G)
          177209506  322908653     5  freebsd-zfs  (154G)

removed disk

# gpart show
segmentation fault

# gpart recover da3
kernel panic

rebooted with just 1 of the mirror disks in... no problems

tested the alleged bad disk on a windows machine which can see it all

put alleged bad disk back in machine

worked fine, resilvered, no errors

messages during my fix attempt:
Code: 
    Oct  4 08:54:56 bcnas1 login: ROOT LOGIN (root) ON ttyv0
    Oct  4 08:56:18 bcnas1 login: ROOT LOGIN (root) ON ttyv1
    Oct  4 08:57:05 bcnas1 kernel: (da3:mps0:0:0:0): SCSI command timeout on device handle 0x000a SMID 568
    Oct  4 08:57:05 bcnas1 kernel: (da3:mps0:0:0:0): SCSI command timeout on device handle 0x000a SMID 998
    Oct  4 08:57:13 bcnas1 kernel: mps0: (0:0:0) terminated ioc 804b scsi 0 state c xfer 0
    Oct  4 08:57:13 bcnas1 kernel: mps0: mpssas_abort_complete: abort request on handle 0x0a SMID 568 complete
    Oct  4 08:57:13 bcnas1 kernel: mps0: mpssas_complete_tm_request: sending deferred task management request for handle 0x0a SMID 998
    Oct  4 08:57:13 bcnas1 kernel: mps0: mpssas_abort_complete: abort request on handle 0x0a SMID 998 complete
    Oct  4 08:58:13 bcnas1 kernel: (da3:mps0:0:0:0): SCSI command timeout on device handle 0x000a SMID 973
    Oct  4 08:58:13 bcnas1 kernel: (da3:mps0:0:0:0): SCSI command timeout on device handle 0x000a SMID 981
    Oct  4 08:58:21 bcnas1 kernel: mps0: (0:0:0) terminated ioc 804b scsi 0 state c xfer 0
    Oct  4 08:58:21 bcnas1 kernel: mps0: mpssas_abort_complete: abort request on handle 0x0a SMID 973 complete
    Oct  4 08:58:21 bcnas1 kernel: mps0: mpssas_complete_tm_request: sending deferred task management request for handle 0x0a SMID 981
    Oct  4 08:58:21 bcnas1 kernel: mps0: mpssas_abort_complete: abort request on handle 0x0a SMID 981 complete
    Oct  4 08:58:24 bcnas1 kernel: (da3:mps0:0:0:0): READ(6). CDB: 8 0 0 0 80 0 
    Oct  4 08:58:24 bcnas1 kernel: (da3:mps0:0:0:0): CAM status: SCSI Status Error
    Oct  4 08:58:24 bcnas1 kernel: (da3:mps0:0:0:0): SCSI status: Check Condition
    Oct  4 08:58:24 bcnas1 kernel: (da3:mps0:0:0:0): SCSI sense: UNIT ATTENTION asc:29,0 (Power on, reset, or bus device reset occurred)
    Oct  4 09:00:14 bcnas1 kernel: mps0: mpssas_remove_complete on target 0x0000, IOCStatus= 0x0
    Oct  4 09:00:14 bcnas1 kernel: (da3:mps0:0:0:0): lost device
    Oct  4 09:00:19 bcnas1 kernel: pid 9993 (gpart), uid 0: exited on signal 11 (core dumped)
    Oct  4 09:00:20 bcnas1 kernel: pid 9997 (gpart), uid 0: exited on signal 11 (core dumped)
    Oct  4 09:00:25 bcnas1 kernel: pid 10040 (gpart), uid 0: exited on signal 11 (core dumped)

Dump log (from camera photo):
Code: 
    frame pointer           = 0x28:0xffffff80001c5b70
    code segment            = base 0x0, limit 0xfffff, type 0x1b
                            = DPL 0, pres 1, long 1, def32 0, gran1
    processor eflags        = interrupt enabled, resume, IOPL = 0
    current process         = 2 (g_event)
    trap number             = 12
    panic: page fault
    cpuid = 4
    KDB: stack backtrace:
    #0 0xffffffff8060db7e at kdb_backtrace+0x5e
    #1 0xffffffff805db077 at panic+0x187
    #2 0xffffffff808c6510 at trap_fatal+0x290
    #3 0xffffffff808c68ef at trap_pfault+0x28f
    #4 0xffffffff808c6dcf at trap+0x3df
    #5 0xffffffff808aeca4 at calltrap+0x8
    #6 0xffffffff8057a62c at g_run_events+0x1ec
    #7 0xffffffff805afd7f at fork_exit+0x11f
    #8 0xffffffff808af1ee at fork_trampoline+0xe
    Uptime: 3d10h8m23s
    (da3:mps0:0:0:0): Synchronize cache failed, status == 0xa, scsi status == 0x0
    Cannot dump. Device not defined or unavailable.
    Automatic reboot in 15 seconds - press a key on the console to abort

And also if someone can tell me how to make crash dumps work, that would be great. Currently I am thinking of making a small UFS slice mounted at /var/crash to replace the current zfs volume mounted there.
 
So...

Updating to 8-STABLE fixed the ZFS related crashes, and also improved performance. (Although dedup kills write performance, despite 48GB of memory, and 300 GB of L2CACHE).

Updating my LSI firmware to version 11 seems to have fixed the disks disappearing and other kernel panics related to that. [edit: This is wrong; the disks still disappear]

So this panicking appears to be solved.


If you also have an LSI 9211 8i:

To update your firmware, go to:
http://www.lsi.com/Channel/Search/Pages/downloads.aspx?k=P00049 assettype:Firmware&r=

Download the firmware:
9211_8i_Package_P11_IR_IT_Firmware_BIOS_for_MSDOS_Windows (which contains the installer exe and the bios and firmware images)

And also download the installer for the platform where you want to do the actual install. I decided to boot on a Linux disk to install, so I downloaded:
Installer_P11_for_Linux (which contains the Linux native installer, but no bios or firmware image)

Then when reading the reference manual, you need to translate their use of the word "download" to mean "upload TO the IO card" and their use of the word "upload" to mean "download FROM the IO card". The "-b" option is what I used to write the new bios, and the "-f" is to write the new firmware file to the card.

In the zip you will find 2 copies of firmware (IR and IT). I didn't know which one to pick, so I decided to put the same type as I had already. To figure out which one I had, I also downloaded P10 of the firmware and compared (using md5 sum) to what was on my card already, which was the IR one.
 
Update: I still believe the panicking is solved. However, the mps driver losing disks is not solved. The same thing happened today (disk faulted, but really mps just lost it), except today some zfs datasets would hang.

I blame the dataset hang issue on NFS. I think it may have to do with the .zfs/snapshots directory, so I changed that to hidden.

# zfs set snapdir=hidden tank

Now it hangs if I try to view the .zfs/snapshot directory through an NFS mount, but not until I actually type in the path. With snapdir=visible, it would crash after a short time on its own (possibly due to a connected machine scanning through the directories). I'll send in a PR for that eventually.
 
What is your source on that? Can you point me to something by the devs, testers, LSI, etc. that says that the mps driver works best with IT firmware?

I would also love to be on a mailing list, or have a bug tracker, or some way of knowing what is going on with the progress of the mps driver... would you happen to know how I could do that?

No, I haven't tried the IT firmware, although I considered it, since ZFS doesn't want RAID in there. And thank you very much for the suggestion. I will do that next reboot, or next time it fails.
 
@olav
Guess who wrote in that perticular mail?;) Too bad that they seem to be busy playing the blame game round and round...

@peetaur
This is more than cool, this is awesome! We have the exact same problem, losing disks and all:
http://forums.freebsd.org/showthread.php?t=27128

Could you post your hardware so we can compare if there´s anything between us that differs so we perhaps could start pointing fingers?:)

/Sebulon
 
@Sebulon

Here are the details:

HW
Code: 
4HE Chassis from Supermicro 847E16-R1400LPB
with 2 1400 Watt red. power and 36x HotSwap for SAS or SATA

Motherboard from Supermicro
- Intel® 5520 (Tylersburg) Chipset
- 12 DIMM memory slots (max. 192GB DDR3)
- 2x 100/1000Base TX Gigabit Ethernet Port (Dual Intel® 82576 Gigabit Ethernet)
- 6x SATA (3 Gbps) Ports via ICH10R Controller
- PCI Slots: 7x (x8) PCI-E 2.0 (in x16 slots)
- Integrated IPMI 2.0 with Dedicated LAN
- Integrated Matrox G200eW Graphics
CPU
- 2x E5620 Intel Xeon (Westmere) Quad Core CPU, (80W) 2,40 GHz, 12 MB L3 Cache
RAM
- 48 GB (6x 8GB) DDR3 1333 DIMM, REG, ECC
SAS HBA
- 9211-8i
Network
- 10G Card with Dual-port Intel® 82598EB (CX4)
Disks
- 9x HDD 3TB SATA from Hitachi, 7.2k UPM, 64 MB Cache
- 9x HDD 3TB SATA from Seagate, 7.2k UPM, 64 MB Cache
- 2x consumer SSDs (boot, root, zil, cache)

SW:
# uname -a
Code: 
FreeBSD bcnas1.bc.local 8.2-STABLE FreeBSD 8.2-STABLE #0: Thu Sep 29 15:06:03 CEST 2011     root@bcnas1.bc.local:/usr/obj/usr/src/sys/GENERIC  amd64

# zpool get version zroot tank
Code: 
NAME   PROPERTY  VALUE    SOURCE
tank   version   28       default
zroot  version   28       default

Our hardware has some differences, but we both have Supermicro board and chassis, and consumer SSDs, and we are using the mps driver.

How interesting that yours gets panics. Mine panicked at random on 8 stable from April, but not recent cvsup-ed versions. The only way I got mine to panic during the FAULTED/degraded state if I remove the faulted disk and run "gpart recover ..." on the disk. (see post #8). Everything else it does in this state, such as rsync to copy files to its pool, zfs send, NFS shares, etc. continue running. But I did find and report a bug where when you use "zfs rename -r <snapshot>" when you have a zvol, zfs can hang.

Are your panics completely solved after your 'periodic' changes, and now just losing disks like me?

Peter
 
olav said:
LSI has released a LSI driver for FreeBDS 8-RELEASE for the 9210-8i in August http://www.lsi.com/products/storagecomponents/Pages/LSISAS9210-8i.aspx

Maybe that can help?
9210-8i is 99% identical to the 9211-8i

Ken may be right its a ZFS issue, though there could be a chain of issues that triggers it.
Click to expand...

I doubt it is only a ZFS issue. It shouldn't matter how I access the disks, whether it is using dd, or a file system, or camcontrol, or smartctl. In the freebsd-scsi mailing list, there is a guy who says he can easily cause the problem simply by using "smartctl -a" rapidly. Can you blame that on ZFS? (message subject is "mps/LSI SAS2008 controller crashes when smartctl is run with upped disk tags")

I still think it is either the driver, or the hardware (such as the mainboard, backplanes, or hba). If errors caused the problem, then the driver or controller should handle those errors. Errors are normal... disks fail... anything happens and it should be handled, not crashed or frozen. A read should fail, not all reads from that point on.

And thanks for the driver suggestion. A driver (the same one?) is linked under the page for my exact card also, but my card is not found in the menus... I found it with an external web search. Here is the link.

http://www.lsi.com/channel/products/storagecomponents/Pages/LSISAS9211-8i.aspx
 
@peetaur

Awesome! Totally awesome! We have different motherboards, hba's, cabling and drives. Just about everything seems different, except we both run 8-STABLE and the mps driver. Isn't that making fairly obvious where the problem is?

/Sebulon
 
@peetaur

Is it OK if I copy your HW and extract from messages and send it to Ken and the rest on the mail thread? I think it´s important for all to know that this is happening to more than just one person.

And yes, the panics are gone. But I don´t think that´s a win, really. I would be much more satisfied if the underlying issue could be solved so that people after me won´t have to worry about it.

/Sebulon
 
@Sebulon

Sure, I figure whatever is posted on these forums is essentially public domain.

And now I am trying the driver from LSI (link found in post #17).

Here is a log while I was using smartctl -a to try to cause it to crash. (I was never successful in crashing it this way before... but on the freebsd-scsi mailing list, someone says he easily does).



Code: 
Nov  3 09:17:10 bcnas1bak kernel: mpslsi0: mpssas_scsiio_timeout checking sc 0xffffff800f629000 cm 0xffffff800f65f698
Nov  3 09:17:10 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 6 2c 0 da 0 0 0 0 0 4f 0 c2 0 b0 0 length 0 SMID 717 command timeout cm 0xffffff800f65f698 ccb
 0xffffff0026bbb800
Nov  3 09:17:10 bcnas1bak kernel: mpslsi0: mpssas_alloc_tm freezing simq
Nov  3 09:17:10 bcnas1bak kernel: mpslsi0: timedout cm 0xffffff800f65f698 allocated tm 0xffffff800f6340f8
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 2c f3 be e2 0 0 2a 0 length 21504 SMID 261 completed cm 0xffffff800f643cd8 ccb 0xffffff0026bd1000 during recovery
ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 2c f3 be e2 0 0 2a 0 length 21504 SMID 261 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 52 1e 2 e3 0 0 2b 0 length 22016 SMID 534 completed cm 0xffffff800f654550 ccb 0xffffff0026b96000 during recovery i
oc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 52 1e 2 e3 0 0 2b 0 length 22016 SMID 534 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 3a 5 14 a3 0 0 2b 0 length 22016 SMID 798 completed cm 0xffffff800f664510 ccb 0xffffff003d438000 during recovery i
oc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 3a 5 14 a3 0 0 2b 0 length 22016 SMID 798 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 39 81 86 6f 0 0 2b 0 length 22016 SMID 590 completed cm 0xffffff800f657b90 ccb 0xffffff00314ce800 during recovery
ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 39 81 86 6f 0 0 2b 0 length 22016 SMID 590 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 39 47 e8 2c 0 0 2a 0 length 21504 SMID 634 completed cm 0xffffff800f65a630 ccb 0xffffff0026ba1800 during recovery
ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 39 47 e8 2c 0 0 2a 0 length 21504 SMID 634 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 2d 8b 96 af 0 0 2b 0 length 22016 SMID 707 completed cm 0xffffff800f65ece8 ccb 0xffffff0026bb1800 during recovery
ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 2d 8b 96 af 0 0 2b 0 length 22016 SMID 707 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 6 2c 0 da 0 0 0 0 0 4f 0 c2 0 b0 0 length 0 SMID 717 completed timedout cm 0xffffff800f65f698 ccb 0xffffff0026bbb800 during recov(da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 1c dc 68 73 0 0 2b 0 length 22016 SMID 690 completed cm 0xffffff800f65dc70 ccb 0xffffff0026bea800 during recovery ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 1c dc 68 73 0 0 2b 0 length 22016 SMID 690 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 58 d da 33 0 0 2b 0 length 22016 SMID 947 completed cm 0xffffff800f66d568 ccb 0xffffff0026bf9000 during recovery ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 58 d da 33 0 0 2b 0 length 22016 SMID 947 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 4b 30 d1 80 0 0 2a 0 length 21504 SMID 683 completed cm 0xffffff800f65d5a8 ccb 0xffffff003d47f800 during recovery ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 4b 30 d1 80 0 0 2a 0 length 21504 SMID 683 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 4a d 10 d0 0 0 2b 0 length 22016 SMID 219 completed cm 0xffffff800f641428 ccb 0xffffff0031536000 during recovery ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 4a d 10 d0 0 0 2b 0 length 22016 SMID 219 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 41 1e 9a 58 0 0 2a 0 length 21504 SMID 169 completed cm 0xffffff800f63e3b8 ccb 0xffffff00314ec800 during recovery ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 41 1e 9a 58 0 0 2a 0 length 21504 SMID 169 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d0 0 1 0 0 0 4f 0 c2 0 b0 0 length 512 SMID 139 completed cm 0xffffff800f63c6a8 ccb 0xffffff0026a89000 during recovery ioc (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d0 0 1 0 0 0 4f 0 c2 0 b0 0 length 512 SMID 139 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 6 2c 0 da 0 0 0 0 0 4f 0 c2 0 b0 0 length 0 SMID 876 completed cm 0xffffff800f6690a0 ccb 0xffffff00314c8800 during recovery ioc 8(pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 6 2c 0 da 0 0 0 0 0 4f 0 c2 0 b0 0 length 0 SMID 876 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d5 0 1 0 6 0 4f 0 c2 0 b0 0 length 512 SMID 661 completed cm 0xffffff800f65c058 ccb 0xffffff0026b7d000 during recovery ioc (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d5 0 1 0 6 0 4f 0 c2 0 b0 0 length 512 SMID 661 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d5 0 1 0 6 0 4f 0 c2 0 b0 0 length 512 SMID 471 completed cm 0xffffff800f650848 ccb 0xffffff0026be7800 during recovery ioc (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d5 0 1 0 6 0 4f 0 c2 0 b0 0 length 512 SMID 471 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d0 0 1 0 0 0 4f 0 c2 0 b0 0 length 512 SMID 215 completed cm 0xffffff800f641048 ccb 0xffffff0026bef800 during recovery ioc (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d0 0 1 0 0 0 4f 0 c2 0 b0 0 length 512 SMID 215 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d5 0 1 0 6 0 4f 0 c2 0 b0 0 length 512 SMID 203 completed cm 0xffffff800f6404a8 ccb 0xffffff0026bb6000 during recovery ioc (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d5 0 1 0 6 0 4f 0 c2 0 b0 0 length 512 SMID 203 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d0 0 1 0 0 0 4f 0 c2 0 b0 0 length 512 SMID 546 completed cm 0xffffff800f6550f0 ccb 0xffffff003d447800 during recovery ioc (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d0 0 1 0 0 0 4f 0 c2 0 b0 0 length 512 SMID 546 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d5 0 1 0 6 0 4f 0 c2 0 b0 0 length 512 SMID 513 completed cm 0xffffff800f6530f8 ccb 0xffffff0026bcb800 during recovery ioc (pass0:mpslsi0:0:10:0): ATA COMMAND PASS THROUGH(16). CDB: 85 8 e 0 d5 0 1 0 6 0 4f 0 c2 0 b0 0 length 512 SMID 513 terminated ioc 804b scsi 0 state c xfer 0
Nov  3 09:17:11 bcnas1bak kernel: (noperiph:mpslsi0:0:10:0): SMID 1 abort TaskMID 717 status 0x0 code 0x0 count 20
Nov  3 09:17:11 bcnas1bak kernel: (noperiph:mpslsi0:0:10:0): SMID 1 finished recovery after aborting TaskMID 717
Nov  3 09:17:11 bcnas1bak kernel: mpslsi0: mpssas_free_tm releasing simq
Nov  3 09:17:17 bcnas1bak kernel: (da0:mpslsi0:0:10:0): READ(10). CDB: 28 0 41 1e 9a 58 0 0 2a 0
Nov  3 09:17:17 bcnas1bak kernel: (da0:mpslsi0:0:10:0): CAM status: SCSI Status Error
Nov  3 09:17:17 bcnas1bak kernel: (da0:mpslsi0:0:10:0): SCSI status: Check Condition
Nov  3 09:17:17 bcnas1bak kernel: (da0:mpslsi0:0:10:0): SCSI sense: UNIT ATTENTION asc:29,0 (Power on, reset, or bus device reset occurred)


It looks similar to the crash with the mps driver, except no ZFS disks FAULTED. :) Everything runs ONLINE.

So give that driver a try, and see if periodic can crash it.
 
Dear readers,

I got another crash, with the mpslsi driver.

NFS services were disrupted, so people noticed it whatever the failure was. On previous crashes, with losing one disk, there was no disruption of service, except when other issues were combined, such as:
-doing [cmd=]ls /some/nfs/mount/.zfs/snapshot[/cmd] which would hang whichever NFS mounted file system you are listing.
-the [cmd=]gpart recover ...[/cmd] causing a panic mentioned above.

This time someone else ended up rebooting it, so I don't know if it lost a disk or what. But the root system was online, so someone could log in and run [cmd=]shutdown -r now[/cmd] And when the system came back up, zfs had 1 checksum error on a root disk, just like other crashes.

And note that this was the third crash, all three of which were on a Friday night. So on Monday, I'll try to figure out what it is about Fridays.

@Sebulon
Maybe you can tell me more about what periodic was doing for you and what I should change to fix it like you did. I already added
Code: 
daily_status_security_chksetuid_enable="NO"
to my /etc/periodic.conf
long before the crash, but didn't reboot, or restart periodic or anything. Is a restart needed?

Unlike the last time with mpslsi, there is no line like this (which was the last line, on a second server, after which things seemed fine):

Code: 
Nov 3 09:17:17 bcnas1bak kernel: (da0:mpslsi0:0:10:0): SCSI sense: UNIT ATTENTION asc:29,0 (Power on, reset, or bus device reset occurred)

Here is a bunch of the log, including the shutdown and the annoying "shutdown terminated abnormally":

Code: 
Nov 18 16:58:46 bcnas1 kernel: mpslsi0: mpssas_scsiio_timeout checking sc 0xffffff800f629000 cm 0xffffff800f669c40
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a1 2a 0 1 0 0 length 131072 SMID 888 command timeout cm
 0xffffff800f669c40 ccb 0xffffff0037d1e000
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: mpssas_alloc_tm freezing simq
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: timedout cm 0xffffff800f669c40 allocated tm 0xffffff800f6340f8
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: mpssas_scsiio_timeout checking sc 0xffffff800f629000 cm 0xffffff800f668218
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a2 2a 0 1 0 0 length 131072 SMID 861 command timeout cm
 0xffffff800f668218 ccb 0xffffff03d58a9800
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: queued timedout cm 0xffffff800f668218 for processing by tm 0xffffff800f6340f8
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: mpssas_scsiio_timeout checking sc 0xffffff800f629000 cm 0xffffff800f670d98
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a3 2a 0 1 0 0 length 131072 SMID 1005 command timeout cm
 0xffffff800f670d98 ccb 0xffffff0026b7a800
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: queued timedout cm 0xffffff800f670d98 for processing by tm 0xffffff800f6340f8
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: mpssas_scsiio_timeout checking sc 0xffffff800f629000 cm 0xffffff800f6457f8
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a4 2a 0 1 0 0 length 131072 SMID 289 command timeout cm
 0xffffff800f6457f8 ccb 0xffffff003d4da000
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: queued timedout cm 0xffffff800f6457f8 for processing by tm 0xffffff800f6340f8
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: mpssas_scsiio_timeout checking sc 0xffffff800f629000 cm 0xffffff800f662ae8
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): SYNCHRONIZE CACHE(10). CDB: 35 0 0 0 0 0 0 0 0 0 length 0 SMID 771 command timeout cm
 0xffffff800f662ae8 ccb 0xffffff0031968800
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: queued timedout cm 0xffffff800f662ae8 for processing by tm 0xffffff800f6340f8
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 2 41 a5 bf 0 0 18 0 length 12288 SMID 345 completed cm
 0xffffff800f648e38 ccb 0xffffff03d5887000 during recovery ioc 804b scsi 0 state c xfer 0
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 2 41 a5 bf 0 0 18 0 length 12288 SMID 345 terminated ioc 804b scsi
 0 state c xfer 0
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): SYNCHRONIZE CACHE(10). CDB: 35 0 0 0 0 0 0 0 0 0 length 0 SMID 771 completed timedout cm
 0xffffff800f662ae8 ccb 0xffffff0031968800 during recovery ioc 804b scsi 0 state(da10:mpslsi0:0:21:0): SYNCHRONIZE CACHE(10). CDB: 35 0 0 0 0 0
 0 0 0 0 length 0 SMID 771 terminated ioc 804b scsi 0 state c xfer 0
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a1 2a 0 1 0 0 length 131072 SMID 888 completed timedout cm
 0xffffff800f669c40 ccb 0xffffff0037d1e000 during recovery ioc 8048 scsi 0 state c (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a3 2a 0 1
 0 0 length 131072 SMID 1005 completed timedout cm 0xffffff800f670d98 ccb 0xffffff0026b7a800 during recovery ioc 804b scsi 0 state
 c(da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a3 2a 0 1 0 0 length 131072 SMID 1005 terminated ioc 804b scsi 0 state c xfer 0
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a2 2a 0 1 0 0 length 131072 SMID 861 completed timedout cm
 0xffffff800f668218 ccb 0xffffff03d58a9800 during recovery ioc 804b scsi 0 state c (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a2 2a 0 1
 0 0 length 131072 SMID 861 terminated ioc 804b scsi 0 state c xfer 0
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a4 2a 0 1 0 0 length 131072 SMID 289 completed timedout cm
 0xffffff800f6457f8 ccb 0xffffff003d4da000 during recovery ioc 804b scsi 0 state c (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 13 32 a4 2a 0 1
 0 0 length 131072 SMID 289 terminated ioc 804b scsi 0 state c xfer 0
Nov 18 17:10:42 bcnas1 kernel: (noperiph:mpslsi0:0:21:0): SMID 1 abort TaskMID 888 status 0x4a code 0x0 count 6
Nov 18 17:10:42 bcnas1 kernel: (noperiph:mpslsi0:0:21:0): SMID 1 finished recovery after aborting TaskMID 888
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: mpssas_free_tm releasing simq
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: mpssas_scsiio_timeout checking sc 0xffffff800f629000 cm 0xffffff800f6513e8
Nov 18 17:10:42 bcnas1 kernel: (da10:mpslsi0:0:21:0): READ(10). CDB: 28 0 2 40 3b 14 0 0 21 0 length 16896 SMID 483 command timeout cm
 0xffffff800f6513e8 ccb 0xffffff0026bd2000
Nov 18 17:10:42 bcnas1 kernel: mpslsi0: mpssas_alloc_tm freezing simq

...

Nov 18 17:39:46 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 a 12 79 0 0 0 88 0 length 69632 SMID 252 completed timedout cm
 0xffffff800f643420 ccb 0xffffff05b6b56800 during recovery ioc 804b scsi 0 state c xf(da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 a 12 79 0 0 0
 88 0 length 69632 SMID 252 terminated ioc 804b scsi 0 state c xfer 0
Nov 18 17:39:46 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 a 12 7a 0 0 0 88 0 length 69632 SMID 159 completed timedout cm
 0xffffff800f63da08 ccb 0xffffff05ada40000 during recovery ioc 804b scsi 0 state c xf(da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 a 12 7a 0 0 0
 88 0 length 69632 SMID 159 terminated ioc 804b scsi 0 state c xfer 0
Nov 18 17:39:46 bcnas1 kernel: (da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 a 12 7b 0 0 0 88 0 length 69632 SMID 572 completed timedout cm
 0xffffff800f656a20 ccb 0xffffff0026be3000 during recovery ioc 804b scsi 0 state c xf(da10:mpslsi0:0:21:0): WRITE(10). CDB: 2a 0 a 12 7b 0 0 0
 88 0 length 69632 SMID 572 terminated ioc 804b scsi 0 state c xfer 0
Nov 18 17:39:46 bcnas1 kernel: (noperiph:mpslsi0:0:21:0): SMID 39 abort TaskMID 304 status 0x4a code 0x0 count 32
Nov 18 17:39:46 bcnas1 kernel: (noperiph:mpslsi0:0:21:0): SMID 39 finished recovery after aborting TaskMID 304
Nov 18 17:39:46 bcnas1 kernel: mpslsi0: mpssas_free_tm releasing simq
Nov 18 17:39:56 bcnas1 shutdown: reboot by uwe:
Nov 18 17:39:58 bcnas1 ntpd[68834]: ntpd exiting on signal 15
Nov 18 17:40:28 bcnas1 rc.shutdown: 30 second watchdog timeout expired. Shutdown terminated.
Nov 18 17:40:28 bcnas1 init: /bin/sh on /etc/rc.shutdown terminated abnormally, going to single user mode
Nov 18 17:40:28 bcnas1 syslogd: exiting on signal 15

Peter
 
For what it's worth, make sure you have a power supply that is big enough for your disks. I have seen erratic disk behaviour like this and solved it by replacing the PSU.
 
That's sound advice, but my dual 1400W PSU system is supposed to run 36 disks with one PSU, and runs fine with new firmware, and reports only 400W used right now.

I still haven't had any new crashes, only hangs, which I've worked around by locking any process using "zfs" so only one can do it at a time; eg. delete snapshots and zfs send together causes a hang. (8.3-STABLE)
 
You must log in or register to reply here.
Back
Top