Unlocking Encrypted Pool: "Please Wait"

tyskiegronie

Cadet
Joined
Sep 2, 2016
Messages
6
Hello,

my NAS restarted itself an hour ago.
When I tried to unlock my encrypted pool, the system didn't react for a long time. Only the loading bar with the message "Please Wait" was visible.

After about 10 minutes the pool was available.
All discs show the status "ONLINE". What can this be?
So far, the unlock only lasted a few seconds.

I have not restarted the system since the beginning of July.

Thank you in advance.
 
D

dlavigne

Guest
Which version of FreeNAS?

Anything in /var/log/messages around the time you unlocked the pool?
 

tyskiegronie

Cadet
Joined
Sep 2, 2016
Messages
6
Hello,

Thank you for your message. I couldn't reproduce the problem anymore.

I looked at the time period in the log. Unfortunately I can't see anything in it.
At 00:32 the pool was unlocked. I entered the password wrong as you can see.

Then the volumes were imported and the system did "nothing" for 10 minutes.
Maybe you can read something interesting?

Sep 15 00:30:48 freenas Trying to mount root from zfs:freenas-boot/ROOT/11.2-U5 []...
Sep 15 00:30:48 freenas da0 at umass-sim0 bus 0 scbus7 target 0 lun 0
Sep 15 00:30:48 freenas da0: <SanDisk Cruzer Fit 1.00> Removable Direct Access SPC-4 SCSI device
Sep 15 00:30:48 freenas da0: Serial Number 4C531001540522116562
Sep 15 00:30:48 freenas da0: 40.000MB/s transfers
Sep 15 00:30:48 freenas da0: 7632MB (15630336 512 byte sectors)
Sep 15 00:30:48 freenas da0: quirks=0x2<NO_6_BYTE>
Sep 15 00:30:48 freenas GEOM_MIRROR: Device mirror/swap0 launched (2/2).
Sep 15 00:30:48 freenas GEOM_MIRROR: Device mirror/swap1 launched (2/2).
Sep 15 00:30:48 freenas GEOM_ELI: Device mirror/swap0.eli created.
Sep 15 00:30:48 freenas GEOM_ELI: Encryption: AES-XTS 128
Sep 15 00:30:48 freenas GEOM_ELI: Crypto: hardware
Sep 15 00:30:48 freenas GEOM_ELI: Device mirror/swap1.eli created.
Sep 15 00:30:48 freenas GEOM_ELI: Encryption: AES-XTS 128
Sep 15 00:30:48 freenas GEOM_ELI: Crypto: hardware
Sep 15 00:30:48 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>
Sep 15 00:30:48 freenas kernel: bge0: link state changed to DOWN
Sep 15 00:30:48 freenas kernel: bge0: link state changed to DOWN
Sep 15 00:30:48 freenas kernel: bge0: link state changed to UP
Sep 15 00:30:48 freenas kernel: bge0: link state changed to UP
Sep 15 00:30:48 freenas ntpd[2781]: ntpd 4.2.8p11-a (1): Starting
Sep 15 00:32:34 freenas uwsgi: [middleware.exceptions:36] [MiddlewareError: Unable to geli attach gptid/8a6a2051-71b6-11e6-a1f3-1c98ec0fa454: geli: Wrong key for gptid/8a6a2051-71b6-11e6-a1f3-1c98ec0fa454.
]
Sep 15 00:32:34 freenas uwsgi: [middleware.notifier:615] [MiddlewareError: Unable to geli attach gptid/8a6a2051-71b6-11e6-a1f3-1c98ec0fa454: geli: Wrong key for gptid/8a6a2051-71b6-11e6-a1f3-1c98ec0fa454.
]
Sep 15 00:32:35 freenas uwsgi: [middleware.exceptions:36] [MiddlewareError: Unable to geli attach gptid/8b1d3adf-71b6-11e6-a1f3-1c98ec0fa454: geli: Wrong key for gptid/8b1d3adf-71b6-11e6-a1f3-1c98ec0fa454.
]
Sep 15 00:32:35 freenas uwsgi: [middleware.notifier:615] [MiddlewareError: Unable to geli attach gptid/8b1d3adf-71b6-11e6-a1f3-1c98ec0fa454: geli: Wrong key for gptid/8b1d3adf-71b6-11e6-a1f3-1c98ec0fa454.
]
Sep 15 00:32:36 freenas uwsgi: [middleware.exceptions:36] [MiddlewareError: Unable to geli attach gptid/936055dc-d539-11e7-93fb-1c98ec0fa454: geli: Wrong key for gptid/936055dc-d539-11e7-93fb-1c98ec0fa454.
]
Sep 15 00:32:36 freenas uwsgi: [middleware.notifier:615] [MiddlewareError: Unable to geli attach gptid/936055dc-d539-11e7-93fb-1c98ec0fa454: geli: Wrong key for gptid/936055dc-d539-11e7-93fb-1c98ec0fa454.
]
Sep 15 00:32:37 freenas uwsgi: [middleware.exceptions:36] [MiddlewareError: Unable to geli attach gptid/f6ba12d1-f18c-11e7-9faa-1c98ec0fa454: geli: Wrong key for gptid/f6ba12d1-f18c-11e7-9faa-1c98ec0fa454.
]
Sep 15 00:32:37 freenas uwsgi: [middleware.notifier:615] [MiddlewareError: Unable to geli attach gptid/f6ba12d1-f18c-11e7-9faa-1c98ec0fa454: geli: Wrong key for gptid/f6ba12d1-f18c-11e7-9faa-1c98ec0fa454.
]
Sep 15 00:32:37 freenas uwsgi: [middleware.notifier:1946] Importing RaidZEncrypted [2867213269513891646] failed with: cannot import '2867213269513891646': no such pool available
Sep 15 00:32:37 freenas uwsgi: [middleware.exceptions:36] [MiddlewareError: Volume could not be imported: 4 devices failed to decrypt]
Sep 15 00:32:44 freenas GEOM_ELI: Device gptid/8a6a2051-71b6-11e6-a1f3-1c98ec0fa454.eli created.
Sep 15 00:32:44 freenas GEOM_ELI: Encryption: AES-XTS 128
Sep 15 00:32:44 freenas GEOM_ELI: Crypto: hardware
Sep 15 00:32:45 freenas GEOM_ELI: Device gptid/8b1d3adf-71b6-11e6-a1f3-1c98ec0fa454.eli created.
Sep 15 00:32:45 freenas GEOM_ELI: Encryption: AES-XTS 128
Sep 15 00:32:45 freenas GEOM_ELI: Crypto: hardware
Sep 15 00:32:47 freenas GEOM_ELI: Device gptid/936055dc-d539-11e7-93fb-1c98ec0fa454.eli created.
Sep 15 00:32:47 freenas GEOM_ELI: Encryption: AES-XTS 256
Sep 15 00:32:47 freenas GEOM_ELI: Crypto: hardware
Sep 15 00:32:48 freenas GEOM_ELI: Device gptid/f6ba12d1-f18c-11e7-9faa-1c98ec0fa454.eli created.
Sep 15 00:32:48 freenas GEOM_ELI: Encryption: AES-XTS 256
Sep 15 00:32:48 freenas GEOM_ELI: Crypto: hardware
Sep 15 00:32:48 freenas ZFS: vdev state changed, pool_guid=2867213269513891646 vdev_guid=9848498471467627530
Sep 15 00:32:48 freenas ZFS: vdev state changed, pool_guid=2867213269513891646 vdev_guid=8693254169734777049
Sep 15 00:32:48 freenas ZFS: vdev state changed, pool_guid=2867213269513891646 vdev_guid=15068223102976522531
Sep 15 00:32:48 freenas ZFS: vdev state changed, pool_guid=2867213269513891646 vdev_guid=11591239326602827583
Sep 15 00:32:48 freenas ZFS: vdev state changed, pool_guid=2867213269513891646 vdev_guid=9848498471467627530
Sep 15 00:32:48 freenas ZFS: vdev state changed, pool_guid=2867213269513891646 vdev_guid=8693254169734777049
Sep 15 00:32:48 freenas ZFS: vdev state changed, pool_guid=2867213269513891646 vdev_guid=15068223102976522531
Sep 15 00:32:48 freenas ZFS: vdev state changed, pool_guid=2867213269513891646 vdev_guid=11591239326602827583
Sep 15 00:41:04 freenas syslog-ng[2297]: syslog-ng shutting down; version='3.20.1'
Sep 15 00:41:04 freenas syslog-ng[5769]: syslog-ng starting up; version='3.20.1'
Sep 15 00:44:40 freenas bridge0: Ethernet address: 02:94:ee:e0:ae:00
Sep 15 00:44:40 freenas kernel: bge0: promiscuous mode enabled
Sep 15 00:44:40 freenas kernel: bridge0: link state changed to UP
Sep 15 00:44:40 freenas kernel: bridge0: link state changed to UP
Sep 15 00:44:40 freenas epair0a: Ethernet address: 02:4d:d0:00:05:0a
Sep 15 00:44:40 freenas epair0b: Ethernet address: 02:4d:d0:00:06:0b
Sep 15 00:44:40 freenas kernel: epair0a: link state changed to UP
Sep 15 00:44:40 freenas kernel: epair0a: link state changed to UP
Sep 15 00:44:40 freenas kernel: epair0b: link state changed to UP
Sep 15 00:44:40 freenas kernel: epair0b: link state changed to UP
Sep 15 00:44:40 freenas kernel: epair0a: changing name to 'vnet0:1'
Sep 15 00:44:45 freenas kernel: vnet0:1: promiscuous mode enabled
Sep 15 00:46:56 freenas tap0: Ethernet address: 00:bd:af:52:06:00
Sep 15 00:46:56 freenas kernel: tap0: promiscuous mode enabled
Sep 15 00:46:56 freenas kernel: tap0: link state changed to UP
Sep 15 00:46:56 freenas kernel: tap0: link state changed to UP
Sep 15 00:46:58 freenas tap1: Ethernet address: 00:bd:21:5a:06:01
Sep 15 00:46:58 freenas kernel: tap1: promiscuous mode enabled
Sep 15 00:46:58 freenas kernel: tap1: link state changed to UP
Sep 15 00:46:58 freenas kernel: tap1: link state changed to UP
Sep 16 00:00:00 freenas newsyslog[47404]: logfile turned over due to size>200K
 
Top