Bug 140416 - [mfi] [patch] mfi driver stuck in timeout
Summary: [mfi] [patch] mfi driver stuck in timeout
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: Unspecified
Hardware: Any Any
: Normal Affects Only Me
Assignee: Xin LI
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2009-11-09 13:20 UTC by Stephane D'Alu
Modified: 2012-02-07 22:01 UTC (History)
0 users

See Also:


Attachments
testperc.c (4.20 KB, text/x-csrc)
2011-03-09 01:04 UTC, nschelly
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Stephane D'Alu 2009-11-09 13:20:07 UTC
Systeme is a 32Go memory, 2 cpus 4 cores 2 SMT threads

The computer is configured to use ZFS with disks attached to the mfi controller
when performing for example zfs scrub, the controller enter in timeout and doesn't leave this state:

mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 41 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 71 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 101 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 131 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 161 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 191 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 221 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 251 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 281 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 311 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 341 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 371 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 401 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 431 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 461 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 491 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 521 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 551 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 581 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 611 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 641 SECONDS
mfi0: COMMAND 0xffffff80009c4b90 TIMEOUT AFTER 671 SECONDS

I can perform further diagnostics on the systems, just tell me what command need to be run
Comment 1 Stéphane D'Alu 2009-11-09 14:16:59 UTC
Adapter is (mfiutil show adapter)

mfi0 Adapter:
     Product Name: PERC 6/E Adapter
    Serial Number: 1122334455667788
         Firmware: 6.2.0-0013
      RAID Levels: JBOD, RAID0, RAID1, RAID5, RAID6, RAID10, RAID50
   Battery Backup: present
            NVRAM: 32K
   Onboard Memory: 512M
   Minimum Stripe: 8K
   Maximum Stripe: 1M


ZFS pool:
   pool: fs
  state: ONLINE
  scrub: scrub in progress for 1h5m, 14.36% done, 6h28m to go
config:

         NAME                STATE     READ WRITE CKSUM
         fs                  ONLINE       0     0     0
           raidz2            ONLINE       0     0     0
             label/fs-zfs-0  ONLINE       0     0     0
             label/fs-zfs-1  ONLINE       0     0     0
             label/fs-zfs-2  ONLINE       0     0     0
             label/fs-zfs-3  ONLINE       0     0     0
             label/fs-zfs-4  ONLINE       0     0     0
             label/fs-zfs-5  ONLINE       0     0     0
             label/fs-zfs-6  ONLINE       0     0     0
             label/fs-zfs-7  ONLINE       0     0     0
Comment 2 Stephane D'Alu 2009-11-12 15:00:49 UTC
when enabling MFI_DEBUG and dumping information on timeout:


mfi0: COMMAND 0xffffff80009c2660 TIMEOUT AFTER 36 SECONDS
mfi0: cm=0xffffff80009c2660 index=12 total_frame_size=52 extra_frames=0
mfi0: flags=83<MAPPED,DATAIN,Q_BUSY>
mfi0: cmd=LD_READ target_id=5 sg_count=1 data_len=128 lba=1505643648
mfi0: flags=12<SGL64,READ>
SG List:
0x9664a000:065536
mfi0: mfi_timeout 2527 COMMAND 0xffffff80009c2660 S/G count bad 0 65536 
65536 0x9664a000
mfi0: cm=0xffffff80009c2660 index=12 total_frame_size=52 extra_frames=0
mfi0: flags=83<MAPPED,DATAIN,Q_BUSY>
mfi0: cmd=LD_READ target_id=5 sg_count=1 data_len=128 lba=1505643648
mfi0: flags=12<SGL64,READ>
SG List:
0x9664a000:065536
0000   01 80 00 00 05 00 00 01 0c 00 00 00 00 00 00 00
0010   12 00 00 00 80 00 00 00 00 06 fa 02 00 00 00 00
0020   80 4c be 59 00 00 00 00 00 a0 64 96 00 00 00 00
0030   00 00 01 00
0000   05 00 00 00 00 00 00 01 12 00 00 00 00 00 00 00
0010   12 00 00 00 00 01 00 00 00 05 04 01 2b 03 00 00
0020   ff ff 00 00 00 00 00 00 00 db d9 0b 00 00 00 00
0030   00 01 00 00


mfi0: COMMAND 0xffffff80009c2660 TIMEOUT AFTER 308 SECONDS
mfi0: cm=0xffffff80009c2660 index=12 total_frame_size=52 extra_frames=0
mfi0: flags=83<MAPPED,DATAIN,Q_BUSY>
mfi0: cmd=LD_READ target_id=5 sg_count=1 data_len=128 lba=1505643648
mfi0: flags=12<SGL64,READ>
SG List:
0x9664a000:065536
mfi0: mfi_timeout 2527 COMMAND 0xffffff80009c2660 S/G count bad 0 65536 
65536 0x9664a000
mfi0: cm=0xffffff80009c2660 index=12 total_frame_size=52 extra_frames=0
mfi0: flags=83<MAPPED,DATAIN,Q_BUSY>
mfi0: cmd=LD_READ target_id=5 sg_count=1 data_len=128 lba=1505643648
mfi0: flags=12<SGL64,READ>
SG List:
0x9664a000:065536
0000   01 80 00 00 05 00 00 01 0c 00 00 00 00 00 00 00
0010   12 00 00 00 80 00 00 00 00 06 fa 02 00 00 00 00
0020   80 4c be 59 00 00 00 00 00 a0 64 96 00 00 00 00
0030   00 00 01 00
0000   05 00 00 00 00 00 00 01 12 00 00 00 00 00 00 00
0010   12 00 00 00 00 01 00 00 00 05 04 01 2b 03 00 00
0020   ff ff 00 00 00 00 00 00 00 db d9 0b 00 00 00 00
0030   00 01 00 00
Comment 3 nschelly 2011-03-09 01:04:56 UTC
As posted here: http://lists.freebsd.org/pipermail/freebsd-scsi/2011-March/004832.html

We've got some more information about the mpt testing we've been doing here.  The setup we're testing is Dell PowerEdge r610 servers with PERC H800 SAS/RAID cards connected to MD1200 shelves full of 12 SAS drives.  We've recreated the same problem on other configurations, including combinations of r510s, MD1220 shelves, PERC H700 cards, etc.  We've also eliminated any particular piece of hardware as faulty by running these on identical hardware configurations in mirrored setups on different physical pieces  of hardware.  We've experienced these issues in FreeBSD 7.3, 8.1, and 8.2.  We've experienced this issue with either RAID10 logical drive configurations formatted with UFS or 6-disk JBOD configurations setup in a ZFS raidz volume.  We've triggered the problem with both bonnie++ and iozone.  All machines are runnning the latest firmware on the H700 and H800 cards.

The easiest method to reproduce this problem is with a ZFS configuration and using `iozone -a`.  We have a 6-disk raidz partition with a ZFS filesystem on it.  We just run `iozone -a` from within that filesystem, and I'd say 3 out of 4 times, it will eventually pause.  After 45-50 seconds of pausing, you'll start seeing the console and /var/log/messages output that looks something like: 
  mfi0: COMMAND 0xffffff8000db5fe0 TIMEOUT AFTER 105 SECONDS

If we let it go for a few days, it may actually "finish" and recover, but it's essentially just stuck and not recovering.  The system is responsive and fully operational except the dead controller at this point.  We cannot kill the iozone process that is hung on these IO operations, even with `kill -9`.  Like others have reported, we can run any of the mfiutil commands and the controller immediately begins to respond normally again.  Usually, the iozone test will complete, but sometimes it will even get st uck again on the same run.  

We compiled mfiutil with debugging symbols so we could run it with gdb and see exactly what was causing the controller to become responsive again.  It's the ioctl() call that does it.  For example:

`mfiutil show volumes` eventually gets to something like:
  mfi_dcmd_command (fd=7, opcode=50397184, buf=0x7fffffffe4a0, bufsize=1032, mbox=0x0, mboxlen=0, statusp=0x0)
  at /usr/src/usr.sbin/mfiutil/mfi_cmd.c:257
 * fd=7 is /dev/mfi0, where the command will be sent with an ioctl command
 * opcode=50397184 is the MFI_DCMD_LD_GET_LIST command

`mfiutil show battery` eventually gets to something like:
  mfi_dcmd_command (fd=7, opcode=84017152, buf=0x7fffffffea20, bufsize=48, mbox=0x0, mboxlen=0, statusp=0x7fffffffe9cf "")
  at /usr/src/usr.sbin/mfiutil/mfi_cmd.c:257
 * fd=7 is /dev/mfi0, where the command will be sent with an ioctl command
 * opcode=84017152 is the MFI_DCMD_BBU_GET_CAPACITY_INFO command

I wrote a small self-contained C program that can easily be modified to run any ioctl command you'd like and send it to /dev/mfi0 (attached).  Use it if you'd like at your own risk, but it's essentially just running an arbitrary command with ioctl, putting nothing into the memory range normally passed by the *buf pointer.  I did try sending random opcodes, and it didn't work, so it does have to be an opcode that the firmware will recognize at least, but it doesn't seem to matter which one.

I'm not sure where else we should be looking for a fix.  We can reliably reproduce the problem, analyze the system during the issue, and recover the system to a normal state.  If there's anyone who can help us troubleshoot this with any information we can gather or even a local login remotely accessible, we're open to ideas.  

--
Neil Schelly
Director of Uptime
Dynamic Network Services, Inc.
W: 603-296-1581
M: 508-410-4776
http://www.dyndns.com
Comment 4 nschelly 2011-03-22 18:46:34 UTC
We came up with a patch and explanation to resolve this issue.  The patch should be credited to Scott Long.

See my explanation and the small patch here: 
http://lists.freebsd.org/pipermail/freebsd-scsi/2011-March/004839.html

--
Neil Schelly
Director of Uptime
Dynamic Network Services, Inc.
W: 603-296-1581
M: 508-410-4776
http://www.dyndns.com
Comment 5 geoffroy desvernay 2011-10-23 13:20:11 UTC
This patch works for me(r) on 8-STABLE from yesterday and 9-RC1
On dell PowerEdge 415 (PERC H700 Adapter) and PE515 (PERC H700 Integrated=
)

Without the patch, same problem occurs (especially with ZFS).

--=20
*Geoffroy Desvernay*
C.R.I - Administration syst=C3=A8mes et r=C3=A9seaux
Ecole Centrale de Marseille
Comment 6 vhoffman 2011-11-02 22:05:10 UTC
I had to manually apply this patch to 8-STABLE but it appears to have
resolved the stalls i was seeing with my

mfi0@pci0:5:0:0:        class=0x010400 card=0x070015d9 chip=0x00791000
rev=0x04 hdr=0x00
    vendor     = 'LSI Logic (Was: Symbios Logic, NCR)'
    class      = mass storage
    subclass   = RAID

[root@banshee /mnt/tmp]# mfiutil -u0 show adapter
mfi0 Adapter:
    Product Name: Supermicro SMC2108
   Serial Number:
        Firmware: 12.12.0-0047
     RAID Levels: JBOD, RAID0, RAID1, RAID5, RAID6, RAID10, RAID50
  Battery Backup: present
           NVRAM: 32K
  Onboard Memory: 512M
  Minimum Stripe: 8k
  Maximum Stripe: 1M
[root@banshee /mnt/tmp]# mfiutil -u0 show firmware
mfi0 Firmware Package Version: 12.12.0-0047
mfi0 Firmware Images:
Name  Version                        Date         Time         Status
APP   2.120.53-1235                  Mar 25 2011  17:37:57     active
BIOS  3.22.00_4.11.05.00_0x05020000   3/16/2011
   3/16/2011
  active
PCLI  04.04-017:#%00008              Oct 12 2010  11:32:58     active
BCON  6.0-37-e_32-Rel                Mar 23 2011  10:30:10     active
NVDT  2.09.03-0013                   Mar 29 2011  02:35:36     active
BTBL  2.02.00.00-0000                Sep 16 2009  21:37:06     active
BOOT  01.250.04.219                  4/28/2009    12:51:38     active
Comment 7 John Baldwin freebsd_committer freebsd_triage 2011-11-14 18:25:42 UTC
State Changed
From-To: open->patched

Fix committed to head in 227409. 


Comment 8 John Baldwin freebsd_committer freebsd_triage 2011-11-14 18:25:42 UTC
Responsible Changed
From-To: freebsd-bugs->delphij

Fix committed to head in 227409.
Comment 9 Xin LI freebsd_committer freebsd_triage 2012-02-07 22:00:10 UTC
State Changed
From-To: patched->closed

The fix was MFC'ed as r227611 and r227533 to RELENG_8 and RELENG_9 
so close this PR.