Fwd: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

Fwd: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Rodrigo Severo]

Hi,


I have this cheap SATA addon card with an ULI chipset.

A have a linear raid over 3 disks one PATA, hda and two SATAs, sda and sdb.

When copying data to the raid device I get log messages like the following:

Apr 15 10:54:20 [kernel] ata1.00: exception Emask 0x0 SAct 0x0 SErr
0x0 action 0x2 frozen
Apr 15 10:54:20 [kernel] ata1.00: cmd
35/00:00:df:90:0e/00:04:0b:00:00/e0 tag 0 cdb 0x0 data 524288 out
Apr 15 10:54:20 [kernel]          res
40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
Apr 15 10:54:27 [kernel] ata1: port is slow to respond, please be
patient (Status 0xd0)
Apr 15 10:54:48 [kernel] ata1: port failed to respond (30 secs, Status 0xd0)
Apr 15 10:54:48 [kernel] ata1: soft resetting port
Apr 15 10:54:48 [kernel] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Apr 15 10:54:48 [kernel] ATA: abnormal status 0xD0 on port 0x9007
                - Last output repeated 6 times -
Apr 15 10:54:48 [kernel] ata1.00: configured for UDMA/133
Apr 15 10:54:48 [kernel] ata1: EH complete
Apr 15 10:54:48 [kernel] SCSI device sda: 488397168 512-byte hdwr
sectors (250059 MB)
Apr 15 10:54:48 [kernel] sda: Write Protect is off
Apr 15 10:54:48 [kernel] SCSI device sda: write cache: enabled, read
cache: enabled, doesn't support DPO or FUA

All references I found to this kind of message where related to some
driver issue and not hardware problems. Can this be the case?

Some extra info on my system:

kernel:
Linux version 2.6.20.7 (root@cameron) (gcc version 4.1.1 (Gentoo
4.1.1-r3)) #1 Sun Apr 15 10:23:37 BRT 2007

lspci:
01:07.0 Mass storage controller: ALi Corporation ALi M5281 Serial ATA
/ RAID Host Controller (rev a1)
01:07.1 Mass storage controller: ALi Corporation M5228 ALi ATA/RAID
Controller (rev c6)

dmesg:
sata_uli 0000:01:07.0: version 1.0
ACPI: PCI Interrupt Link [APC4] enabled at IRQ 19
ACPI: PCI Interrupt 0000:01:07.0[A] -> Link [APC4] -> GSI 19 (level,
high) -> IRQ 16
ata1: SATA max UDMA/133 cmd 0x9000 ctl 0x9402 bmdma 0xA000 irq 16
ata2: SATA max UDMA/133 cmd 0x9800 ctl 0x9C02 bmdma 0xA008 irq 16
scsi0 : sata_uli
ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata1.00: ATA-7, max UDMA/133, 488397168 sectors: LBA48 NCQ (depth 0/32)
ata1.00: configured for UDMA/133
scsi1 : sata_uli
ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata2.00: ATA-7, max UDMA/133, 586114704 sectors: LBA48 NCQ (depth 0/32)
ata2.00: ata2: dev 0 multi count 0
ata2.00: configured for UDMA/133
scsi 0:0:0:0: Direct-Access     ATA      ST3250820AS      3.AA PQ: 0 ANSI: 5
SCSI device sda: 488397168 512-byte hdwr sectors (250059 MB)
sda: Write Protect is off
sda: Mode Sense: 00 3a 00 00
SCSI device sda: write cache: enabled, read cache: enabled, doesn't
support DPO or FUA
SCSI device sda: 488397168 512-byte hdwr sectors (250059 MB)
sda: Write Protect is off
sda: Mode Sense: 00 3a 00 00
SCSI device sda: write cache: enabled, read cache: enabled, doesn't
support DPO or FUA
 sda: sda1
sd 0:0:0:0: Attached scsi disk sda
scsi 1:0:0:0: Direct-Access     ATA      Maxtor 6L300S0   BACE PQ: 0 ANSI: 5
SCSI device sdb: 586114704 512-byte hdwr sectors (300091 MB)
sdb: Write Protect is off
sdb: Mode Sense: 00 3a 00 00
SCSI device sdb: write cache: enabled, read cache: enabled, doesn't
support DPO or FUA
SCSI device sdb: 586114704 512-byte hdwr sectors (300091 MB)
sdb: Write Protect is off
sdb: Mode Sense: 00 3a 00 00
SCSI device sdb: write cache: enabled, read cache: enabled, doesn't
support DPO or FUA
 sdb: sdb1
sd 1:0:0:0: Attached scsi disk sdb

Please let me know if there is any extra info or tests necessary.


Regards,

Rodrigo Severo

Re: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Rodrigo Severo]

On 4/15/07, Rodrigo Severo <rodrigo@fabricadeideias.com> wrote:
>
> I have this cheap SATA addon card with an ULI chipset.
>
> A have a linear raid over 3 disks one PATA, hda and two SATAs, sda and sdb.
>
> When copying data to the raid device I get log messages like the following:
>
> Apr 15 10:54:20 [kernel] ata1.00: exception Emask 0x0 SAct 0x0 SErr
> 0x0 action 0x2 frozen
> Apr 15 10:54:20 [kernel] ata1.00: cmd
> 35/00:00:df:90:0e/00:04:0b:00:00/e0 tag 0 cdb 0x0 data 524288 out
> Apr 15 10:54:20 [kernel]          res
> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> Apr 15 10:54:27 [kernel] ata1: port is slow to respond, please be
> patient (Status 0xd0)
> Apr 15 10:54:48 [kernel] ata1: port failed to respond (30 secs, Status 0xd0)
> Apr 15 10:54:48 [kernel] ata1: soft resetting port
> Apr 15 10:54:48 [kernel] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> Apr 15 10:54:48 [kernel] ATA: abnormal status 0xD0 on port 0x9007
>                 - Last output repeated 6 times -
> Apr 15 10:54:48 [kernel] ata1.00: configured for UDMA/133
> Apr 15 10:54:48 [kernel] ata1: EH complete
> Apr 15 10:54:48 [kernel] SCSI device sda: 488397168 512-byte hdwr
> sectors (250059 MB)
> Apr 15 10:54:48 [kernel] sda: Write Protect is off
> Apr 15 10:54:48 [kernel] SCSI device sda: write cache: enabled, read
> cache: enabled, doesn't support DPO or FUA
>
> All references I found to this kind of message where related to some
> driver issue and not hardware problems. Can this be the case?

In search for a solution for this issue I bought a new HD to replace
the one presenting the problem above.

Now I have a SAMSUNG HD400LJ in place of the previous ST3250820AS. The
problem remains the same.

When I put a Maxtor 6L300S0 to perform the same hole as the Samsung or
the Seagate, I couldn't trigger the exception. I bet this happened
because Maxtor is immune to this issue and the Samsung (which seems to
be affected) was barely used.

I'm really out of ideas where to look for an explanation or fix. I
don't think I'm dealing with a hardware issue.

What should be my next step?


Regards,

Rodrigo Severo

Re: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Rodrigo Severo]

On 4/16/07, Rodrigo Severo <rodrigo@fabricadeideias.com> wrote:
> On 4/15/07, Rodrigo Severo <rodrigo@fabricadeideias.com> wrote:
> >
> > I have this cheap SATA addon card with an ULI chipset.
> >
> > A have a linear raid over 3 disks one PATA, hda and two SATAs, sda and sdb.
> >
> > When copying data to the raid device I get log messages like the following:
> >
> > Apr 15 10:54:20 [kernel] ata1.00: exception Emask 0x0 SAct 0x0 SErr
> > 0x0 action 0x2 frozen
> > Apr 15 10:54:20 [kernel] ata1.00: cmd
> > 35/00:00:df:90:0e/00:04:0b:00:00/e0 tag 0 cdb 0x0 data 524288 out
> > Apr 15 10:54:20 [kernel]          res
> > 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> > Apr 15 10:54:27 [kernel] ata1: port is slow to respond, please be
> > patient (Status 0xd0)
> > Apr 15 10:54:48 [kernel] ata1: port failed to respond (30 secs, Status 0xd0)
> > Apr 15 10:54:48 [kernel] ata1: soft resetting port
> > Apr 15 10:54:48 [kernel] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> > Apr 15 10:54:48 [kernel] ATA: abnormal status 0xD0 on port 0x9007
> >                 - Last output repeated 6 times -
> > Apr 15 10:54:48 [kernel] ata1.00: configured for UDMA/133
> > Apr 15 10:54:48 [kernel] ata1: EH complete
> > Apr 15 10:54:48 [kernel] SCSI device sda: 488397168 512-byte hdwr
> > sectors (250059 MB)
> > Apr 15 10:54:48 [kernel] sda: Write Protect is off
> > Apr 15 10:54:48 [kernel] SCSI device sda: write cache: enabled, read
> > cache: enabled, doesn't support DPO or FUA
> >
> > All references I found to this kind of message where related to some
> > driver issue and not hardware problems. Can this be the case?
>
> In search for a solution for this issue I bought a new HD to replace
> the one presenting the problem above.
>
> Now I have a SAMSUNG HD400LJ in place of the previous ST3250820AS. The
> problem remains the same.
>
> When I put a Maxtor 6L300S0 to perform the same hole as the Samsung or
> the Seagate, I couldn't trigger the exception. I bet this happened
> because Maxtor is immune to this issue and the Samsung (which seems to
> be affected) was barely used.

Now with kernel 2.6.21-rc6, addon board reattached and cables changed
I still get messages like the following every 10 minutes or so under
high load:

Apr 16 13:03:27 [kernel] ata1.00: exception Emask 0x0 SAct 0x0 SErr
0x0 action 0x2 frozen
Apr 16 13:03:27 [kernel] ata1.00: cmd
35/00:00:91:fd:06/00:04:0b:00:00/e0 tag 0 cdb 0x0 data 524288 out
Apr 16 13:03:27 [kernel]          res
40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
Apr 16 13:03:35 [kernel] ata1: port is slow to respond, please be
patient (Status 0xd0)
Apr 16 13:03:58 [kernel] ata1: port failed to respond (30 secs, Status 0xd0)
Apr 16 13:03:58 [kernel] ata1: soft resetting port
Apr 16 13:03:58 [kernel] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Apr 16 13:03:58 [kernel] ata1.00: configured for UDMA/133
Apr 16 13:03:58 [kernel] ata1: EH complete
Apr 16 13:03:58 [kernel] SCSI device sda: 781422768 512-byte hdwr
sectors (400088 MB)
Apr 16 13:03:58 [kernel] sda: Write Protect is off
Apr 16 13:03:58 [kernel] SCSI device sda: write cache: enabled, read
cache: enabled, doesn't support DPO or FUA

Is this expected behavior?


Rodrigo Severo

Re: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Tejun Heo]

Rodrigo Severo wrote:
> Now with kernel 2.6.21-rc6, addon board reattached and cables changed
> I still get messages like the following every 10 minutes or so under
> high load:
> 
> Apr 16 13:03:27 [kernel] ata1.00: exception Emask 0x0 SAct 0x0 SErr
> 0x0 action 0x2 frozen
> Apr 16 13:03:27 [kernel] ata1.00: cmd
> 35/00:00:91:fd:06/00:04:0b:00:00/e0 tag 0 cdb 0x0 data 524288 out
> Apr 16 13:03:27 [kernel]          res
> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
> Apr 16 13:03:35 [kernel] ata1: port is slow to respond, please be
> patient (Status 0xd0)
> Apr 16 13:03:58 [kernel] ata1: port failed to respond (30 secs, Status
> 0xd0)
> Apr 16 13:03:58 [kernel] ata1: soft resetting port
> Apr 16 13:03:58 [kernel] ata1: SATA link up 1.5 Gbps (SStatus 113
> SControl 300)
> Apr 16 13:03:58 [kernel] ata1.00: configured for UDMA/133
> Apr 16 13:03:58 [kernel] ata1: EH complete
> Apr 16 13:03:58 [kernel] SCSI device sda: 781422768 512-byte hdwr
> sectors (400088 MB)
> Apr 16 13:03:58 [kernel] sda: Write Protect is off
> Apr 16 13:03:58 [kernel] SCSI device sda: write cache: enabled, read
> cache: enabled, doesn't support DPO or FUA
> 
> Is this expected behavior?

Certainly not.  Can you post the result of 'smartctl -d ata -a /dev/sdX'?

-- 
tejun

Re: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Rodrigo Severo]

On 4/17/07, Tejun Heo <htejun@gmail.com> wrote:
> Certainly not.  Can you post the result of 'smartctl -d ata -a /dev/sdX'?

Here is smartctl -d ata -a /dev/sda for the same HD that presented the
previous log messages:
-----------------------------------------------------------------------------------------------------
smartctl version 5.36 [i686-pc-linux-gnu] Copyright (C) 2002-6 Bruce Allen
Home page is http://smartmontools.sourceforge.net/

=== START OF INFORMATION SECTION ===
Device Model:     SAMSUNG HD400LJ
Serial Number:    S0H2J1UL602108
Firmware Version: ZZ100-14
User Capacity:    400,088,457,216 bytes
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   7
ATA Standard is:  ATA/ATAPI-7 T13 1532D revision 4a
Local Time is:    Tue Apr 17 14:20:20 2007 BRT

==> WARNING: May need -F samsung or -F samsung2 enabled; see manual for details.

SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED

General SMART Values:
Offline data collection status:  (0x00)	Offline data collection activity
					was never started.
					Auto Offline Data Collection: Disabled.
Self-test execution status:      (   0)	The previous self-test routine completed
					without error or no self-test has ever
					been run.
Total time to complete Offline
data collection: 		 (7576) seconds.
Offline data collection
capabilities: 			 (0x5b) SMART execute Offline immediate.
					Auto Offline data collection on/off support.
					Suspend Offline collection upon new
					command.
					Offline surface scan supported.
					Self-test supported.
					No Conveyance Self-test supported.
					Selective Self-test supported.
SMART capabilities:            (0x0003)	Saves SMART data before entering
					power-saving mode.
					Supports SMART auto save timer.
Error logging capability:        (0x01)	Error logging supported.
					General Purpose Logging supported.
Short self-test routine
recommended polling time: 	 (   2) minutes.
Extended self-test routine
recommended polling time: 	 ( 129) minutes.

SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE
UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x000f   100   100   051    Pre-fail
Always       -       0
  3 Spin_Up_Time            0x0007   100   100   015    Pre-fail
Always       -       7936
  4 Start_Stop_Count        0x0032   100   100   000    Old_age
Always       -       8
  5 Reallocated_Sector_Ct   0x0033   253   253   010    Pre-fail
Always       -       0
  7 Seek_Error_Rate         0x000f   253   253   051    Pre-fail
Always       -       0
  8 Seek_Time_Performance   0x0025   253   253   015    Pre-fail
Offline      -       0
  9 Power_On_Hours          0x0032   253   253   000    Old_age
Always       -       16
 10 Spin_Retry_Count        0x0033   253   253   051    Pre-fail
Always       -       0
 11 Calibration_Retry_Count 0x0012   253   253   000    Old_age
Always       -       0
 12 Power_Cycle_Count       0x0032   100   100   000    Old_age
Always       -       8
190 Unknown_Attribute       0x0022   061   060   000    Old_age
Always       -       39
194 Temperature_Celsius     0x0022   121   118   000    Old_age
Always       -       39
195 Hardware_ECC_Recovered  0x001a   100   100   000    Old_age
Always       -       507637
196 Reallocated_Event_Count 0x0032   253   253   000    Old_age
Always       -       0
197 Current_Pending_Sector  0x0012   253   253   000    Old_age
Always       -       0
198 Offline_Uncorrectable   0x0030   253   253   000    Old_age
Offline      -       0
199 UDMA_CRC_Error_Count    0x003e   200   200   000    Old_age
Always       -       0
200 Multi_Zone_Error_Rate   0x000a   100   100   000    Old_age
Always       -       0
201 Soft_Read_Error_Rate    0x000a   253   253   000    Old_age
Always       -       0
202 TA_Increase_Count       0x0032   253   253   000    Old_age
Always       -       0

SMART Error Log Version: 1
No Errors Logged

SMART Self-test log structure revision number 1
No self-tests have been logged.  [To run self-tests, use: smartctl -t]


SMART Selective Self-Test Log Data Structure Revision Number (0) should be 1
SMART Selective self-test log data structure revision number 0
Warning: ATA Specification requires selective self-test log data
structure revision number = 1
 SPAN  MIN_LBA  MAX_LBA  CURRENT_TEST_STATUS
    1        0        0  Not_testing
    2        0        0  Not_testing
    3        0        0  Not_testing
    4        0        0  Not_testing
    5        0        0  Not_testing
Selective self-test flags (0x0):
  After scanning selected spans, do NOT read-scan remainder of disk.
If Selective self-test is pending on power-up, resume after 0 minute delay.
-----------------------------------------------------------------------------------------------------

I bought a new SATA board this morning. lspci -v:
-----------------------------------------------------------------------------------------------------
01:07.0 RAID bus controller: VIA Technologies, Inc. VT6421 IDE RAID
Controller (rev 50)
        Subsystem: VIA Technologies, Inc. VT6421 IDE RAID Controller
        Flags: bus master, medium devsel, latency 32, IRQ 16
        I/O ports at c000 [size=16]
        I/O ports at c400 [size=16]
        I/O ports at c800 [size=16]
        I/O ports at cc00 [size=16]
        I/O ports at d000 [size=32]
        I/O ports at d400 [size=256]
        [virtual] Expansion ROM at 30040000 [disabled] [size=64K]
        Capabilities: [e0] Power Management version 2
-----------------------------------------------------------------------------------------------------

This is the SATA board running now. Everything else is exactly the
same. I got no syslog messages after rsyncing 255GB.

I believe the smartctl output is still valid despite having other SATA board.

Please let me know if there is anything else I can do to help debug this issue.

I can put the ULi M5281/M5283 back for tests.


Thanks for your attention,

Rodrigo Severo

Re: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Tejun Heo]

Rodrigo Severo wrote:
> SMART Error Log Version: 1
> No Errors Logged

It seemed like a transmission problem so I was hoping the drive's SMART
log recorded something.  Apparently not.  :-(

> This is the SATA board running now. Everything else is exactly the
> same. I got no syslog messages after rsyncing 255GB.
> 
> I believe the smartctl output is still valid despite having other SATA
> board.

Yeap, it's valid.

> Please let me know if there is anything else I can do to help debug this
> issue.
> 
> I can put the ULi M5281/M5283 back for tests.

ULi SATA is a fairly standard controller and the driver doesn't do much
other than feeding IO addresses to generic ATA layer, so there's nothing
much to go wrong there.  It might be a genuine hardware problem on the
controller side or driver missing some undocumented magic tweaks.  I
think the former is more likely.

Occasional errors should be okay.  libata EH can recover most conditions
and there won't be any data integrity problem.  Too long timeout (30s)
can be a problem tho.

Unfortunately, I don't think we have much to go on here.  Both SError
register and SMART log aren't reporting anything useful.  :-(

-- 
tejun

Re: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Rodrigo Severo]

On 4/17/07, Tejun Heo <htejun@gmail.com> wrote:
> Rodrigo Severo wrote:
> > Please let me know if there is anything else I can do to help debug this
> > issue.
> >
> > I can put the ULi M5281/M5283 back for tests.
>
> ULi SATA is a fairly standard controller and the driver doesn't do much
> other than feeding IO addresses to generic ATA layer, so there's nothing
> much to go wrong there.  It might be a genuine hardware problem on the
> controller side or driver missing some undocumented magic tweaks.  I
> think the former is more likely.
>
> Occasional errors should be okay.  libata EH can recover most conditions
> and there won't be any data integrity problem.  Too long timeout (30s)
> can be a problem tho.
>
> Unfortunately, I don't think we have much to go on here.  Both SError
> register and SMART log aren't reporting anything useful.  :-(

I have another ULi M5281/M5283 at home. I can bring it to work and try
to reproduce this issue. Interested?

BTW lspci mentions a M5281 but the chipset is marked M5283. Is this ok?


Regards,

Rodrigo Severo

Re: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Tejun Heo]

Rodrigo Severo wrote:
> I have another ULi M5281/M5283 at home. I can bring it to work and try
> to reproduce this issue. Interested?

Yeap, that will tell us whether the specific card is busted or not.

> BTW lspci mentions a M5281 but the chipset is marked M5283. Is this ok?

Yeap, that's okay.

-- 
tejun

Re: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Rodrigo Severo]

On 4/17/07, Tejun Heo <htejun@gmail.com> wrote:
> Rodrigo Severo wrote:
> > I have another ULi M5281/M5283 at home. I can bring it to work and try
> > to reproduce this issue. Interested?
>
> Yeap, that will tell us whether the specific card is busted or not.

I expect to have news tomorrow.


Thanks again for your attention,

Rodrigo Severo

Re: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen on SATA hd

[Rodrigo Severo]

On 4/17/07, Rodrigo Severo <rodrigo@fabricadeideias.com> wrote:
> On 4/17/07, Tejun Heo <htejun@gmail.com> wrote:
> > Rodrigo Severo wrote:
> > > I have another ULi M5281/M5283 at home. I can bring it to work and try
> > > to reproduce this issue. Interested?
> >
> > Yeap, that will tell us whether the specific card is busted or not.

The card is busted. I tried to reinstall it now just to see the syslog
messages again before testing the other ULi board.

It isn't recognized anymore. It's completely dead now.


Thanks for your help,

Rodrigo Severo