sil3132 eSATA problem

Hello
Hello!
I am running
Linux ante 2.6.32.55sebita4-reiserfs4 #5 SMP Wed Feb 1 06:24:50 ART 2012 x86_64 GNU/Linux custom compiled with reiserfs4 patches on an IBM X3200 M3

I have a two port eSATA SIL3132:
10:00.0 RAID bus controller: Silicon Image, Inc. SiI 3132 Serial ATA Raid II Controller (rev 01)
Subsystem: Silicon Image, Inc. Device 7132
Flags: bus master, fast devsel, latency 0, IRQ 18
Memory at 91b04000 (64-bit, non-prefetchable) [size=128]
Memory at 91b00000 (64-bit, non-prefetchable) [size=16K]
I/O ports at 3000 [size=128]
Expansion ROM at 80600000 [disabled] [size=512K]
Capabilities: [54] Power Management version 2
Capabilities: [5c] MSI: Enable- Count=1/1 Maskable- 64bit+
Capabilities: [70] Express Legacy Endpoint, MSI 00
Kernel driver in use: sata_sil24

This gives me this two ports:
[6] sata_sil24
cmd_per_lun=1 host_busy=0 sg_tablesize=253 unchecked_isa_dma=0
dir: /sys/class/scsi_host//host6
device dir: /sys/devices/pci0000:00/0000:00:1c.6/0000:10:00.0/host6
[7] sata_sil24
cmd_per_lun=1 host_busy=0 sg_tablesize=253 unchecked_isa_dma=0
dir: /sys/class/scsi_host//host7
device dir: /sys/devices/pci0000:00/0000:00:1c.6/0000:10:00.0/host7

On ata6 I have a Lian Li box with JM393PM with 5 disks:
[6:0:0:0] disk ATA WDC WD20EARS-00S 0957 /dev/sdb
state=running queue_depth=1 scsi_level=6 type=0 device_blocked=0
timeout=30
dir: /sys/bus/scsi/devices/6:0:0:0
[/sys/devices/pci0000:00/0000:00:1c.6/0000:10:00.0/host6/target6:0:0/6:0:0:0]
[6:1:0:0] disk ATA WDC WD20EARS-00S 80.0 /dev/sdc
state=running queue_depth=31 scsi_level=6 type=0 device_blocked=0
timeout=30
dir: /sys/bus/scsi/devices/6:1:0:0
[/sys/devices/pci0000:00/0000:00:1c.6/0000:10:00.0/host6/target6:1:0/6:1:0:0]
[6:2:0:0] disk ATA WDC WD20EARS-00S 80.0 /dev/sdd
state=running queue_depth=31 scsi_level=6 type=0 device_blocked=0
timeout=30
dir: /sys/bus/scsi/devices/6:2:0:0
[/sys/devices/pci0000:00/0000:00:1c.6/0000:10:00.0/host6/target6:2:0/6:2:0:0]
[6:3:0:0] disk ATA WDC WD20EARS-00M 51.0 /dev/sde
state=running queue_depth=31 scsi_level=6 type=0 device_blocked=0
timeout=30
dir: /sys/bus/scsi/devices/6:3:0:0
[/sys/devices/pci0000:00/0000:00:1c.6/0000:10:00.0/host6/target6:3:0/6:3:0:0]
[6:4:0:0] disk ATA WDC WD20EARS-00M 51.0 /dev/sdf
state=running queue_depth=31 scsi_level=6 type=0 device_blocked=0
timeout=30
dir: /sys/bus/scsi/devices/6:4:0:0
[/sys/devices/pci0000:00/0000:00:1c.6/0000:10:00.0/host6/target6:4:0/6:4:0:0]

And ata7 is _unused_, nothing is connected to it.

However from time to time I see on the logs:

[904916.169177] ata7.00: failed to read SCR 1 (Emask=0x40)
[904916.169210] ata7.01: failed to read SCR 1 (Emask=0x40)
[904916.169239] ata7.02: failed to read SCR 1 (Emask=0x40)
[904916.169268] ata7.03: failed to read SCR 1 (Emask=0x40)
[904916.169293] ata7.04: failed to read SCR 1 (Emask=0x40)
[904916.169322] ata7.00: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
[904916.169367] ata7.01: exception Emask 0x100 SAct 0x1 SErr 0x0 action 0x6 frozen
[904916.169411] ata7.01: failed command: WRITE FPDMA QUEUED
[904916.169440] ata7.01: cmd 61/88:00:b7:e4:2e/03:00:4e:00:00/40 tag 0 ncq 462848 out
[904916.169440]          res 90/7c:00:00:00:00/00:00:00:00:90/00 Emask 0x2 (HSM violation)
[904916.169530] ata7.01: status: { Busy }
[904916.169554] ata7.01: error: { UNC IDNF ABRT }
[904916.169579] ata7.02: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
[904916.169623] ata7.03: exception Emask 0x10 SAct 0x4 SErr 0x0 action 0x6 frozen
[904916.169667] ata7.03: irq_stat 0x01060002, failed to transmit command FIS
[904916.169696] ata7.03: failed command: WRITE FPDMA QUEUED
[904916.169724] ata7.03: cmd 61/88:10:b7:e4:2e/03:00:4e:00:00/40 tag 2 ncq 462848 out
[904916.169725]          res 90/7c:00:00:00:00/00:00:c0:21:90/00 Emask 0x12 (ATA bus error)
[904916.169811] ata7.03: status: { Busy }
[904916.169834] ata7.03: error: { UNC IDNF ABRT }
[904916.169859] ata7.04: exception Emask 0x100 SAct 0x0 SErr 0x0 action 0x6 frozen
[904916.169904] ata7.15: hard resetting link
[904916.169927] ata7: controller in dubious state, performing PORT_RST
[904918.396264] ata7.15: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
[904918.396666] ata7.00: hard resetting link
[904918.731825] ata7.00: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[904918.731902] ata7.01: hard resetting link
[904919.067090] ata7.01: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[904919.067170] ata7.02: hard resetting link
[904919.402343] ata7.02: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[904919.402420] ata7.03: hard resetting link
[904919.753567] ata7.03: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[904919.753649] ata7.04: hard resetting link
[904920.104789] ata7.04: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[904920.105952] ata7.00: configured for UDMA/100
[904920.118162] ata7.01: configured for UDMA/100
[904920.130177] ata7.02: configured for UDMA/100
[904920.138029] ata7.03: configured for UDMA/100
[904920.145862] ata7.04: configured for UDMA/100
[904920.145997] ata7: EH complete

This is the frequency:

root@ante:~# dmesg|grep "ata7: EH complete"
[409984.923590] ata7: EH complete
[415032.569957] ata7: EH complete
[420312.071009] ata7: EH complete
[421192.345587] ata7: EH complete
[875586.406464] ata7: EH complete
[904920.145997] ata7: EH complete

Questions:
- Is this a problem? Nothing looks wrong at the server, everything works as expected, but I receive a page from time time because of this error.
- Is there a way to keep the ata7 port down? Kind of disable it.
- Is this the way to deal with this problem?

Thanks a lot in advance,
Sebastian

Are you sure ata7 is an unused port? I'm pretty sure there must be a drive on that port and it's throwing errors on writes. Can you post the full dmesg log?

I am sorry, my mailer sent it on html. Resending on plain text.

-------- Original Message --------
Subject: Re: sil3132 eSATA problem
Date: Thu, 16 Feb 2012 01:55:11 -0300
From: Sebastian Muniz <[email protected]>
To: Robert Hancock <[email protected]>
CC: [email protected]

Hello Robert,
Indeed I am sure.
The lsscsi output says so:

root@ante:~# lsscsi -l
[0:0:0:0]    disk    ATA      HUA722050CLA330  JP2O  /dev/sda
  state=running queue_depth=31 scsi_level=6 type=0 device_blocked=0 
timeout=30
[4:0:0:0]    cd/dvd  TSSTcorp DVD-ROM TS-H353C LE01  /dev/sr0
  state=running queue_depth=1 scsi_level=6 type=5 device_blocked=0 
timeout=30
[6:0:0:0]    disk    ATA      WDC WD20EARS-00S 0957  /dev/sdb
  state=running queue_depth=1 scsi_level=6 type=0 device_blocked=0 
timeout=30
[6:1:0:0]    disk    ATA      WDC WD20EARS-00S 80.0  /dev/sdc
  state=running queue_depth=31 scsi_level=6 type=0 device_blocked=0 
timeout=30
[6:2:0:0]    disk    ATA      WDC WD20EARS-00S 80.0  /dev/sdd
  state=running queue_depth=31 scsi_level=6 type=0 device_blocked=0 
timeout=30
[6:3:0:0]    disk    ATA      WDC WD20EARS-00M 51.0  /dev/sde
  state=running queue_depth=31 scsi_level=6 type=0 device_blocked=0 
timeout=30
[6:4:0:0]    disk    ATA      WDC WD20EARS-00M 51.0  /dev/sdf
  state=running queue_depth=31 scsi_level=6 type=0 device_blocked=0 
timeout=30
root@ante:~#
Physically there is only one used port.
dmesg at:
http://pastebin.com/cJwKbPA9
Relevant parts I can see:
Ouch! you are correct!
Ata7 is scsi6 that is where the disks are connected!

1.

   [    2.953688] sata_sil24 0000:10:00.0: version 1.1
2.
   [    2.953702] sata_sil24 0000:10:00.0: PCI->APIC IRQ transform: INT
   A -> IRQ 18
3.
   [    2.953835] sata_sil24 0000:10:00.0: setting latency timer to 64
4. [    2.990750] scsi6 : sata_sil24
5.
   [    3.022360] scsi7 : sata_sil24
6.
   [    3.022455] ata7: SATA max UDMA/100 host m128@0x91b04000 port
   0x91b00000 irq 18
7.
   [    3.022554] ata8: SATA max UDMA/100 host m128@0x91b04000 port
   0x91b02000 irq 18
8.
   [    5.217790] ata7: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
9.
   [    5.218248] ata7.15: Port Multiplier 1.2, 0x197b:0x0325 r0, 5
   ports, feat 0x5/0xf
10.
   [    5.218670] ata7.00: hard resetting link
11.
   [    5.553352] ata7.00: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
12.
   [    5.553493] ata7.01: hard resetting link
13.
   [    5.888613] ata7.01: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
14.
   [    5.888753] ata7.02: hard resetting link
15.
   [    6.335621] ata7.02: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
16.
   [    6.335761] ata7.03: hard resetting link
17.
   [    6.782634] ata7.03: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
18.
   [    6.782776] ata7.04: hard resetting link
19.
   [    7.245612] ata7.04: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
20.
   [    7.246217] ata7.00: ATA-7: WDC WD20EARS-00S8B1, 0957, max UDMA/133
21.
   [    7.246303] ata7.00: 3907029168 sectors, multi 1: LBA48
22.
   [    7.246930] ata7.00: configured for UDMA/100
23.
   [    7.250620] ata7.01: ATA-8: WDC WD20EARS-00S8B1, 80.00A80, max
   UDMA/133
24.
   [    7.250711] ata7.01: 3907029168 sectors, multi 0: LBA48 NCQ
   (depth 31/32)
25.
   [    7.254637] ata7.01: configured for UDMA/100
26.
   [    7.258461] ata7.02: ATA-8: WDC WD20EARS-00S8B1, 80.00A80, max
   UDMA/133
27.
   [    7.258550] ata7.02: 3907029168 sectors, multi 0: LBA48 NCQ
   (depth 31/32)
28.
   [    7.262478] ata7.02: configured for UDMA/100
29.
   [    7.265427] ata7.03: ATA-8: WDC WD20EARS-00MVWB0, 51.0AB51, max
   UDMA/133
30.
   [    7.265517] ata7.03: 3907029168 sectors, multi 0: LBA48 NCQ
   (depth 31/32)
31.
   [    7.269402] ata7.03: configured for UDMA/100
32.
   [    7.272915] ata7.04: ATA-8: WDC WD20EARS-00MVWB0, 51.0AB51, max
   UDMA/133
33.
   [    7.273004] ata7.04: 3907029168 sectors, multi 0: LBA48 NCQ
   (depth 31/32)
34.
   [    7.276599] ata7.04: configured for UDMA/100
35.
   [    7.276783] ata7: EH complete

36. [ 9.352622] ata8: SATA link down (SStatus 0 SControl 0)

So I am in trouble here.
I have downloaded, configured and I am ready to install Linux-3.2.4 if that might help.

Thanks in advance.
Sebastian

Looking at the output a bit more closely, it seems a bit strange. The controller is reporting failures to send a command FIS, and also supposedly seeing uncorrectable errors from the drive. You could try a later kernel but I suspect this may be some kind of hardware issue. Maybe some kind of SATA cable problem?

You might be true, since it is reporting on all the drives.
I will replace the cable, and report back.
Btw, I need to check why but it looks as if an add on PCI ethernet card is having some IRQ issues. The server freezes for 4 seconds and works for 10 more, and so on.
Unloading the module makes the problem go away.
But maybe there is other problem at the bus.
I wanted to make sure there is nothing too obvious from the software side before going on site to check.

Thanks in advance
Sebastian