ZFS pool import crashes FreeNAS 9.2.0 x64 VM

[Richard666]

VMware ESXi v5.1.0, 1065491
FreeNAS-9.2.0-RELEASE-x64.iso
Supermicro X9DR3-LN4+
96GB ECC Ram, pass memtest 1pass +19% of 2nd pass (took 11hours for just 19%)
pcie device passthrough for my LSI SAS 9206-16E HBA (2 x lsi 2308, one is passed through for this VM)
All hardware + disks are on UPS
Pool is 11 drive Raidz3
Poolname: rdkmovie01
Datasetname: rdkmovie01
There is no backup of the data, as murphy's law dictates, I had just started a backup as I had structured all the folders/data the way I wanted and cleaned everything up.

Overall summary is the pool is there, all devices available/online, labels appear to check out, importing pool crashes OS. I can view the structure to some degree using zdb, but it hits points where it crashes/fails. The attached images and code quotes below have command outputs. If you want the long story, I've included that below as well as various troubleshooting steps I've tried.

Pool was originally created under FreeNAS 9.1, I believe from the GUI. I forget as I've gone back and forth with nas4free but gave up on it due to gui failing to create the array. The VM has been working great and I recently upgraded my other VM to use XBMC v13 (gotham) to view my movie collection. While performing my library scan (first time I think), my FreeNAS VM crashed. It was a 'Fatal trap' of some kind but I didn't make any notes. I rebooted the VM and thought nothing of it. I believe the scan continued on and crashed the FreeNAS VM again. This time the FreeNAS VM wouldn't boot, I got some kind of error that lead me to believe the contents of the virtual drive were corrupt.

I created a new VM and did a fresh install of FreeNAS 9.2 release x64. I loaded up my database from the other VM and upon boot got a 'Fatal trap 12: page fault while in kernel mode' (attached freenas_92rel_crash.jpg)

I went through and determined rdkmovie01 pool was the issue. I then tried to manually import the pool (zpool import rdkmovie01) which resulted in another 'fatal trap 12'. Upon reboot it crashed again with a 'fatal trap 12'. Turns out another pool was now corrupt (rdkscratch01). I am able to mount rdkscratch01 in read only mode and copy the data off.

I've now split my LSI 9206-16E controller between two VMs, one with the stable/working pools and the other with rdkmovie01 + spare drives to tinker with.

With all the detailed history above, here's what I've done so far:
Ubuntu 12.04.3 server x64
zpool import -f rdkmovie01 results in Ubuntu_crash.jpg

Openindiana dev151a8 x86
zpool import sees the pool but says all its drives are unavailable (openindiana_zpool_import.jpg). zpool import -f rdkmovie01 results in 'invalid vdev configuration'

Solaris 11.1 liveCD x86
zpool import -f rdkmovie01 results in 'invalid vdev configuration'

FreeNAS 9.2.0 x64 following http://forums.freenas.org/threads/zfs-has-failed-you.11951/
zpool import -fR /mnt rdkmovie01 this results in the 'fatal trap 12' crash
zpool import -fo readonly=on -R /mnt rdkmovie01 results in the 'fatal trap 12' crash
zpool import -R /mnt -FX poolname I have not run this as it says it can destroy the pool


Currently I've been reading through http://cuddletech.com/blog/?p=407 which covers use of zdb to examine the pool/structure. Based on the posts I've read on these forums and that, here's the output of various commands that I suspect will be helpful. I've run all of them under Ubuntu 12.04.3 as it has proven to not crash the OS as I troubleshoot and reboots very quickly compared to some of the other OSes. But if needed, I can switch back to FreeNAS to perform the troubleshooting.

zpool import
note: shows all disks online and no errors of any kind

pool: rdkmovie01

id: 530582438526630596

state: ONLINE

status: The pool was last accessed by another system.

action: The pool can be imported using its name or numeric identifier and

the '-f' flag.

see: http://zfsonlinux.org/msg/ZFS-8000-EY

config:

rdkmovie01 ONLINE

raidz3-0 ONLINE

ata-Hitachi_HDS723030ALA640_MK0303YHGD1E3C ONLINE

ata-Hitachi_HDS5C4040ALE630_PL2331LAGDL0VJ ONLINE

ata-Hitachi_HDS5C4040ALE630_PL2331LAGDP9JJ ONLINE

ata-HGST_HDS5C4040ALE630_PL2331LAGHY3PJ ONLINE

ata-HGST_HDS5C4040ALE630_PL2331LAGHVHEJ ONLINE

ata-Hitachi_HDS5C3030ALA630_MJ1321YNG12WBA ONLINE

ata-HGST_HDS5C4040ALE630_PL2331LAGHXRUJ ONLINE

ata-Hitachi_HDS5C3030ALA630_MJ1311YNG25LBA ONLINE

ata-Hitachi_HDS5C3030ALA630_MJ0351YNG809JA ONLINE

ata-Hitachi_HDS5C3030ALA630_MJ1321YNG0VN5A ONLINE

ata-HGST_HDS5C4040ALE630_PL2331LAGJ3B3J ONLINE

dmesg
http://pastebin.com/AquCYSBJ

zdb -e rdkmovie01
note: this seems to stop at object 2368 and shows corruption/unknown values?
http://pastebin.com/Wj2DnsMm

zdb -eh rdkmovie01
note: just shows the history for this pool, didn't see anything helpful
http://pastebin.com/L4XWs5Te

 

[cyberjock]

Oh boy.. I see plenty of problems and little if any possible solutions(or at least no solutions that are easy to explain in the forum).

 

[Richard666]

I see plenty of problems

If you're willing and have time, would you elaborate further? I ask as I still have a couple other ZFS pools up and running and I'm fairly concerned that a simple OS crash can scamble multiple pools beyond easy recovery. I migrated to ZFS for the resiliency and future proofing of raidz3, but I haven't been feeling the love, hehe.

Also, perhaps this is a bit too much, but per this site: http://www.eall.com.br/blog/?p=312 it seems possible to read data from the disks using zdb to get the sector offset + size/etc. Of course, his example is for a mirror which makes things easy, but I assume with some scripting I could do the same in my case? One problem I have though, is I cannot get his command to work:

zdb -R poolname/datasetname:device:offset:size:r 2
I get back 'invalid block specifier: 2 - size must not be zero'. If I do like a prior example where he parses a text file (I do the same on my end), omitting the :r results in zdb showing help

 

[cyberjock]

Well, for starters you have things like ata-Hitachi_HDS723030ALA640_MK0303YHGD1E3C being listed. That's not a gptid, so the pool clearly wasn't created with FreeNAS. Probably not the smartest choice in the world and will undoubtedly make recovery more difficult because you are adding unknowns. I've done many pool recoveries, but to be honest I'd be scared to even touch your pool because I can't make the same assumptions that I normally do since I can't assume anything about how your pool was constructed. In short, you've created your pool in a non-standard way for this forum so you are basically on an island all alone. One thing I can guarantee you the pool was not created from FreeNAS despite you saying you created it in 9.1 and from the GUI.

Also, it's been warned again and again that virtualizing FreeNAS can have undesired consequences. You appear to have read up on virtualizing since you did pcie passthrough. However there's always that question of "what did you forget to do?" which is why we strongly recommend against FreeNAS in a VM. The fact that 2 pools corrupted in quick succession suggests something is actually wrong and its not just a software bug. It could be a hardware compatibility problem, virtualization problem, improper setup of your hardware, a misconfigure when setting up FreeNAS, or even somehow related to the fact that you didn't create the pool in FreeNAS. I really don't know and there's little to go on except "shit is broke".

Not sure what that link for eall.com.br is supposed to be, but it fails to load for me.

At this time I have zero recommendations because any of them would be quite time consuming and I'm really not particularly interested in leading you astray, especially in a way that could result in damaging your pool(this goes back to the "I can't make assumptions since you didn't use FreeNAS for the pool creation" and "FreeNAS in a VM == bad"). There's just way too many variables to even think about providing informed assistance with your problem in a forum setting.

Edit: And can you repost your zpool status info in CODE tags? Posting it like you did removed the formatting, so the output is as good as useless.

 

[Richard666]

The pool was created under FreeNAS, the pool history outlines that and I intentionally did it there. I may have done it manually though, but the dataset creation was 100% done through the gui. The only reason I mention I may have issues the command manually is under nas4free it would refuse to do it through the gui, but I believe freenas didn't have the issue. I just didn't want to be involved with running all the commands through commandline as I'm sure I'd miss some settings the gui wouldn't.

zdb -eh rdkmovie01 note: just shows the history for this pool, didn't see anything helpful
http://pastebin.com/L4XWs5Te

The reason the pool lists ata_* is I've imported the pool into Ubuntu, which did it in this fashion. I can go back to freenas so that the zpool/zdb commands show in the expected format, I just haven't as freenas likes to crash while Ubuntu will throw out a dump but keep on going. When I looked at the pool under freenas it showed by gptid, but doing so under Ubuntu is problematic as it changes on reboot. So I believe the equivalent under Ubuntu is by ata-* (aka UUID) which doesn't change, this is the suggested method under Ubuntu these days.

Code:

  pool: rdkmovie01
    id: 530582438526630596
  state: ONLINE
status: The pool was last accessed by another system.
action: The pool can be imported using its name or numeric identifier and
    the '-f' flag.
  see: http://zfsonlinux.org/msg/ZFS-8000-EY
config:
 
    rdkmovie01                                      ONLINE
      raidz3-0                                      ONLINE
        ata-Hitachi_HDS723030ALA640_MK0303YHGD1E3C  ONLINE
        ata-Hitachi_HDS5C4040ALE630_PL2331LAGDL0VJ  ONLINE
        ata-Hitachi_HDS5C4040ALE630_PL2331LAGDP9JJ  ONLINE
        ata-HGST_HDS5C4040ALE630_PL2331LAGHY3PJ    ONLINE
        ata-HGST_HDS5C4040ALE630_PL2331LAGHVHEJ    ONLINE
        ata-Hitachi_HDS5C3030ALA630_MJ1321YNG12WBA  ONLINE
        ata-HGST_HDS5C4040ALE630_PL2331LAGHXRUJ    ONLINE
        ata-Hitachi_HDS5C3030ALA630_MJ1311YNG25LBA  ONLINE
        ata-Hitachi_HDS5C3030ALA630_MJ0351YNG809JA  ONLINE
        ata-Hitachi_HDS5C3030ALA630_MJ1321YNG0VN5A  ONLINE
        ata-HGST_HDS5C4040ALE630_PL2331LAGJ3B3J    ONLINE

I won't argue about the virtualization issues, but I did read the multiple threads here. I chose my hardware in part to satisfy all the suggestions. Also, I currently run the remaining arrays under nas4free and XBMC library scans don't cause a crash. While not directly applicable, I've been running my array under a VM for ~15months now on this hardware. Previously it was under Windows 7 with Flexraid then snapraid+stablebit drivepool. I moved to nas4free initially and struggled to get the gui to work properly. Once freenas added some features I wanted, I migrated over using new 3&4TB drives I purchased for my new arrays. The only hardware issue I've had has been a bad stick of ram, which ECC detected, but that was 6months ago. Each time I ran through 1+ cycles of memtest just to play it safe.

 

[cyberjock]

Ok. Thanks for clarifying a few things. Unfortunately, I'm still out of recommendations that you could try. :(

 

[Richard666]

Thanks for your time regardless, appreciate your taking the time to look things over. I'll hold onto the array for a bit in the hopes I find or someone comments with some things to try. Overall, I view the data as lost at this point, so I won't have an issue trying whatever to recover it. I'll do a follow up post if I get any further.

Just out of curiosity, I take it you haven't seen anything like this before? High level it seems like the underlying structure has some corruption, I guess at object 2368, which seems to boggle the ZFS code causing the trap.

Another shot in the dark, is I've read opensolaris (so I assume openindiana/solaris these days) is the *best* for troubleshooting these issues. Any idea why they'd throw up a 'invalid vdev configuration' when trying to import the pool? I originally thought that was pointing to a label problem (that I've read about a lot), but it didn't seem to pan out as the issue.

 

[cyberjock]

I've seen all sorts of problems as of late. Yours isn't particularly abnormal. Obviously its bad and there are problems. The cause of the problem however is just as important as the error messages themselves.

 

[Richard666]

I wanted to follow up in the hopes it might help someone else down the line:

First: My goal is to load my failed ZFS pool to get the data off.
Second: I knew that the few days prior to my pool crashing, that I had only renamed folders/files and cleaned up duplicate/misnamed folders/files. This meant I would be very likely to get all my data back. Also, my pool could not be imported, so I had to issue commands while it was exported, so extra options are needed (as I mentioned below)

I imagine using a stable version of zfs on Linux under Ubuntu would've worked fine, so would FreeNAS or any other solution supporting my ZFS version + pool version.

I performed all the following on Ubuntu 13.10 and in the hopes that the latest zfs on Linux code changes might help me, I loaded the latest daily experimental build:
https://launchpad.net/~zfs-native/+archive/daily

I found much chat about people having problems with labels being overwritten.

Code:

zdb -lll /dev/disk/by-id/ata-XXXXXX_XXXX_XXXXX | grep ' name: '

I ran this for each disk and verified all 4 labels were present on all devices and all correctly showed my pool name 'rdkmovie01'

In my research, I found the following site which discusses an undocumented import option. It specifically relates to transaction groups. The key here is that I could import the pool using a prior transaction group, basically going back in time before the 'corruption' occurred. In my instance as all disks were intact, recently scrubbed and error free and without issue probably meant this solution was right up my alley.
http://www.c0t0d0s0.org/archives/7621-Back-in-time-or-zpool-import-T.html
Another resource which I found once I knew specifically what I was looking to do, was here: http://lists.freebsd.org/pipermail/freebsd-hackers/2013-July/043131.html

The first thing I needed to figure out was what's the last/current transaction group for my ZFS pool:

Code:

zdb -ue rdkmovie01

-u means to display the uberblock information, -e means work with an exported ZFS pool
This showed

Code:

Uberblock:
     magic = 0000000000bab10c
     version = 28
     txg = 1337019
     guid_sum = 535301744993486743
     timestamp = 1389304807 UTC = Thu Jan  9 17:00:07 2014

So I now know the latest txg (Transaction group). In my case, I decided to do some shots in the dark troubleshooting <insert yeehawww here>

I tried importing my pool just one txg prior:

Code:

zpool import -f -T 1337018 -o readonly=on rdkmovie01

-f forces the pool to import, this was necessary as it was last imported under my FreeNAS system and cannot be imported into another system without this flag, or properly exporting the pool first (not an option in my case)
-T is to define which txg I'm using for my import
-o readonly=on means just that, read only mode, I cannot modify the volume/datasets in this pool once mounted. I'd strongly encourage you to only mount it in readonly mode, to prevent any permanent changes to the pool/volume.

This crashed, so I tried going way back (to save some time) to 1337000 which worked. Encouraged by this, I continue my countdown and found that 1337017 worked. In my case, I've chosen to copy the data off before performing anymore work. I suspect I could mount the pool in read/write using this txg then continue on like nothing happened.

If I wanted to get an idea of the impact of 'how much data' I lost:

Code:

zdb -ul /dev/disk/by-id/ata-XXX-XXX_XXX

This will list all the uberblocks for this disk with a related timestamp (like the command I used above to get the last uberblock for my pool) Scrolling through, I found that my 1337017 txg had a timestamp of 10 seconds prior. Big picture I'd say that was pretty irrelevant in my case.

A big issue with any piece of software is what can be done when something goes wrong, it's not if, it is when... That said, it is sad that ZFS appears to have much of its troubleshooting obscured, because there's no time worse than during downtime to dig in and research for a solution. On the flip side, ZFS was capable of recovering from a scenario that I've seen hardware raid controllers fail under, where you'd be even less likely to find a post on a forum with a solution. Hopefully a simple example like this can help someone down the line recover their pool in minutes, with minimal risk and a rough understanding of the impact to their data.

 

[cyberjock]

1337? Are you leet? I'm kidding, but it was funny to see your transaction number was 1337000. :)

Good guide. While I've seen several people manage partial recoveries this way, I have yet to recover data with it personally. Of course, generally by the time people come to me with a bad pool, it's horribly damaged. So not surprisingly, my success rate would be lower. I had to resort to alternate methods to get data back that were unique to that situation.

 

[jason2g]

Richard666 I am having the same issue and was able to follow your instructions and get the pool imported but I am unable to mount it. Since it is read only I can not change the mount point so I can access the data to copy off. Any help would be appreciated.

 

[zxsystems]

With a mix of your instructions and links, I was able to recover my data and save it off to a non-ZFS resource. Thank you soo much for you help. I tried every option there was and the only thing that worked was from your TXG method command.

I did have a little bit of trouble as I was actually using Nas4Free and the /etc/rc.initdiskless does not exist as stated in this link: http://forums.freenas.org/index.php?threads/zfs-has-failed-you.11951/

So I took a shot in the dark and just ran #sh /etc/rc and let it load the default init script, which let me in. With the diskless setup, your OS is read-only so you won't be able to create the mount points necessary to import the pool. Though, maybe I missed something in that attempt.

Regardless, once I followed the first few commands from the ZFS Has Failed You link, then executed #sh /etc/rc I was able to create the mount points /mnt/ZFSPool/Dataset.

One of the two ways I was able to "see" anything about my missing ZPool was to run "zpool import -d /dev -Fn" This does not import the pool, the -n shows you what it could do.
zpool man page: http://www.freebsd.org/cgi/man.cgi?...FreeBSD+10.0-RELEASE&arch=default&format=html

Once I saw data there and the words ONLINE, I figured there was hope...
So I ran the command from Richard666 "zdb -ue ZFSPool" and was able to obtain the txg.

Fortunately, I was able to execute "zpool import -f -T ### -o readonly=on ZFSPool" where ### was the current TXG - 1.
Almost immediately thereafter, my pool was available. I checked out the mounts and directories and there appeared to be data, so I immediately started copying files off. Skeptical at first I took a few files and opened them to make sure they weren't corrupt and to my surprise, they were fully intact!

So instantly I began an rsync to another NAS device. One of my datasets has completed successfully and now I'm working on another, albeit less critical data, but still not fun to lose data.

So thank you again for everyone's help and hopefully I can be of assistance to someone else! I'm sure I left out some details but if anyone is attempting this without success, reply to the post and see what happens!