Re: XFS shutting down due to IO timeout on SATA disk (pata_via for CX700)

Previous thread: Strange looking line from "ps aux" by Rogério on Thursday, September 11, 2008 - 10:43 am. (1 message)

Next thread: Re: [PATCH 1/2] audit: fix NUL handling in untrusted strings by Miloslav on Thursday, September 11, 2008 - 11:10 am. (3 messages)
From: Bruno
Date: Thursday, September 11, 2008 - 10:35 am

Since some time one of my systems "freezes" after limited uptime (a few hours), usually
during package compilation process.
This seems to happen only with recent kernel versions (2.6.27-rc*), don't remember if
it also happened with 2.6.26 (though I'm pretty sure it did not happen with early
2.6.2x series)

Unfortunately this always shutdowns the root filesystem rendering system unusable.

The kernel output below was generated by 2.6.27-rc5-git9, same symptoms happened with
other -rc releases of 2.6.27 though I couldn't look at dmesg because it happens to /
and I only enabled networked syslog pretty recently on that box in order to find out
what happens.

Unfortunately either the chipset or the BIOS do not support AHCI, for the SATA
controller as the only choice for SATA offered by BIOS is: IDE.


Is this a known issue? At least there seem to be similar ATA exceptions happening
lately according to search results returned by google when looking for the error
messages (exception and originating command).


-- improvement suggestion --
To keep the system running it would be nice if the failing command could be re-issued
after resetting the link and rediscovering the drive, that is, pushing the error to
upper layers only after new failure when retrying the operation following the reset.
-- end of suggestion --

If kernel config or complete output of dmesg is of some help, please let me know.

In case there are some tuning options to try in order to pinpoint the cause I can try
them out, that system is not in production use. (according to some of the messages I
found it could be related to drive cache flushing)

Bruno


lspci output:
00:00.0 Host bridge [0600]: VIA Technologies, Inc. CX700 Host Bridge [1106:0324] (rev 03)
00:00.1 Host bridge [0600]: VIA Technologies, Inc. CX700 Host Bridge [1106:1324]
00:00.2 Host bridge [0600]: VIA Technologies, Inc. CX700 Host Bridge [1106:2324]
00:00.3 Host bridge [0600]: VIA Technologies, Inc. CX700 Host Bridge [1106:3324]
00:00.4 Host ...
From: Tejun Heo
Date: Monday, September 15, 2008 - 1:55 am

(please try to wrap paragraphs for 80 column)

Hello,


Timeout on FLUSH_EXT.  That's a bad sign.  Patch to retry FLUSH is
pending but at any rate FLUSH failure is often accompanied by loss of
data and XFS is doing the right thing of giving up on it.

Can you please post the result of "smartctl -a /dev/sda"?

-- 
tejun
--

From: Bruno
Date: Monday, September 15, 2008 - 10:02 am

Hello,

I try not to break lines from dmesg, lspci and and other commands'
(formatted) output as those tend to get pretty hard to read when
line-wrapped.
I checked it though there were no errors logged nor any other information
that would catch attention. The disk/machine is pretty unused (a year old
but low uptime, a few hours those days with uptime)

Anyhow smaprtctl's output is blow.

Bruno



smartctl version 5.38 [i686-pc-linux-gnu] Copyright (C) 2002-8 Bruce Allen
Home page is http://smartmontools.sourceforge.net/

=== START OF INFORMATION SECTION ===
Device Model:     FUJITSU MHY2250BH
Serial Number:    K407T7A25THF
Firmware Version: 0000000B
User Capacity:    250,059,350,016 bytes
Device is:        Not in smartctl database [for details use: -P showall]
ATA Version is:   8
ATA Standard is:  ATA-8-ACS revision 3f
Local Time is:    Mon Sep 15 18:52:53 2008 CEST
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:                 (1009) seconds.
Offline data collection
capabilities:                    (0x7b) SMART execute Offline immediate.
                                        Auto Offline data collection on/off support.
                                        Suspend Offline collection upon new
                                        command.
                                        Offline surface scan supported.
                            ...
From: Tejun Heo
Date: Monday, September 15, 2008 - 1:43 pm

Hello,


Yeap, I was talking only about the text.  Not wrapping outputs and

Whee... That's unusally high realloc count but I'm not sure whether it
indicates actual problem or it's just the drive's way of saying I'm

Hmmm.. Do you happen to have drives of the same model?  If so, can you
please check what other drives are reporting?

Thanks.

-- 
tejun
--

From: Bruno
Date: Tuesday, September 16, 2008 - 1:21 am

Hello,

I don't have other drives of the same model, but 3 ones slightly smaller
in size and previous generation, those are just a few months older (but
also have way more uptime), see below for the smartctl output. I've never
seen ATA errors on them.
These other drives are running on AMD based platform, SB600 SATA with AHCI.


Just for the record, on the VIA there were no errors yet with
2.6.27-rc6-git3 though I ran some compiling on it. As such it *could* be
that one of the patches pushed by Jeff helped:
  [libata] LBA28/LBA48 off-by-one bug in ata.h
  sata_inic162x: enable LED blinking
  ata: duplicate variable sparse warning

Bruno


=============== first drive ====================
smartctl version 5.38 [x86_64-pc-linux-gnu] Copyright (C) 2002-8 Bruce Allen
Home page is http://smartmontools.sourceforge.net/

=== START OF INFORMATION SECTION ===
Model Family:     Fujitsu MHW2 BH
Device Model:     FUJITSU MHW2160BH
Serial Number:    K102T7727YER
Firmware Version: 0000001C
User Capacity:    160,041,885,696 bytes
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   8
ATA Standard is:  ATA-8-ACS revision 3b
Local Time is:    Tue Sep 16 09:50:34 2008 CEST
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:                 ( 649) seconds.
Offline data collection
capabilities:                    (0x7b) SMART execute ...
From: Tejun Heo
Date: Tuesday, September 16, 2008 - 10:35 am

Hello,



The only patch which could have affected the result is the off-by-one
one; however, FLUSH timeout is a bit unexpected failure mode for the
problem.  Can you please keep the system running for a whlie and see
whether the problem occurs?

Thanks.

-- 
tejun
--

From: Bruno
Date: Sunday, September 21, 2008 - 12:51 pm

Hello,


I haven't seen the error happen yet with 2.6.27-rc6-git3, so that off
by one bug might have had an incidence.
No warranty on that as I did also slightly change power-saving settings
for the disk around the time I updated kernel (-B254, -S241 parameters
to hdparm) and have not seen the error yet on 2.6.27-rc5-git9 since
then.

Will do more testing as time permits over the next days and report if I
find anything that looks useful (e.g. better way than time to trigger
the error or some of the hdparm options influencing the probability)

In case there is a patch that would eventually be able to get more info
when the error occurs I would be happy to apply it.

Bruno
--

From: Grant Grundler
Date: Tuesday, September 16, 2008 - 8:07 am

On Mon, Sep 15, 2008 at 1:43 PM, Tejun Heo <tj@kernel.org> wrote:

The "raw" values are "vendor defined".
Often the 6 bytes of raw data are split up into  1 or 2 byte wide fields.

Any volunteers to submit a patch to smartmontools to dump
"raw values" as hexidecimal by default?


441778176 == 0x1a550000

Need to see if the vendor will provide documentation to decode these values.

AFAICT, it's not safe to directly compare raw values between vendors since
the raw values don't mean exactly the same thing (e.g. more aggressive retries
might result in few reallocations.)

hth,
--

From: Mark Lord
Date: Monday, September 15, 2008 - 1:30 pm

..

Bruno, please also post the output from these commands:

   hdparm --Istdout /dev/sda
   smartctl -data -a /dev/sda

..

Tejun, are we *sure* that's really a timeout?
The status shows 0x40 "drive ready" there, aka. "command complete". 

I have a client who is also seeing this exact scenario on 750GB drives,
using a patched SLES10 kernel (2.6.16 + libata from 2.6.18 or so).

Smartctl output is clean (no logged errors), and the drives themselves
are fine after a reboot -- necessary since libata/scsi kicked the drive out
of the RAID array.

Something strange is going on here.

????
--

From: Tejun Heo
Date: Monday, September 15, 2008 - 1:37 pm

Heh... on timeout, libata EH doesn't touch status register as some
controllers lock the whole machine up on that, so the 0x40 is just the
fill value libata used during qc initialization.  It definitely

Hmm.. most of FLUSH timeouts I've seen are either a dying drive or bad
PSU.  There just isn't much which can go wrong from the driver side.
IIRC, there was a problem when the unused part of TF is not cleared

Any chance you can trick the client to hook up the drive to a separate
PSU?

Thanks.

-- 
tejun
--

From: Mark Lord
Date: Monday, September 15, 2008 - 8:49 pm

..

No, the failures happen randomly at customer sites, and only since they
"upgraded" to SLES10 with libata.  I think the PSUs are probably just fine.

Time to hack the drivers to give proper status on the timeouts, too;
otherwise we won't ever have any clue as to what is really happening.

Cheers
--

Previous thread: Strange looking line from "ps aux" by Rogério on Thursday, September 11, 2008 - 10:43 am. (1 message)

Next thread: Re: [PATCH 1/2] audit: fix NUL handling in untrusted strings by Miloslav on Thursday, September 11, 2008 - 11:10 am. (3 messages)