Error Unlocking

Scrat_ · Oct 14, 2019

I get this in a pop up window..

Code:

[MiddlewareError: Volume could not be imported: 2 devices failed to decrypt]

Error: Traceback (most recent call last):

  File "/usr/local/lib/python3.6/site-packages/tastypie/resources.py", line 219, in wrapper
    response = callback(request, *args, **kwargs)

  File "./freenasUI/api/resources.py", line 949, in unlock
    form.done(obj)

  File "./freenasUI/storage/forms.py", line 2847, in done
    raise MiddlewareError(msg)

freenasUI.middleware.exceptions.MiddlewareError: [MiddlewareError: Volume could not be imported: 2 devices failed to decrypt]

From the shell pane, I see this..

Code:

freenas# zpool status
  pool: freenas-boot
 state: ONLINE
  scan: scrub repaired 0 in 0 days 00:20:39 with 0 errors on Sat Oct  5 04:05:39 2019
config:

        NAME        STATE     READ WRITE CKSUM
        freenas-boot  ONLINE       0     0     0
          mirror-0  ONLINE       0     0     0
            da4p2   ONLINE       0     0     0
            da5p2   ONLINE       0     0     0

errors: No known data errors

..and this from the bottom activity(?) window..

Code:

Oct 15 00:28:04 freenas uwsgi: [middleware.exceptions:36] [MiddlewareError: Unable to geli attach gptid/cd6e9bff-dcb5-11e8-8358-d0509987dc86: geli: Cannot open gptid/cd6e9bff-dcb5-11e8-8358-d0509987dc86: No such file or directory.
]
Oct 15 00:28:04 freenas uwsgi: [middleware.notifier:615] [MiddlewareError: Unable to geli attach gptid/cd6e9bff-dcb5-11e8-8358-d0509987dc86: geli: Cannot open gptid/cd6e9bff-dcb5-11e8-8358-d0509987dc86: No such file or directory.
]
Oct 15 00:28:04 freenas uwsgi: [middleware.exceptions:36] [MiddlewareError: Unable to geli attach gptid/daec2dfa-dcb5-11e8-8358-d0509987dc86: geli: Cannot open gptid/daec2dfa-dcb5-11e8-8358-d0509987dc86: No such file or directory.
]
Oct 15 00:28:04 freenas uwsgi: [middleware.notifier:615] [MiddlewareError: Unable to geli attach gptid/daec2dfa-dcb5-11e8-8358-d0509987dc86: geli: Cannot open gptid/daec2dfa-dcb5-11e8-8358-d0509987dc86: No such file or directory.
]
Oct 15 00:28:04 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 15 00:28:04 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 15 00:28:04 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 15 00:28:04 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 15 00:28:05 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 15 00:28:06 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 15 00:28:06 freenas uwsgi: [middleware.notifier:1946] Importing databank01 [9906055174888524968] failed with: cannot import 'databank01': one or more devices is currently unavailable
Oct 15 00:28:06 freenas uwsgi: [middleware.exceptions:36] [MiddlewareError: Volume could not be imported: 2 devices failed to decrypt]

I've done some searching. I have removed the cache drives from the array - there was two. FreeNAS no longer sees them. Is the passphrase the same as the root equivalent user, or is it something different? I have geli.key files from before, and I've been able to download one after my now issue.

*presently miffed*

PhiloEpisteme · Oct 15, 2019

What version of FreeNAS are you running?

Scrat_ said:
Is the passphrase the same as the root equivalent user, or is it something different?

No, the passphrase for your pool is different than for your root user. The passphrase is for encryption.

Scrat_ said:
I have geli.key files from before, and I've been able to download one after my now issue.

The User Guide contains many notes about encryption. These notes include specific instructions about when you need to regenerate your keys; such as when adding a new drive or replacing a drive. It is important that you follow the User Guide to the letter in this regard.

Do you have the recovery key as well?

Also, how many drives are in the pool you are trying to unlock? What have you done with that pool lately (such as replaced a disk etc)?

You may find this post useful.

Scrat_ · Oct 15, 2019

FreeNAS v11.2-u6
I have the recovery key from before this mess
4 drives in the pool, I had two cache drives (not sure if that matters)

I took them out and then I put them back in.. but the cache drives are out.

Never forsaw this coming.

Code:

Oct 16 00:12:25 freenas uwsgi: [middleware.notifier:1946] Importing databank01 [9906055174888524968] failed with: cannot import 'databank01': one or more devices is currently unavailable
Oct 16 00:12:26 freenas syslog-ng[5494]: syslog-ng starting up; version='3.20.1'
Oct 16 00:12:26 freenas kernel: pid 3421 (syslog-ng), uid 0: exited on signal 6 (core dumped)

The missing two things that come to mind are the cache drives.

PhiloEpisteme · Oct 15, 2019

Did you try putting the cache drives in? Also, did you reset the passphrase and recovery key after adding the cache drives?

My bet/hope is that the cache drives are all you need here.

Scrat_ · Oct 20, 2019

Yeah, I put the drives I had used as the cache back in.. after I used 'em elsewhere. I don't think they qualify anymore.

If FreeNAS didn't require the cache drives to be validated, would I still get in? If possible, could I get a private release to get access to my data? Or am I thoroughly screwed beyond belief?

PhiloEpisteme · Oct 20, 2019

Scrat_ said:
If FreeNAS didn't require the cache drives to be validated, would I still get in? If possible, could I get a private release to get access to my data? Or am I thoroughly screwed beyond belief?

The cache drives won't matter. You just need the data disks and the keys. I'm a bit late to this game though so a zpool status would help a lot just to make sure I didn't miss anything about the state of affairs you're in.

PhiloEpisteme · Oct 20, 2019

Scrat_ said:
If FreeNAS didn't require the cache drives to be validated, would I still get in?

Yes, very likely. What is the output of zpool import

Scrat_ · Oct 20, 2019

Results..

Code:

freenas# zpool import
   pool: databank01
     id: 9906055174888524968
  state: UNAVAIL
 status: One or more devices are missing from the system.
 action: The pool cannot be imported. Attach the missing
        devices and try again.
   see: http://illumos.org/msg/ZFS-8000-6X
 config:

        databank01                                          UNAVAIL  missing device
          raidz1-0                                          ONLINE
            gptid/92916e9a-acbf-11e8-bb20-d0509987dc86.eli  ONLINE
            gptid/979acf23-acbf-11e8-bb20-d0509987dc86.eli  ONLINE
            gptid/9d9dbfc2-acbf-11e8-bb20-d0509987dc86.eli  ONLINE
            gptid/a2b34942-acbf-11e8-bb20-d0509987dc86.eli  ONLINE
        logs
          14841255592024334244                              UNAVAIL  cannot open

        Additional devices are known to be part of this pool, though their
        exact configuration cannot be determined.

The logs were on a cache drive.. ugh. If I'm not mistaken at least.

PhiloEpisteme · Oct 20, 2019

Okay great. We can import this pool through the command line for sure.

If I were you I'd run the following command. zpool import -m databank01. The -m flag will tell the system to ignore that log device and move on.

Now, two very important questions.

First, what does the GUI show? Is your pool visible? If so, great! If not, no worries we can fix that.

Second, and most importantly; are you 100% certain that you have the correct keys? You should have two keys geli.key and geli_recovery.key. If you didn't click "Add Recovery Key" after doing any resilvering etc of the main data disks on the pool your keys may be out of date. If so, we should take the chance now to fix them. I recommend you not restart your server (or lock the pool) until you're sure that you have the right keys since a restart will lock the pool and without the correct keys you can't open it again.

If you're certain that you have the correct geli keys you can just export your pool via the CLI, export it via the GUI (if it shows up) and then reimport it via the GUI. If you're not certain you have the correct geli keys you may want to hold off on that until you fix the keys.

Scrat_ · Oct 20, 2019

I've never had to do any resilvering. Never seen a spot for downloading a geli_recovery.key file.

Under storage, 'databank01' is visible.. with a yellow lock symbol beside it.

This is the first time my FreeNAS server has had an issue with my tinkering. It never complained (that stood out to me) about my key when I tried to import my storage.

--
Stress level is down partly now.. thank you! Now, I just hope I can recall the smartass phrase I used. Something I'd hoped the key wouldn't require.

PhiloEpisteme · Oct 20, 2019

Scrat_ said:
Never seen a spot for downloading a geli_recovery.key file.

This is downloaded by clicking the lock for the pool and clicking "Add Recovery Key".

Scrat_ said:
Under storage, 'databank01' is visible.. with a yellow lock symbol beside it.

Do you mind sending a screen shot? I suspect that the UI just doesn't know the pool is now imported and unlocked. You may need to export it and reimport it again via the GUI for it to work.

Scrat_ said:
This is the first time my FreeNAS server has had an issue with my tinkering. It never complained (that stood out to me) about my key when I tried to import my storage.

This is a good sign; if you can import it with your key and you haven't changed the disks it is definitely the correct one.

Did you import the pool with the command from the above?

Scrat_ · Oct 20, 2019

I'm getting this after I rebooted the server..

Code:

Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:29 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:30 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:31 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:32 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:33 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=14841255592024334244
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=12734363457240657830
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=10475122516117072403
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=387696117640772092
Oct 20 22:38:34 freenas ZFS: vdev state changed, pool_guid=9906055174888524968 vdev_guid=4680114721152768678

It's just cycling away.

Scrat_ · Oct 20, 2019

Netdata stats..

Oct 20 23:11:31 freenas zfsd: Consumer::EventsPending(): POLLHUP detected on devd socket. must have something to do with the system trying to get disk information since I'm on the 'pools' page..?

PhiloEpisteme · Oct 21, 2019

What about zpool status and a screen shot of the pools screen?

Scrat_ · Oct 22, 2019

Pool and disk listing pain.. For some reason they don't show up after reboot. prior, you I saw the pool list as in the screenshot up there ^^

Scrat_ · Oct 22, 2019

I got this on shutdown..

PhiloEpisteme · Oct 23, 2019

Sorry, above I was talking about the output of zpool status copy-pasted here. zpool import would also likely be useful.

Scrat_ · Nov 10, 2019

Sorry for the delay on the issue. I've had a very hectic last while. I've since been laid off work for the season, so I can really spend time troubleshooting my issues.
--
zpool status:

Code:

freenas# zpool status
  pool: databank01
 state: UNAVAIL
status: One or more devices could not be opened.  There are insufficient
        replicas for the pool to continue functioning.
action: Attach the missing device and online it using 'zpool online'.
   see: http://illumos.org/msg/ZFS-8000-3C
  scan: none requested
config:

        NAME                      STATE     READ WRITE CKSUM
        databank01                UNAVAIL      0     0     0
          raidz1-0                UNAVAIL      0     0     0
            12734363457240657830  UNAVAIL      0     0     0  was /dev/gptid/92916e9a-acbf-11e8-bb20-d0509987dc86.eli
            10475122516117072403  UNAVAIL      0     0     0  was /dev/gptid/979acf23-acbf-11e8-bb20-d0509987dc86.eli
            387696117640772092    UNAVAIL      0     0     0  was /dev/gptid/9d9dbfc2-acbf-11e8-bb20-d0509987dc86.eli
            4680114721152768678   UNAVAIL      0     0     0  was /dev/gptid/a2b34942-acbf-11e8-bb20-d0509987dc86.eli
        logs
          14841255592024334244    UNAVAIL      0     0     0  was /dev/gptid/daec2dfa-dcb5-11e8-8358-d0509987dc86.eli

  pool: freenas-boot
 state: ONLINE
  scan: scrub repaired 0 in 0 days 00:21:56 with 0 errors on Tue Oct 15 04:06:56 2019
config:

        NAME        STATE     READ WRITE CKSUM
        freenas-boot  ONLINE       0     0     0
          mirror-0  ONLINE       0     0     0
            da4p2   ONLINE       0     0     0
            da5p2   ONLINE       0     0     0

errors: No known data errors

zpool import: no result

Scrat_ · Nov 10, 2019

Did a reboot, got this from the activity pane:

Code:

Nov 10 22:28:06 freenas da5: 40.000MB/s transfers
Nov 10 22:28:06 freenas da5: 15264MB (31260672 512 byte sectors)
Nov 10 22:28:06 freenas da5: quirks=0x2<NO_6_BYTE>
Nov 10 22:28:06 freenas da4: Serial Number 4C531001480511121014
Nov 10 22:28:06 freenas da4: 40.000MB/s transfers
Nov 10 22:28:06 freenas da4: 15264MB (31260672 512 byte sectors)
Nov 10 22:28:06 freenas da4: quirks=0x2<NO_6_BYTE>
Nov 10 22:28:06 freenas da3 at mps0 bus 0 scbus0 target 3 lun 0
Nov 10 22:28:06 freenas da3: <ATA ST4000VN008-2DR1 SC60> Fixed Direct Access SPC-4 SCSI device
Nov 10 22:28:06 freenas da3: Serial Number ZDH16CMP
Nov 10 22:28:06 freenas da3: 600.000MB/s transfers
Nov 10 22:28:06 freenas da3: Command Queueing enabled
Nov 10 22:28:06 freenas da3: 3815447MB (7814037168 512 byte sectors)
Nov 10 22:28:06 freenas da2 at mps0 bus 0 scbus0 target 2 lun 0
Nov 10 22:28:06 freenas da2: <ATA ST4000VN008-2DR1 SC60> Fixed Direct Access SPC-4 SCSI device
Nov 10 22:28:06 freenas da2: Serial Number ZGY002G6
Nov 10 22:28:06 freenas da2: 600.000MB/s transfers
Nov 10 22:28:06 freenas da2: Command Queueing enabled
Nov 10 22:28:06 freenas da2: 3815447MB (7814037168 512 byte sectors)
Nov 10 22:28:06 freenas da1 at mps0 bus 0 scbus0 target 1 lun 0
Nov 10 22:28:06 freenas da1: <ATA ST4000VN008-2DR1 SC60> Fixed Direct Access SPC-4 SCSI device
Nov 10 22:28:06 freenas da1: Serial Number ZGY0025Z
Nov 10 22:28:06 freenas da1: 600.000MB/s transfers
Nov 10 22:28:06 freenas da1: Command Queueing enabled
Nov 10 22:28:06 freenas da1: 3815447MB (7814037168 512 byte sectors)
Nov 10 22:28:06 freenas da0 at mps0 bus 0 scbus0 target 0 lun 0
Nov 10 22:28:06 freenas da0: <ATA ST4000VN008-2DR1 SC60> Fixed Direct Access SPC-4 SCSI device
Nov 10 22:28:06 freenas da0: Serial Number ZDH16L77
Nov 10 22:28:06 freenas da0: 600.000MB/s transfers
Nov 10 22:28:06 freenas da0: Command Queueing enabled
Nov 10 22:28:06 freenas da0: 3815447MB (7814037168 512 byte sectors)
Nov 10 22:28:06 freenas Trying to mount root from zfs:freenas-boot/ROOT/11.2-U6 []...
Nov 10 22:28:06 freenas kernel: igb0: link state changed to UP
Nov 10 22:28:06 freenas kernel: igb0: link state changed to UP
Nov 10 22:28:06 freenas kernel: igb1: link state changed to UP
Nov 10 22:28:06 freenas kernel: igb1: link state changed to UP
Nov 10 22:28:06 freenas GEOM_MIRROR: Cannot open consumer da3p1 (error=1).
Nov 10 22:28:06 freenas GEOM_MIRROR: Device swap0 destroyed.
Nov 10 22:28:06 freenas GEOM_MIRROR: Device mirror/swap0 launched (2/2).
Nov 10 22:28:06 freenas GEOM_ELI: Device mirror/swap0.eli created.
Nov 10 22:28:06 freenas GEOM_ELI: Encryption: AES-XTS 128
Nov 10 22:28:06 freenas GEOM_ELI:     Crypto: hardware
Nov 10 22:28:06 freenas hwpmc: SOFT/16/64/0x67<INT,USR,SYS,REA,WRI> TSC/1/64/0x20<REA> IAP/4/48/0x3ff<INT,USR,SYS,EDG,THR,REA,WRI,INV,QUA,PRC> IAF/3/48/0x67<INT,USR,SYS,REA,WRI>
Nov 10 22:28:06 freenas kernel: igb0: link state changed to DOWN
Nov 10 22:28:06 freenas kernel: igb0: link state changed to DOWN
Nov 10 22:28:06 freenas kernel: igb0: link state changed to UP
Nov 10 22:28:06 freenas kernel: igb0: link state changed to UP
Nov 10 22:28:06 freenas nfsd: can't register svc name
Nov 10 22:28:06 freenas ntpd[3179]: ntpd 4.2.8p11-a (1): Starting

PhiloEpisteme · Nov 12, 2019

Scrat_ said:
I'm getting this after I rebooted the server..

Depending on what is wrong you don't want to reboot your server until you are completely done getting everything set correctly. Even if the pool unlocks doesn't necessarily mean all the work is complete.

To be 100% honest I'm not 100% sure what all of the error output is that you are experiencing. I can, however, try to troubleshoot the pool that isn't visible anymore. Can you answer all of the following questions? It'll help give me an idea of what your exact situation is.

First, since you're using 11.2-U6 can you please show me the output of the storage->pools disk screen with only "Pool", "Serial Number", and "Disk Size" selected under columns? I'm interested in seeing what available disks your system sees at all.

Then, can I see the output of this command? It will tell me the output of the following two commands sqlite3 /data/freenas-v1.db 'select * from storage_volume' and sqlite3 /data/freenas-v1.db 'select * from storage_encrypteddisk'?

And, to clarify, what encryption keys do you have for your pool? Every pool has 1 and can have 2 keys to download associated with it.

Important Announcement for The TrueNAS Community.

Error Unlocking

Explorer

Guru

Explorer

Guru

Explorer

Guru

Guru

Explorer

Guru

Explorer

Attachments

Guru

Explorer

Explorer

Attachments

Guru

Explorer

Attachments

Explorer

Attachments

Guru

Explorer

Explorer

Guru

Similar threads

Important Announcement for The TrueNAS Community.