Re: I/O error on data file, can't run backup

On Thursday 6. October 2011 07.07.11 Craig Ringer wrote:
> On 10/06/2011 03:06 AM, Leif Biberg Kristensen wrote:
> > I seemingly fixed the problem by stopping postgres and doing:
> >
> > balapapa 612249 # mv 11658 11658.old
> > balapapa 612249 # mv 11658.old 11658
> >
> > And the backup magically works.
>
> Woooooo! That's ... "interesting".
>
> I'd be inclined to suspect filesystem corruption, a file system bug /
> kernel bug (not very likely if you're on ext3), flakey RAM, etc rather
> than a failing disk ... though a failing disk _could_ still be the culprit.
>
> Use smartmontools to do a self-test; if 'smartctl -d ata -t long
> /dev/sdx' (where 'x' is the drive node) is reported by 'smartctl -d ata
> -a /dev/sdx' as having passed, there are no pending or uncorrectable
> sectors, and the disk status is reported as 'HEALTHY' your disk is quite
> likely OK. Note that a 'PASSED' or 'HEALTHY' report by its self doesn't
> mean much, disk firmwares often return HEALTHY even when the disk can't
> even read sector 0.
>
> I strongly recommend making a full backup, both a pg_dump *and* a
> file-system level copy of the datadir. Personally I'd then do a test
> restore of the pg_dump backup on a separate Pg instance and if it looked
> OK I'd re-initdb then reload from the dump.

Craig,
Thank you very much for the tip on smartmontools, which I didn't know about.
There indeed appears to be some problems with this disk:

8<---

balapapa ~ # smartctl -d ata -a /dev/sdb -s on
smartctl 5.40 2010-10-16 r3189 [x86_64-pc-linux-gnu] (local build)
Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net

=== START OF INFORMATION SECTION ===
Model Family: Seagate Barracuda 7200.11 family
Device Model: ST31000340AS
Serial Number: 9QJ1ZMHY
Firmware Version: SD15
User Capacity: 1 000 204 886 016 bytes
Device is: In smartctl database [for details use: -P show]
ATA Version is: 8
ATA Standard is: ATA-8-ACS revision 4
Local Time is: Thu Oct 6 07:46:19 2011 CEST

==> WARNING: There are known problems with these drives,
AND THIS FIRMWARE VERSION IS AFFECTED,
see the following Seagate web pages:
http://seagate.custkb.com/seagate/crm/selfservice/search.jsp?DocId=207931
http://seagate.custkb.com/seagate/crm/selfservice/search.jsp?DocId=207951

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

=== START OF ENABLE/DISABLE COMMANDS SECTION ===
SMART Enabled.

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

General SMART Values:
Offline data collection status: (0x82) Offline data collection activity
was completed without error.
Auto Offline Data Collection: Enabled.
Self-test execution status: ( 25) The self-test routine was aborted by
the host.
Total time to complete Offline
data collection: ( 650) 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.
Self-test supported.
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: ( 1) minutes.
Extended self-test routine
recommended polling time: ( 236) minutes.
Conveyance self-test routine
recommended polling time: ( 2) minutes.
SCT capabilities: (0x103b) SCT Status supported.
SCT Error Recovery Control supported.
SCT Feature Control supported.
SCT Data Table supported.

SMART Attributes Data Structure revision number: 10
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 114 099 006 Pre-fail Always
- 61796058
3 Spin_Up_Time 0x0003 094 092 000 Pre-fail Always
- 0
4 Start_Stop_Count 0x0032 100 100 020 Old_age Always
- 46
5 Reallocated_Sector_Ct 0x0033 100 100 036 Pre-fail Always
- 1
7 Seek_Error_Rate 0x000f 045 045 030 Pre-fail Always
- 3848329867033
9 Power_On_Hours 0x0032 076 076 000 Old_age Always
- 21358
10 Spin_Retry_Count 0x0013 100 100 097 Pre-fail Always
- 0
12 Power_Cycle_Count 0x0032 100 100 020 Old_age Always
- 141
184 End-to-End_Error 0x0032 100 100 099 Old_age Always
- 0
187 Reported_Uncorrect 0x0032 016 016 000 Old_age Always
- 84
188 Command_Timeout 0x0032 100 100 000 Old_age Always
- 0
189 High_Fly_Writes 0x003a 100 100 000 Old_age Always
- 0
190 Airflow_Temperature_Cel 0x0022 063 049 045 Old_age Always
- 37 (Min/Max 37/37)
194 Temperature_Celsius 0x0022 037 051 000 Old_age Always
- 37 (0 23 0 0)
195 Hardware_ECC_Recovered 0x001a 018 014 000 Old_age Always
- 61796058
197 Current_Pending_Sector 0x0012 100 100 000 Old_age Always
- 2
198 Offline_Uncorrectable 0x0010 100 100 000 Old_age Offline -
2
199 UDMA_CRC_Error_Count 0x003e 200 200 000 Old_age Always
- 0

SMART Error Log Version: 1
ATA Error Count: 84 (device log contains only the most recent five errors)
CR = Command Register [HEX]
FR = Features Register [HEX]
SC = Sector Count Register [HEX]
SN = Sector Number Register [HEX]
CL = Cylinder Low Register [HEX]
CH = Cylinder High Register [HEX]
DH = Device/Head Register [HEX]
DC = Device Command Register [HEX]
ER = Error register [HEX]
ST = Status register [HEX]
Powered_Up_Time is measured from power on, and printed as
DDd+hh:mm:SS.sss where DD=days, hh=hours, mm=minutes,
SS=sec, and sss=millisec. It "wraps" after 49.710 days.

Error 84 occurred at disk power-on lifetime: 19483 hours (811 days + 19 hours)
When the command that caused the error occurred, the device was active or
idle.

After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
40 51 00 ff ff ff 0f Error: UNC at LBA = 0x0fffffff = 268435455

Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
25 00 08 ff ff ff ef 00 11:02:43.659 READ DMA EXT
27 00 00 00 00 00 e0 00 11:02:43.658 READ NATIVE MAX ADDRESS EXT
ec 00 00 00 00 00 a0 00 11:02:43.638 IDENTIFY DEVICE
ef 03 46 00 00 00 a0 00 11:02:43.619 SET FEATURES [Set transfer mode]
27 00 00 00 00 00 e0 00 11:02:43.558 READ NATIVE MAX ADDRESS EXT

Error 83 occurred at disk power-on lifetime: 19483 hours (811 days + 19 hours)
When the command that caused the error occurred, the device was active or
idle.

After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
40 51 00 ff ff ff 0f Error: UNC at LBA = 0x0fffffff = 268435455

Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
25 00 08 ff ff ff ef 00 11:02:40.589 READ DMA EXT
27 00 00 00 00 00 e0 00 11:02:40.588 READ NATIVE MAX ADDRESS EXT
ec 00 00 00 00 00 a0 00 11:02:40.568 IDENTIFY DEVICE
ef 03 46 00 00 00 a0 00 11:02:40.549 SET FEATURES [Set transfer mode]
27 00 00 00 00 00 e0 00 11:02:40.498 READ NATIVE MAX ADDRESS EXT

Error 82 occurred at disk power-on lifetime: 19483 hours (811 days + 19 hours)
When the command that caused the error occurred, the device was active or
idle.

After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
40 51 00 ff ff ff 0f Error: UNC at LBA = 0x0fffffff = 268435455

Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
25 00 08 ff ff ff ef 00 11:02:37.539 READ DMA EXT
27 00 00 00 00 00 e0 00 11:02:37.538 READ NATIVE MAX ADDRESS EXT
ec 00 00 00 00 00 a0 00 11:02:37.518 IDENTIFY DEVICE
ef 03 46 00 00 00 a0 00 11:02:37.499 SET FEATURES [Set transfer mode]
27 00 00 00 00 00 e0 00 11:02:37.448 READ NATIVE MAX ADDRESS EXT

Error 81 occurred at disk power-on lifetime: 19483 hours (811 days + 19 hours)
When the command that caused the error occurred, the device was active or
idle.

After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
40 51 00 ff ff ff 0f Error: UNC at LBA = 0x0fffffff = 268435455

Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
25 00 08 ff ff ff ef 00 11:02:34.459 READ DMA EXT
27 00 00 00 00 00 e0 00 11:02:34.458 READ NATIVE MAX ADDRESS EXT
ec 00 00 00 00 00 a0 00 11:02:34.438 IDENTIFY DEVICE
ef 03 46 00 00 00 a0 00 11:02:34.419 SET FEATURES [Set transfer mode]
27 00 00 00 00 00 e0 00 11:02:34.348 READ NATIVE MAX ADDRESS EXT

Error 80 occurred at disk power-on lifetime: 19483 hours (811 days + 19 hours)
When the command that caused the error occurred, the device was active or
idle.

After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
40 51 00 ff ff ff 0f Error: UNC at LBA = 0x0fffffff = 268435455

Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
25 00 08 ff ff ff ef 00 11:02:31.369 READ DMA EXT
27 00 00 00 00 00 e0 00 11:02:31.368 READ NATIVE MAX ADDRESS EXT
ec 00 00 00 00 00 a0 00 11:02:31.348 IDENTIFY DEVICE
ef 03 46 00 00 00 a0 00 11:02:31.329 SET FEATURES [Set transfer mode]
27 00 00 00 00 00 e0 00 11:02:31.278 READ NATIVE MAX ADDRESS EXT

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 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.

8<---

I'm not a hard disk guru, and this info doesn't really say anything specific to
me. Wrt the firmware issue, I went to the Seagate site and downloaded and
burned an ISO, rebooted and followed the instructions, but the firmware update
failed with "unexpected disk type" or something to that effect, although I'm
positively certain that I downloaded the correct ISO and the program initially
identified the disk correctly. The download page is
<http://seagate.custkb.com/seagate/crm/selfservice/search.jsp?DocId=207951>
and the ISO is the bottommost, for ST31000340AS. I'm going to send a mail to
the Seagate support about it, but first I have to rerun the procedure and get
the exact messages.

regards, Leif.