Disk kicked out of pool after upgrade to 11.1-U4

Status
Not open for further replies.

mhugelmann

Cadet
Joined
Mar 16, 2012
Messages
8
Hey all,

I was running 11.1-U2 for the past month or so without issue. I saw that there were some issues with -U3, so I passed on the update. When -U4 came out (fixing the problems of -U3), I decided to update.

However, upon rebooting the machine, one of my storage pools reported that it was degraded. I checked dmesg, and the system saw the drive, but for some reason didn't allocate it to the pool. (Instead creating a GEOM_ELI device for the disk.)
dmesg | grep ada18:
Code:
root@comp:~ # dmesg | grep ada18
ada18 at ata3 bus 0 scbus18 target 0 lun 0
ada18: <WDC WD20EZRX-00D8PB0 80.00A80> ACS-2 ATA SATA 3.x device
ada18: Serial Number WD-XXXXXXXXXXXX
ada18: 150.000MB/s transfers (SATA 1.x, UDMA5, PIO 8192bytes)
ada18: 1907729MB (3907029168 512 byte sectors)
ada18: quirks=0x1<4K>
GEOM: ada18: the primary GPT table is corrupt or invalid.
GEOM: ada18: using the secondary instead -- recovery strongly advised.
GEOM_ELI: Device ada18p1.eli created.


zpool status -v pool:
Code:
  pool: pool
 state: DEGRADED
status: One or more devices could not be opened.  Sufficient replicas exist for
		the pool to continue functioning in a degraded state.
action: Attach the missing device and online it using 'zpool online'.
   see: http://illumos.org/msg/ZFS-8000-2Q
  scan: scrub repaired 0 in 0 days 16:13:22 with 0 errors on Fri Mar 23 19:13:23 2018
config:

		NAME					  STATE	 READ WRITE CKSUM
		pool					  DEGRADED	 0	 0	 0
		  raidz1-0				DEGRADED	 0	 0	 0
			ada17				 ONLINE	   0	 0	 0
			14486299466296630956  UNAVAIL	  0	 0	 0  was /dev/ada18
			ada19				 ONLINE	   0	 0	 0
			ada20				 ONLINE	   0	 0	 0
		cache
		  gpt/pool_cache_1		ONLINE	   0	 0	 0
		  gpt/pool_cache_2		ONLINE	   0	 0	 0

errors: No known data errors


I tried rebooting the machine just in case it was something like a timeout error when booting (which has never happened to me before). However, when the system came back up, the error persisted. Same result as the first time.

I thought it was too much of a coincidence that the drive died or that there was some issue with it just as I upgraded the system, so I decided to try downgrading back to -U2. Sure enough, once the system came back up, the pool seemed to be back in a working state. The status of the pool reported that there were 4 checksum errors with the drive that weren't there previously. (I associate this with the upgrade and the system not putting the drive into the pool.)
zpool status -v pool:
Code:
  pool: pool
 state: ONLINE
status: One or more devices has experienced an unrecoverable error.  An
		attempt was made to correct the error.  Applications are unaffected.
action: Determine if the device needs to be replaced, and clear the errors
		using 'zpool clear' or replace the device with 'zpool replace'.
   see: http://illumos.org/msg/ZFS-8000-9P
  scan: resilvered 156K in 0 days 00:00:01 with 0 errors on Wed Mar 28 00:24:01 2018
config:

		NAME				  STATE	 READ WRITE CKSUM
		pool				  ONLINE	   0	 0	 0
		  raidz1-0			ONLINE	   0	 0	 0
			ada17			 ONLINE	   0	 0	 0
			ada18			 ONLINE	   0	 0	 4
			ada19			 ONLINE	   0	 0	 0
			ada20			 ONLINE	   0	 0	 0
		cache
		  gpt/pool_cache_1	ONLINE	   0	 0	 0
		  gpt/pool_cache_2	ONLINE	   0	 0	 0

errors: No known data errors


As a precaution, I scrubbed the pool just to make sure all the data was intact.
zpool status -v pool:
Code:
  pool: pool
 state: ONLINE
status: One or more devices has experienced an unrecoverable error.  An
		attempt was made to correct the error.  Applications are unaffected.
action: Determine if the device needs to be replaced, and clear the errors
		using 'zpool clear' or replace the device with 'zpool replace'.
   see: http://illumos.org/msg/ZFS-8000-9P
  scan: scrub repaired 0 in 0 days 16:21:40 with 0 errors on Wed Mar 28 16:49:00 2018
config:

		NAME				  STATE	 READ WRITE CKSUM
		pool				  ONLINE	   0	 0	 0
		  raidz1-0			ONLINE	   0	 0	 0
			ada17			 ONLINE	   0	 0	 0
			ada18			 ONLINE	   0	 0	 4
			ada19			 ONLINE	   0	 0	 0
			ada20			 ONLINE	   0	 0	 0
		cache
		  gpt/pool_cache_1	ONLINE	   0	 0	 0
		  gpt/pool_cache_2	ONLINE	   0	 0	 0

errors: No known data errors


Since there were 0 errors, I cleared the error.

Has anyone else had this problem with the new update? Could there be any reason that the drive wouldn't work in -U4 but is absolutely fine in -U2? Is this an actual bug and should I be reporting it?

My system's specs are as follows:
  • ECS IC780M-A Motherboard
  • AMD Phenom(tm) II X6 1065T Processor
  • 16GB DDR2 RAM
  • The affected drive is plugged into a Startech PCISATA4R1 SATA expansion card

Any help is greatly appreciated!

Thank you,
Mike

Edited to use CODE tags instead of SPOILER tags.
 
Last edited:

MrToddsFriends

Documentation Browser
Joined
Jan 12, 2015
Messages
1,338

mhugelmann

Cadet
Joined
Mar 16, 2012
Messages
8
Thanks for the reply, MrToddsFriends.

Here's the output requested (please note I'm still booted into -U2, but I don't think it should affect anything):
Code:
smartctl 6.6 2017-11-05 r4594 [FreeBSD 11.1-STABLE amd64] (local build)
Copyright (C) 2002-17, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family:	 Western Digital Green
Device Model:	 WDC WD20EZRX-00D8PB0
Serial Number:	WD-XXXXXXXXXXXX
LU WWN Device Id: 5 0014ee 65axxxxxx
Firmware Version: 80.00A80
User Capacity:	2,000,398,934,016 bytes [2.00 TB]
Sector Sizes:	 512 bytes logical, 4096 bytes physical
Rotation Rate:	5400 rpm
Device is:		In smartctl database [for details use: -P show]
ATA Version is:   ACS-2 (minor revision not indicated)
SATA Version is:  SATA 3.0, 6.0 Gb/s (current: 1.5 Gb/s)
Local Time is:	Thu Mar 29 08:35:57 2018 EDT
SMART support is: Available - device has SMART capability.
SMART support is: Enabled
AAM feature is:   Unavailable
APM feature is:   Unavailable
Rd look-ahead is: Enabled
Write cache is:   Enabled
DSN feature is:   Unavailable
ATA Security is:  Disabled, NOT FROZEN [SEC1]
Wt Cache Reorder: 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:				(27240) 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:		(   2) minutes.
Extended self-test routine
recommended polling time:		( 275) minutes.
Conveyance self-test routine
recommended polling time:		(   5) minutes.
SCT capabilities:			  (0x7035) SCT Status 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		  FLAGS	VALUE WORST THRESH FAIL RAW_VALUE
  1 Raw_Read_Error_Rate	 POSR-K   200   200   051	-	0
  3 Spin_Up_Time			POS--K   175   172   021	-	4250
  4 Start_Stop_Count		-O--CK   100   100   000	-	212
  5 Reallocated_Sector_Ct   PO--CK   200   200   140	-	0
  7 Seek_Error_Rate		 -OSR-K   200   200   000	-	0
  9 Power_On_Hours		  -O--CK   071   071   000	-	21752
 10 Spin_Retry_Count		-O--CK   100   100   000	-	0
 11 Calibration_Retry_Count -O--CK   100   100   000	-	0
 12 Power_Cycle_Count	   -O--CK   100   100   000	-	211
192 Power-Off_Retract_Count -O--CK   200   200   000	-	133
193 Load_Cycle_Count		-O--CK   193   193   000	-	22374
194 Temperature_Celsius	 -O---K   116   106   000	-	31
196 Reallocated_Event_Count -O--CK   200   200   000	-	0
197 Current_Pending_Sector  -O--CK   200   200   000	-	0
198 Offline_Uncorrectable   ----CK   200   200   000	-	0
199 UDMA_CRC_Error_Count	-O--CK   200   199   000	-	5618
200 Multi_Zone_Error_Rate   ---R--   200   200   000	-	0
							||||||_ K auto-keep
							|||||__ C event count
							||||___ R error rate
							|||____ S speed/performance
							||_____ O updated online
							|______ P prefailure warning

General Purpose Log Directory Version 1
SMART		   Log Directory Version 1 [multi-sector log support]
Address	Access  R/W   Size  Description
0x00	   GPL,SL  R/O	  1  Log Directory
0x01		   SL  R/O	  1  Summary SMART error log
0x02		   SL  R/O	  5  Comprehensive SMART error log
0x03	   GPL	 R/O	  6  Ext. Comprehensive SMART error log
0x06		   SL  R/O	  1  SMART self-test log
0x07	   GPL	 R/O	  1  Extended self-test log
0x09		   SL  R/W	  1  Selective self-test log
0x10	   GPL	 R/O	  1  NCQ Command Error log
0x11	   GPL	 R/O	  1  SATA Phy Event Counters log
0x80-0x9f  GPL,SL  R/W	 16  Host vendor specific log
0xa0-0xa7  GPL,SL  VS	  16  Device vendor specific log
0xa8-0xb7  GPL,SL  VS	   1  Device vendor specific log
0xbd	   GPL,SL  VS	   1  Device vendor specific log
0xc0	   GPL,SL  VS	   1  Device vendor specific log
0xc1	   GPL	 VS	  93  Device vendor specific log
0xe0	   GPL,SL  R/W	  1  SCT Command/Status
0xe1	   GPL,SL  R/W	  1  SCT Data Transfer

SMART Extended Comprehensive Error Log Version: 1 (6 sectors)
No Errors Logged

SMART Extended Self-test Log Version: 1 (1 sectors)
Num  Test_Description	Status				  Remaining  LifeTime(hours)  LBA_of_first_error
# 1  Short offline	   Completed without error	   00%	 20297		 -
# 2  Short offline	   Completed without error	   00%	 20273		 -
# 3  Short offline	   Completed without error	   00%	 20249		 -
# 4  Short offline	   Completed without error	   00%	 20233		 -
# 5  Short offline	   Completed without error	   00%	 20223		 -
# 6  Short offline	   Completed without error	   00%	 20199		 -
# 7  Short offline	   Completed without error	   00%	 20177		 -
# 8  Short offline	   Completed without error	   00%	 20153		 -
# 9  Short offline	   Completed without error	   00%	 20129		 -
#10  Short offline	   Completed without error	   00%	 20105		 -
#11  Short offline	   Completed without error	   00%	 20081		 -
#12  Short offline	   Completed without error	   00%	 20057		 -
#13  Short offline	   Completed without error	   00%	 20033		 -
#14  Short offline	   Completed without error	   00%	 20009		 -
#15  Short offline	   Completed without error	   00%	 19985		 -
#16  Short offline	   Completed without error	   00%	 19961		 -
#17  Short offline	   Completed without error	   00%	 19937		 -
#18  Extended offline	Completed without error	   00%	 19925		 -

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.

SCT Status Version:				  3
SCT Version (vendor specific):	   258 (0x0102)
SCT Support Level:				   1
Device State:						Active (0)
Current Temperature:					31 Celsius
Power Cycle Min/Max Temperature:	 27/34 Celsius
Lifetime	Min/Max Temperature:	 18/41 Celsius
Under/Over Temperature Limit Count:   0/0
Vendor specific:
01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

SCT Temperature History Version:	 2
Temperature Sampling Period:		 1 minute
Temperature Logging Interval:		1 minute
Min/Max recommended Temperature:	  0/60 Celsius
Min/Max Temperature Limit:		   -41/85 Celsius
Temperature History Size (Index):	478 (283)

Index	Estimated Time   Temperature Celsius
 284	2018-03-29 00:38	32  *************
 ...	..(116 skipped).	..  *************
 401	2018-03-29 02:35	32  *************
 402	2018-03-29 02:36	31  ************
 ...	..(352 skipped).	..  ************
 277	2018-03-29 08:29	31  ************
 278	2018-03-29 08:30	32  *************
 ...	..(  4 skipped).	..  *************
 283	2018-03-29 08:35	32  *************

SCT Error Recovery Control command not supported

Device Statistics (GP/SMART Log 0x04) not supported

Pending Defects log (GP Log 0x0c) not supported

SATA Phy Event Counters (GP Log 0x11)
ID	  Size	 Value  Description
0x0001  2			0  Command failed due to ICRC error
0x0002  2			0  R_ERR response for data FIS
0x0003  2			0  R_ERR response for device-to-host data FIS
0x0004  2			0  R_ERR response for host-to-device data FIS
0x0005  2			0  R_ERR response for non-data FIS
0x0006  2			0  R_ERR response for device-to-host non-data FIS
0x0007  2			0  R_ERR response for host-to-device non-data FIS
0x0008  2			0  Device-to-host non-data FIS retries
0x0009  2		   14  Transition from drive PhyRdy to drive PhyNRdy
0x000a  2		   14  Device-to-host register FISes sent due to a COMRESET
0x000b  2			0  CRC errors within host-to-device FIS
0x000f  2			0  R_ERR response for host-to-device data FIS, CRC
0x0012  2			0  R_ERR response for host-to-device non-data FIS, CRC
0x8000  4	  3294604  Vendor specific



Also, thanks for the tip about using CODE tags. I'll go back to my original post and edit accordingly.

Thanks again for your help, any insight is greatly appreciated!
 

MrToddsFriends

Documentation Browser
Joined
Jan 12, 2015
Messages
1,338
A causal relationship of pool degradation with the update to 11.1-U4 is highly unlikely.
 
Last edited:

mhugelmann

Cadet
Joined
Mar 16, 2012
Messages
8
This is an indication of a connection issue, 9 out of 10 times a bad SATA cable.

I considered that that could be a cause of the problem, however I thought it was strange the only -U4 presented an issue. Moreover, I didn't see any connection issues reported in the logs or console.

Beyond that, I actually just replaced all the SATA cables in my system just a few months ago. (Those errors might have been logged from before because I was having connection issues with the disk.) That's not to say that perhaps one cable out of the 20 or so new cables I replaced doesn't have an issue, but I wanted to try to rule out the software side of things since that's the only thing that changed.

Also, curious, wouldn't the scrubbing of the pool thrown a lot of errors if it were a case of a bad cable? (I recall that being the case when a bad cable was previously plugged into the drive.) Not to mention hundreds of checksum errors.

I'll definitely try replacing the one cable this weekend and booting into -U4 and seeing if the system still throws me an error. But before swapping the cable, I think I'll try booting into -U4 again to see if it does the same thing.
 

mhugelmann

Cadet
Joined
Mar 16, 2012
Messages
8
A causal relationship of pool degradation with the update to 11.1-U4 is highly unlikely.
While it is unlikely, I do believe it is the source of my problem. There must have been something else changed in the update to cause this to happen. Perhaps some underlying code was changed that wasn't bug or issue related.

I'm going to rule out the cable as the culprit because the drive's error count hasn't increased all day even with the drive being accessed. I believe that number was due to a cable issue, as I said before, but has since been rectified.

I did some further testing this evening. Switching back to -U4 once again produces the exact same issue as before and going back to -U2 makes everything return to normal. With that in mind, I wondered if maybe during the install of the update something became corrupt. (A file on the boot drive becoming corrupt while being written to or some other anomaly.)

I proceeded to delete -U4 snapshot from the boot drive while in -U2. Once complete, I went ahead and told the system to update to -U4 again. After it re-downloaded and re-installed the update, the system came back online with the problem yet again. Upon activating -U2 and rebooting the machine another time, everything returned to normal.

I'm still open to other suggestions or tests to find out what is causing this problem, but I highly suspect it's in the code itself. That being said, I'm definitely going to file a bug report for it in hopes that maybe the FreeNAS team/developers can make sense of it and help to fix it. (Or at least what changed and broke my system so that I can figure out a work-around.)
 

MrToddsFriends

Documentation Browser
Joined
Jan 12, 2015
Messages
1,338
I did some further testing this evening. Switching back to -U4 once again produces the exact same issue as before and going back to -U2 makes everything return to normal. With that in mind, I wondered if maybe during the install of the update something became corrupt. (A file on the boot drive becoming corrupt while being written to or some other anomaly.)

What kind of boot medium are you using? USB sticks do fail frequently and don't have SMART diagnostics ...

If you didn't already do so (and preferably after ruling out the cabling issue): Scrub the boot pool
System -> Boot -> Scrub Boot
and do a Verify Install while you are in -U4
System -> Update -> Verify Install

If a failing boot medium can be ruled out, maybe even by trying another one in case of USB sticks, the creation of a bug report would be appropriate. Report the issue number here then.
 
Joined
May 10, 2017
Messages
838
(Those errors might have been logged from before because I was having connection issues with the disk.)

It's possible they are old errors, just keep monitoring and make sure it stops increasing, a single CRC error once in a blue moon is OK, any more than that there's still a problem.
 
Status
Not open for further replies.
Top