"Disk fail event" during RAID sync following initialization
Environment:
ReadyNAS NV running 4.1.13
Four SAMSUNG HD103UJ (1TB) drives
UPS
After running the HD103UJ drives for just over five years, the drive in slot 3 started to show increased Raw Read Error rates and Current Pending Sector errors. I first bought a "new" HD103UJ to replace the failing drive, but it soon became clear that I'd bought a drive with more errors than the one it replaced. (One star for that Amazon vendor! :evil: )
So I decided to replace all four drives with shiny new Seagate ST2000DM001 (2TB) drives. I hot-swapped the failing drive in slot 3. It initialized, but soon after got a "failure to sync" error. Here's the log from removing the failed drive up to the sync failure:
Sat Feb 1 06:34:34 PST 2014 A SATA reset has been performed on one or more of your disks that may have affected the RAID parity integrity. It is recommended that you perform a RAID volume resync from the RAID Settings tab ( accessible in the Volumes page => Volume tab in FrontView ). The resync process will run in the background, and you can continue to use the ReadyNAS in the meantime. Sat Feb 1 06:32:57 PST 2014 Disk fail event occurred on SATA channel 3. If the failed disk is used in a RAID level 1, 5, or X-RAID volume, please note that volume is now unprotected, and an additional disk failure may render that volume dead. Sat Feb 1 00:31:28 PST 2014 RAID sync started on volume C. Fri Jan 31 21:09:33 PST 2014 Disk initialization started. The estimated time of completion is 17 hour(s) and 39 minute(s), at which time you will be notified via email. You can also check the progress in Frontview in the Volumes -> RAID Settings tab. Please do not shutdown the system while the initialization is in progress. Fri Jan 31 21:09:24 PST 2014 Disk add event occurred on SATA channel 3. Fri Jan 31 21:09:24 PST 2014 Disk remove event occurred on SATA channel 3.
So I decided not to panic and simply unplug and replug drive 3 again. This time, it initialized and completed the sync without error. (Note that I disabled disk spin-down along the way, thinking that might have caused trouble.):
Sun Feb 2 00:26:07 PST 2014 RAID sync finished on volume C. The volume is now fully redundant. Sat Feb 1 09:58:05 PST 2014 RAID sync started on volume C. Sat Feb 1 09:58:05 PST 2014 Disk initialization successfully finished. Sat Feb 1 06:37:58 PST 2014 Automatic disk spin-down disabled. Sat Feb 1 06:36:09 PST 2014 Disk initialization started. The estimated time of completion is 17 hour(s) and 39 minute(s), at which time you will be notified via email. You can also check the progress in Frontview in the Volumes -> RAID Settings tab. Please do not shutdown the system while the initialization is in progress. Sat Feb 1 06:35:59 PST 2014 Disk add event occurred on SATA channel 3. Sat Feb 1 06:35:47 PST 2014 Disk remove event occurred on SATA channel 3.
Now that I had a fully redundant system, I went about upgrading the remaining three drives. But while upgrading slot 4, I've now gotten TWO sync failures in a row:
Sun Feb 2 12:54:09 PST 2014 Disk fail event occurred on SATA channel 4. If the failed disk is used in a RAID level 1, 5, or X-RAID volume, please note that volume is now unprotected, and an additional disk failure may render that volume dead. Sun Feb 2 12:14:24 PST 2014 RAID sync started on volume C. Sun Feb 2 12:14:23 PST 2014 Disk initialization successfully finished. Sun Feb 2 08:44:50 PST 2014 Disk initialization started. The estimated time of completion is 17 hour(s) and 39 minute(s), at which time you will be notified via email. You can also check the progress in Frontview in the Volumes -> RAID Settings tab. Please do not shutdown the system while the initialization is in progress. Sun Feb 2 08:44:41 PST 2014 Disk add event occurred on SATA channel 4. Sun Feb 2 08:44:15 PST 2014 Disk remove event occurred on SATA channel 4. Sun Feb 2 06:35:54 PST 2014 Disk fail event occurred on SATA channel 4. If the failed disk is used in a RAID level 1, 5, or X-RAID volume, please note that volume is now unprotected, and an additional disk failure may render that volume dead. Sun Feb 2 06:30:47 PST 2014 RAID sync started on volume C. Sun Feb 2 06:30:46 PST 2014 Disk initialization successfully finished. Sun Feb 2 03:00:40 PST 2014 Disk initialization started. The estimated time of completion is 17 hour(s) and 39 minute(s), at which time you will be notified via email. You can also check the progress in Frontview in the Volumes -> RAID Settings tab. Please do not shutdown the system while the initialization is in progress. Sun Feb 2 03:00:32 PST 2014 Disk add event occurred on SATA channel 4. Sun Feb 2 02:57:05 PST 2014 Disk fail event occurred on SATA channel 4. If the failed disk is used in a RAID level 1, 5, or X-RAID volume, please note that volume is now unprotected, and an additional disk failure may render that volume dead. Sun Feb 2 02:56:22 PST 2014 Disk remove event occurred on SATA channel 4.
I'm now trying a third time to initialize / sync channel 4. But that's a lengthy process. While I'm anxiously waiting, is there anything else I should be doing?
Re: "Disk fail event" during RAID sync following initializat
Stranger and stranger.
The third attempt at reinsert - reinitialize - resync succeeded.
It wasn't until I tried to access the volume (to do a TimeMachine backup) that it failed. What I got on my MacBook console:
2/3/14 6:07:23.000 AM kernel[0]: AFP_VFS afpfs_mount: /Volumes/ReadyNAS-1, pid 96482 2/3/14 6:07:23.000 AM kernel[0]: AFP_VFS afpfs_mount : succeeded on volume 0xffffff80d927c008 /Volumes/ReadyNAS-1 (error = 0, retval = 0) 2/3/14 6:07:31.000 AM kernel[0]: jnl: disk5s2: replay_journal: from: 210067456 to: 212340736 (joffset 0x2ace000) 2/3/14 6:07:39.000 AM kernel[0]: disk5s2: 0xc005 (UNDEFINED). 2/3/14 6:07:39.000 AM kernel[0]: jnl: disk5s2: update_fs_block: error reading fs block # 44500856! (ret 5) 2/3/14 6:07:39.000 AM kernel[0]: disk5s2: 0xc005 (UNDEFINED). 2/3/14 6:07:39.000 AM kernel[0]: jnl: disk5s2: update_fs_block: error reading fs block # 44500858! (ret 5) 2/3/14 6:07:39.000 AM kernel[0]: disk5s2: 0xc005 (UNDEFINED). 2/3/14 6:07:39.000 AM kernel[0]: jnl: disk5s2: update_fs_block: error reading fs block # 44500860! (ret 5) 2/3/14 6:07:39.000 AM kernel[0]: disk5s2: 0xc005 (UNDEFINED).
...etc. Shortly after that, my ReadyNAS log declared the drive dead:
Mon Feb 3 06:11:11 PST 2014 Disk fail event occurred on SATA channel 4. If the failed disk is used in a RAID level 1, 5, or X-RAID volume, please note that volume is now unprotected, and an additional disk failure may render that volume dead. Mon Feb 3 03:00:01 PST 2014 RAID sync finished on volume C. The volume is now fully redundant. Sun Feb 2 22:46:49 PST 2014 RAID sync started on volume C.
It seems suspicious that the RAID sync completed without trouble, but problems show up only after trying to access the disk over the net.
