Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 27 Jun 2013 04:38:37 +0200
From:      Nikola =?utf-8?B?UGF2bG92acSH?= <nzp@riseup.net>
To:        freebsd-questions@freebsd.org
Subject:   Troubleshooting a gmirror disk marked broken
Message-ID:  <20130627023837.GA7685@sputnjik.localdomain>

Next in thread | Raw E-Mail | Index | Archive | Help

--LZvS9be/3tNcYl/X
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

Hi,

Last night during a massive (~1 year worth :| )
portsnap fetch

the server went unresponsive and ssh eventually disconnected.  I decided
to leave it during the night, and, sure enough, the situation was the
same in the morning, so I had to do a hard reset.  It came back up, but
one of the two gmirror components was marked as broken and deactivated.

The hang happened during the 'fetching new files or ports' (~24000 of
them, there are currently ~10000 snapshots in /var/db/portsnap) phase
of postsnap fetch.

/var/log/messages was completely silent during the period between the
hang and the reset.

Googling around I found a mention that it's possible to sometimes get a
'blip'[*] during busy periods, so I decided to just bite the bullet and
reinsert the component with
# gmirror forget gm0
# gmirror clean ad4
# gmirror insert gm0 ad4

Currently it's syncing and things *seem* OK.  My question is how much
should I be worried and what could be the cause of this?  Is it possible
that  ports snapshot fetching caused this, or that perhaps it was the other
way around (a failing disk causing the machine to choke during the huge
portsnap fetch)?  How to proceed? :)

At the moment I'm attaching smartctl -a results for both disks (ad4 was
marked broken).  As I'm completely useless in deciphering smartctl
results (apart from being thought by experience to pretty much
ignore(tm) the 'Pre-fail' statuses), I'd appreciate assessment from more
knowledgeable people.

Also attached is a trimmed /var/log/messages from the moment of hard
reset on (I can fill in the snipped parts, just didn't want to choke people
with possibly irrelevant details).


$ uname -a
FreeBSD isus 8.3-RELEASE-p3 FreeBSD 8.3-RELEASE-p3 #0: Tue Jun 12 00:39:29 UTC 2012 root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  amd64


-------
[*]
http://www.eztiger.org/2008/08/removing-and-re-adding-a-disk-in-gmirror/


-- 
If you analyse anything, you destroy it.
		-- Arthur Miller


--LZvS9be/3tNcYl/X
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename=smartctl-ad4

smartctl 5.42 2011-10-20 r3458 [FreeBSD 8.3-RELEASE-p3 amd64] (local build)
Copyright (C) 2002-11 by Bruce Allen, http://smartmontools.sourceforge.net

=== START OF INFORMATION SECTION ===
Model Family:     Seagate Barracuda 7200.10
Device Model:     ST3320620AS
Serial Number:    5QF1FDAS
Firmware Version: 3.AAE
User Capacity:    320,072,933,376 bytes [320 GB]
Sector Size:      512 bytes logical/physical
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   7
ATA Standard is:  Exact ATA specification draft version not indicated
Local Time is:    Thu Jun 27 03:55:37 2013 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:  (0x82) Offline data collection activity
                                        was completed without error.
                                        Auto Offline Data Collection: Enabled.
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:                (  430) 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:        (   1) minutes.
Extended self-test routine
recommended polling time:        ( 115) minutes.

ATA Version is:   7
ATA Standard is:  Exact ATA specification draft version not indicated
Local Time is:    Thu Jun 27 03:55:37 2013 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:  (0x82) Offline data collection activity
                                        was completed without error.
                                        Auto Offline Data Collection: Enabled.
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:                (  430) 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:        (   1) minutes.
Extended self-test routine
recommended polling time:        ( 115) minutes.

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   097   088   006    Pre-fail  Always       -       168982958
  3 Spin_Up_Time            0x0003   096   096   000    Pre-fail  Always       -       0
  4 Start_Stop_Count        0x0032   100   100   020    Old_age   Always       -       23
  5 Reallocated_Sector_Ct   0x0033   100   100   036    Pre-fail  Always       -       2
  7 Seek_Error_Rate         0x000f   088   060   030    Pre-fail  Always       -       800989511
  9 Power_On_Hours          0x0032   085   085   000    Old_age   Always       -       13768
 10 Spin_Retry_Count        0x0013   100   100   097    Pre-fail  Always       -       0
 12 Power_Cycle_Count       0x0032   100   100   020    Old_age   Always       -       38
187 Reported_Uncorrect      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   048   046   045    Old_age   Always       -       52 (Min/Max 30/52)
194 Temperature_Celsius     0x0022   052   054   000    Old_age   Always       -       52 (0 19 0 0 0)
195 Hardware_ECC_Recovered  0x001a   062   057   000    Old_age   Always       -       118828427
197 Current_Pending_Sector  0x0012   100   100   000    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0010   100   100   000    Old_age   Offline      -       0
199 UDMA_CRC_Error_Count    0x003e   200   200   000    Old_age   Always       -       0
200 Multi_Zone_Error_Rate   0x0000   100   253   000    Old_age   Offline      -       0
202 Data_Address_Mark_Errs  0x0032   100   253   000    Old_age   Always       -       0

SMART Error Log Version: 1
No Errors Logged

SMART Self-test log structure revision number 1
Num  Test_Description    Status                  Remaining  LifeTime(hours)  LBA_of_first_error
# 1  Extended offline    Completed without error       00%     13229         -
# 2  Short offline       Completed without error       00%     13197         -
# 3  Short offline       Completed without error       00%     10062         -

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.

--LZvS9be/3tNcYl/X
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename=smartctl-ad6

smartctl 5.42 2011-10-20 r3458 [FreeBSD 8.3-RELEASE-p3 amd64] (local build)
Copyright (C) 2002-11 by Bruce Allen, http://smartmontools.sourceforge.net

=== START OF INFORMATION SECTION ===
Model Family:     SAMSUNG SpinPoint T133
Device Model:     SAMSUNG HD300LJ
Serial Number:    S0D7J1CLB13745
Firmware Version: ZT100-13
User Capacity:    300,069,052,416 bytes [300 GB]
Sector Size:      512 bytes logical/physical
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:    Thu Jun 27 04:05:02 2013 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:  (0x82) Offline data collection activity
                                        was completed without error.
                                        Auto Offline Data Collection: Enabled.
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:                ( 6980) 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:        ( 126) minutes.
SCT capabilities:              (0x003f) SCT Status supported.
                                        SCT Error Recovery Control supported.
                                        SCT Feature Control supported.
                                        SCT Data Table supported.

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       -       7552
  4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       17
  5 Reallocated_Sector_Ct   0x0033   100   100   010    Pre-fail  Always       -       1
  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   100   100   000    Old_age   Always       -       49422
 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       -       17
190 Airflow_Temperature_Cel 0x0022   055   055   000    Old_age   Always       -       45
194 Temperature_Celsius     0x0022   103   103   000    Old_age   Always       -       45
195 Hardware_ECC_Recovered  0x001a   100   100   000    Old_age   Always       -       184485293
196 Reallocated_Event_Count 0x0032   100   100   000    Old_age   Always       -       1
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   100   100   000    Old_age   Always       -       0
202 Data_Address_Mark_Errs  0x0032   253   253   000    Old_age   Always       -       0

SMART Error Log Version: 1
No Errors Logged

SMART Self-test log structure revision number 1
Num  Test_Description    Status                  Remaining  LifeTime(hours)  LBA_of_first_error
# 1  Extended offline    Completed without error       00%     38620         -
# 2  Extended offline    Completed without error       00%     38599         -

Note: selective self-test log revision number (0) not 1 implies that no selective self-test has ever been run
SMART Selective self-test log data structure revision number 0
Note: revision number not 1 implies that no selective self-test has ever been run
 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.

--LZvS9be/3tNcYl/X
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename=messages

Jun 26 10:51:34 isus syslogd: kernel boot file is /boot/kernel/kernel
Jun 26 10:51:34 isus kernel: ad6: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad6: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad6: WARNING - SET_MULTI taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad6: TIMEOUT - WRITE_DMA48 retrying (1 retry left) LBA=337093455
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SET_MULTI taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: TIMEOUT - WRITE_DMA48 retrying (1 retry left) LBA=337093455
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SET_MULTI taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - WRITE_DMA48 requeued due to channel reset LBA=337092335
Jun 26 10:51:34 isus kernel: ad4: TIMEOUT - WRITE_DMA48 retrying (1 retry left) LBA=337092271
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SET_MULTI taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - WRITE_DMA48 requeued due to channel reset LBA=337093455
Jun 26 10:51:34 isus kernel: ata2: FAILURE - already active DMA on this device
Jun 26 10:51:34 isus kernel: ata2: setting up DMA failed
Jun 26 10:51:34 isus kernel: ad4: TIMEOUT - WRITE_DMA48 retrying (1 retry left)GEOM_MIRROR LBA=337092303: Request failed (error=5).
Jun 26 10:51:34 isus kernel: ad4[WRITE(offset=172591848960, length=16384)]
Jun 26 10:51:34 isus kernel: GEOM_MIRROR: Device gm0: provider ad4 disconnected.
Jun 26 10:51:34 isus kernel: ad6: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad6: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad6: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad6: WARNING - SET_MULTI taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad6: TIMEOUT - WRITE_DMA48 retrying (1 retry left) LBA=337092271
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SET_MULTI taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: TIMEOUT - WRITE_DMA48 retrying (0 retries left) LBA=337092271

[ snip lots more simmilar ]

Jun 26 10:51:34 isus kernel: unknown: TIMEOUT - WRITE_DMA48 retrying (0 retries left) LBA=586072367
Jun 26 10:51:34 isus kernel: ata3: timeout waiting to issue command
Jun 26 10:51:34 isus kernel: ata3: error issuing WRITE_DMA48 command
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES SET TRANSFER MODE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE RCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SETFEATURES ENABLE WCACHE taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: WARNING - SET_MULTI taskqueue timeout - completing request directly
Jun 26 10:51:34 isus kernel: ad4: TIMEOUT - WRITE_DMA48 retrying (0 retries left) LBA=337092399
Jun 26 10:51:34 isus kernel: GEOM_MIRROR: Cannot write metadata on ad6 (device=gm0, error=5).
Jun 26 10:51:34 isus kernel: GEOM_MIRROR: Cannot update metadata on disk ad6 (error=5).
Jun 26 10:51:34 isus kernel: GEOM_MIRROR: Device gm0: provider ad6 disconnected.
Jun 26 10:51:34 isus kernel: GEOM_MIRROR: Device gm0: provider mirror/gm0 destroyed.
Jun 26 10:51:34 isus kernel: g_vfs_done():mirror/gm0s1a[READ(offset=799555584, length=4096)]error = 6
Jun 26 10:51:34 isus kernel: g_vfs_done():mirror/gm0s1g[READ(offset=56259260416, length=2048)]error = 6
Jun 26 10:51:34 isus kernel: g_vfs_done():mirror/gm0s1g[READ(offset=56463439872, length=2048)]error = 6
Jun 26 10:51:34 isus kernel: g_vfs_done():mirror/gm0s1g[WRITE(offset=86691856384, length=16384)]error = 6
Jun 26 10:51:34 isus kernel: /dev: got error 6 while accessing filesystem
Jun 26 10:51:34 isus kernel: panic: softdep_deallocate_dependencies: unrecovered I/O error
Jun 26 10:51:34 isus kernel: cpuid = 0
Jun 26 10:51:34 isus kernel: KDB: stack backtrace:
Jun 26 10:51:34 isus kernel: #0 0xffffffff8063dcbe at kdb_backtrace+0x5e
Jun 26 10:51:34 isus kernel: #1 0xffffffff8060aed7 at panic+0x187
Jun 26 10:51:34 isus kernel: #2 0xffffffff80839970 at clear_remove+0
Jun 26 10:51:34 isus kernel: #3 0xffffffff80683750 at brelse+0x60
Jun 26 10:51:34 isus kernel: #4 0xffffffff806862a8 at bufdone+0x68
Jun 26 10:51:34 isus kernel: #5 0xffffffff805aae56 at g_io_schedule_up+0xa6
Jun 26 10:51:34 isus kernel: #6 0xffffffff805ab3d8 at g_up_procbody+0x58
Jun 26 10:51:34 isus kernel: #7 0xffffffff805dfb2f at fork_exit+0x11f
Jun 26 10:51:34 isus kernel: Copyright (c) 1992-2012 The FreeBSD Project.
Jun 26 10:51:34 isus kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Jun 26 10:51:34 isus kernel: The Regents of the University of California. All rights reserved.
Jun 26 10:51:34 isus kernel: FreeBSD is a registered trademark of The FreeBSD Foundation.
Jun 26 10:51:34 isus kernel: FreeBSD 8.3-RELEASE-p3 #0: Tue Jun 12 00:39:29 UTC 2012
Jun 26 10:51:34 isus kernel: root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC amd64

[ snip the normal stuff ]

Jun 26 10:51:34 isus kernel: GEOM_MIRROR: Component ad4 (device gm0) broken, skipping.
Jun 26 10:51:34 isus kernel: GEOM_MIRROR: Device mirror/gm0 launched (1/2).
Jun 26 10:51:34 isus kernel: SMP: AP CPU #1 Launched!
Jun 26 10:51:34 isus kernel: GEOM: ad4s1: geometry does not match label (255h,63s != 16h,63s).

[ after this it' all the usual, plus background fsck fixing a huge amount of INCORRECT BLOCK COUNT and some UNREF FILE on gm0s1g (/var)]

Jun 26 11:03:15 isus fsck: /dev/mirror/gm0s1g: Reclaimed: 0 directories, 4294956770 files, -12913 fragments
Jun 26 11:03:15 isus fsck: /dev/mirror/gm0s1g: 249619 files, 1273037 used, 100022063 free (19495 frags, 12500321 blocks, 0.0% fragmentation)

--LZvS9be/3tNcYl/X--



Want to link to this message? Use this URL: <http://docs.FreeBSD.org/cgi/mid.cgi?20130627023837.GA7685>