tl;dr: It ended up being a bad RAM stick that took my btrfs cache pool on the first crash and my Docker image file on a subsequent crash.

 

Original post:

 

Version: 6.1.6 (Plus)

Parity: 4TB

Data: Disk 1 (3TB), Disk 2 (3TB), Disk 3 (1TB) - reiserfs (upgraded from v5, haven't migrated file systems yet)

Cache: 2x120TB Kingston SSD in a cache pool

 

This afternoon I noticed that all of my shares were read-only in Windows, and when I tried to access the web gui to investigate, it was completely hung up. I connected via telnet, downloaded the syslog and noticed some nasty errors ("general protection fault", "BTRFS warning", etc.). I tried everything I could think of to get the system to do a clean reboot, but in the end I stopped all of my dockers (which were still running) and issued a "reboot" command.

 

When the system came back up, my Dockers were gone, my VM was stopped, and one of the two SSDs in my cache pool (ID ending in "F2FE") was listed at "unmountable" and I am given an option to reformat it. My cache pool still shows as a "Pool of two devices" but the word "Unmountable" is next to the first drive on the list.

 

Prior to this mess, my system had a cache-only "Apps" share containing all of the files for my Dockers (e.g. Plex library files, MySQL data files, etc.). Between the files in this share, the docker file itself and the VM image, my cache drive would tend to fill up, especially when adding a lot of files to the array at once. I'm not sure if this is related to the issue or not, but I thought I would point it out.

 

Questions:

1. What happened? Do the logs indicate some problem with the SSD, or something else? In the attached diagnostics, both SSDs are showing as healthy in their SMART reports, so I can't tell if this is a hardware failure or not. However, I am unable to extract the "Kinston_DT_101_G2_.....txt" file from the .zip due to "destination file could not be created". I'm not sure what this file is. (EDIT: That's my flash drive. 7-zip was able to open it.)

2. Is there any way to recover my cache pool? My cache-only "Apps" share didn't have any data (other than my backed-up MySQL databases), but setting up all of my Dockers is going to be a massive undertaking that I'd like to avoid if possible.

3. What is the next step at this point? Should I take the option of reformatting the SSD or try something else first?

4. Is it bad for the system to have the cache drive fill up? It's not every day, but somewhat regular.

5. If I am out of luck with recovering the pool, how do I go about backing up my docker and VM image files (i.e. do they need to be stopped first, etc) on a regular basis once they're rebuilt? Does anyone have a script that does this?

 

Note about the syslog: I removed some mover logger entries that included file paths, and replaced a few other paths with "REDACTED". The repeating "shfs_open" ... Read-only file system" error is a path that is accessed by the BTSync docker.

 

The attached "syslog_Edited" is the pre-reboot log, and the diagnostics zip file is post-reboot.

 

...looks like I need to split the log into two files. First file is attached, I'll post the second half next.

depot-diagnostics-20151228-1650.zip

syslog_20151228_Edited1.txt

...second half of the syslog, showing all of the errors.

syslog_20151228_Edited2.txt

Update:Based on a few posts, I tried running the "scrub" command on each SSD but received this message each time:

 

root@depot:~# btrfs scrub start -rdB /dev/sdd

ERROR: '/dev/sdd' is not a mounted btrfs device

root@depot:~# btrfs scrub start -rdB /dev/sdh

ERROR: '/dev/sdh' is not a mounted btrfs device

 

Then I tried running a "restore" command on each of the two SSDs and received this message:

 

root@depot:~# btrfs restore -v -i /dev/sdh /mnt/user/Backups/cacherestore

No valid Btrfs found on /dev/sdh

Could not open root, trying backup super

No valid Btrfs found on /dev/sdh

Could not open root, trying backup super

Superblock bytenr is larger than device size

Could not open root, trying backup super

root@depot:~# btrfs restore -v -i /dev/sdd /mnt/user/Backups/cacherestore

No valid Btrfs found on /dev/sdd

Could not open root, trying backup super

No valid Btrfs found on /dev/sdd

Could not open root, trying backup super

Superblock bytenr is larger than device size

Could not open root, trying backup super

 

In my reading I found other cases where removing one of the drives from the pool seemed to help, but before I try anything like that, I'd really like to get some advice from someone who knows what they're doing. The last thing I want is to ruin any slim chance of recovering my "Apps" share.

 

...and if recovery isn't an option, I'd definitely appreciate advice on backing up Dockers and VMs!

I had a issue recently with my cache drive and had to reformat it as XFS after some reading seems to be more stable format than Btrfs.

 

 

Interesting... Of course, that eliminates the possibility of a pool, which in my case didn't seem to help anyway.

I believe your best option is to try one cache disk at a time, note that you have to physically unplug the other disk from the server, it’s not enough to unassign it.

 

If that doesn’t work you can still try other recovery options.

 

Ok, I'll try that next and update the thread.

 

In the meantime: Can someone look at the attachments and let me know what happened? I really don't think I was doing anything out of the ordinary apart from having my cache drive occasionally fill up.

 

Also, if I decide to move to XFS for the cache drive, am I painting myself into any corners? Obviously the redundancy of the pool didn't seem to help much, but I don't want to start down a path that will limit future options. Either way, once I get things rebuilt I plan on coming up with a strategy to back up my cache drive so this won't be such a pain if it happens again.

 

Just tried stopping/starting array with each of my SSDs connected as the only device, and in both cases I got this in the syslog:

 

Dec 29 13:51:56 depot kernel: BTRFS: open /dev/sdh1 failed

Dec 29 13:51:56 depot kernel: BTRFS info (device sdd1): allowing degraded mounts

Dec 29 13:51:56 depot kernel: BTRFS info (device sdd1): disk space caching is enabled

Dec 29 13:51:56 depot kernel: BTRFS: has skinny extents

Dec 29 13:51:56 depot kernel: BTRFS critical (device sdd1): corrupt leaf, bad key order: block=1098874880,root=1, slot=65

Dec 29 13:51:56 depot kernel: BTRFS critical (device sdd1): corrupt leaf, bad key order: block=1098874880,root=1, slot=65

Dec 29 13:51:56 depot kernel: BTRFS: Failed to read block groups: -5

Dec 29 13:51:56 depot logger: mount: wrong fs type, bad option, bad superblock on /dev/sdd1,

Dec 29 13:51:56 depot logger:        missing codepage or helper program, or other error

Dec 29 13:51:56 depot logger:        In some cases useful info is found in syslog - try

Dec 29 13:51:56 depot logger:        dmesg | tail  or so

Dec 29 13:51:56 depot logger:

Dec 29 13:51:56 depot emhttp: shcmd: shcmd (120): exit status: 32

Dec 29 13:51:56 depot emhttp: mount error: No file system (32)

Dec 29 13:51:56 depot emhttp: shcmd (121): rmdir /mnt/cache

Dec 29 13:51:56 depot kernel: BTRFS: open_ctree failed

 

(second time the device ID referred to the other SSD).

 

So, it looks like I'm toast and just need to reformat the cache drive and start over. For now I'm going to just use one of the SSDs as XFS and just do the minimal set up to get my Dockers up and running again.

 

If anyone has the time, I would still very much like to know what went wrong here. If it really is just a btrfs issue, then I'd be curious to know what I'd be walking away from if I leave my cache as XFS.

I just returned from a few days away, and once again my system is unresponsive. This time, I cannot navigate to the web gui, and I cannot connect via Telnet (after entering the "root" login, the screen just hangs). However, I can still access files via my PC and the shares are not read-only.

 

Before I left, I formatted one of my two SSDs as XFS and changed my cache settings to use it as the lone cache drive. I didn't set anything else up (no dockers, no VMs, no files in the cache-only "Apps" share), and left my PC running with the syslog page loaded. Thankfully, because the syslog was on the screen when I left, I can see the last few entries. It looks like OpenVPN Client disconnected at 7am (per cron job), and a parity check kicked off at 11pm. Also at 11pm, the OpenVPN Client reconnected (per cron job).

 

I can't remember if the parity check was supposed to start at 11pm or not, so I'm not sure if some event caused this or if it's the normal monthly check. It's important to note that nothing has changed in my setup (other than the cache drive) for almost 5 months. The cron jobs that start/stop OpenVPN Client have been this way for a long time.

 

Since I can't access the web gui and I can't telnet to the server, how do I proceed? Syslog excerpt below:

 

Dec 31 03:40:13 depot logger: mover finished

Dec 31 03:55:53 depot kernel: mdcmd (28): spindown 0

Dec 31 03:55:53 depot kernel: mdcmd (29): spindown 1

Dec 31 03:57:11 depot emhttp: shcmd (377): /usr/sbin/hdparm -y /dev/sdh &> /dev/null

Dec 31 07:00:01 depot avahi-daemon[27208]: Withdrawing workstation service for tun5.

Dec 31 07:00:03 depot ntpd[1581]: Deleting interface #6 tun5, 10.103.1.6#123, interface stats: received=32, sent=32, dropped=0, active_time=28796 secs

Dec 31 07:00:03 depot ntpd[1581]: 45.79.78.173 local addr 10.103.1.6 ->

Dec 31 22:39:42 depot emhttp: shcmd (378): /usr/sbin/hdparm -y /dev/sdh &> /dev/null

Dec 31 23:00:01 depot kernel: mdcmd (30): check

Dec 31 23:00:01 depot kernel: md: recovery thread woken up ...

Dec 31 23:00:01 depot kernel: md: recovery thread checking parity...

Dec 31 23:00:01 depot kernel: md: using 1536k window, over a total of 3907018532 blocks.

Dec 31 23:00:03 depot sudo:    root : TTY=unknown ; PWD=/boot/openvpn ; USER=root ; COMMAND=/bin/bash -c nohup /tmp/openvpn/openvpn.sh >  /tmp/openvpn/openvpn.out /dev/null 2>&1 &

Dec 31 23:00:03 depot sudo:    root : TTY=unknown ; PWD=/boot/openvpn ; USER=root ; COMMAND=/usr/sbin/openvpn --writepid /var/run/openvpn/openvpn.pid --script-security 3 --mute-replay-warnings --config /boot/openvpn/USMidwest.ovpn /dev/null

Sorry for all of the posts to my own thread, but I'm afraid I REALLY NEED HELP!

 

I ended up rebooting the server using the reset button on the case, since I couldn't access it via the web gui, telnet or even directly after plugging in a keyboard and monitor. Once the system came back up, I proceeded to rebuild my dockers (MySQL, Plex, Sickbeard, SAB). At one point during the process, the server started having issues. Syslog is attached. I was able to recover with a "powerdown -r" and everything seemed fine so I continued working on getting my Dockers set up again. After a few more hours of this I kicked off a parity check and went to bed. The previous parity check after the hard reboot was halfway done with 0 errors when I had to run powerdown, so I wanted to run another just to be safe.

 

This morning my server was once again unresponsive. No access to webgui, Telnet or directly via keyboard/monitor. I can't get a log file out so I'm going to have to do another hard reboot.

 

I really don't understand what is going on. I have been running unraid for years and I've never had any problems like this. I've been running v6 since August and I've been absolutely loving it. These issues have come out of nowhere. I'm starting to suspect some sort of hardware failure (RAM maybe?), but I don't know what tools I can run to investigate this, and I can't figure it out from the syslog files either.

 

I would really appreciate any help or advice or troubleshooting steps. Thank you!

depot-syslog-20160101-2140.zip

Have you tried running memtest? Having the system pass 24 hours of that would eliminate the ram from being an issue.

Thanks buxton, you are correct: I had already started running Memtest after a hard restart and I can't say for sure, but to me this doesn't look good.

 

The RAM is this, purchased in July:

http://www.newegg.com/Product/Product.aspx?Item=N82E16820233536

 

I noticed the timings on the screen don't match the specs on the RAM. RAM is 9-10-9-27 @ 933 MHz, but my system was running it at 9-9-9-24 @ 666 MHz! I assumed the mobo would detect and automatically assign the correct settings (ASRock Z97 Extreme6, DRAM timings were all "Auto")... I certainly didn't intend to run my RAM out of spec!

 

I manually reset the timings and clock speed, ran another memtest with both sticks, and still got a ton of failures. I tested each stick individually and narrowed it down to one bad stick. I ruled out mobo issues by testing each stick in a couple slots. Bad stick failed everywhere, good stick nowhere.

 

I assume it's ok to hobble the system along on one stick until I can replace it, correct?

...but to me this doesn't look good.

 

Correct, a single error is not good.

 

 

I noticed the timings on the screen don't match the specs on the RAM. RAM is 9-10-9-27 @ 933 MHz, but my system was running it at 9-9-9-24 @ 666 MHz! I assumed the mobo would detect and automatically assign the correct settings (ASRock Z97 Extreme6, DRAM timings were all "Auto")... I certainly didn't intend to run my RAM out of spec!

 

You were running them at SPD speed, which is bellow maximum speed, so no problem, usually need to select XMP profile in Bios to use maximum rated speed.

 

I assume it's ok to hobble the system along on one stick until I can replace it, correct?

 

Yes, but looking at your syslog there are some signs of corruption on your docker image, maybe a good idea to recreate it.

Thanks johnnie.black (my favorite blended Scotch, FWIW)!

 

I agree that the speed on the RAM was underclocked, but the timings seemed aggressive. Or maybe just bad luck fried the RAM. Either way, I'm ordering two more sticks of the same so I can have a spare on hand if the other goes down.

 

I'll rebuild my Docker image as well. I'm starting to get good at that.

 

Final question and I'll mark this as "RESOLVED":

 

Is there a known issue that btrfs is especially susceptible to corruption when there's bad RAM in the system? I ask because through all of the crashes and surprise reboots, my reiserfs data/parity drives had no problems, and I'm not seeing any issues with my newly XFS-formatted cache drive. However, when the issue first occurred it completely wiped my btrfs cache pool, and now there's an issue in my Docker image (which I believe is also btrfs, right?).

I agree that the speed on the RAM was underclocked, but the timings seemed aggressive. Or maybe just bad luck fried the RAM. Either way, I'm ordering two more sticks of the same so I can have a spare on hand if the other goes down.

 

Timings decrease as frequency increases, those kind of Dimms usually have two sets of timings, for the model you're using they are:

 

SPD 9-9-9-24@1333Mhz (this setting is generally used with bios set to auto)

XMP 9-10-9-27@1866Mhz (to use this one you have to set xmp profile in bios)

 

Both should work reliably and for Unraid use (and most other uses) performance will be similar.

 

Is there a known issue that btrfs is especially susceptible to corruption when there's bad RAM in the system? I ask because through all of the crashes and surprise reboots, my reiserfs data/parity drives had no problems, and I'm not seeing any issues with my newly XFS-formatted cache drive. However, when the issue first occurred it completely wiped my btrfs cache pool, and now there's an issue in my Docker image (which I believe is also btrfs, right?).

 

This is just a guess, but the fact that Btfrs uses real time checksums probably makes it more susceptible to memory errors.

Thanks again johnnie.black!

 

I'm going to mark this as "RESOLVED" and stick with XFS for my cache drive from now on. I'm also going to implement some sort of backup schedule for my cache-only share so I don't need to redo my Docker settings if this ever happens again (e.g. Sickbeard DB... ugh.). I understand the benefit of a cache pool, but I'd rather stick with something that runs less of a risk of losing everything due to a RAM failure.