Hanging after decrypting ZFS volume

[Dr.T]

Hello, everyone.
For the last weeks I have one strange problem - after decrypting ZFS volume FreeNAS is restarting some services and stuck on "Stopping collectd".
I've completely reinstalled FreeNAS, imported previous settings and geli-key and now it's the same!
If I leave it overnight - it properly finishing. But it's abnormally and annoying.
How can I diagnose this problem?
Thank you!

 

[Ericloewe]

FreeNAS version and hardware?

 

[Dr.T]

Last version 9.2.1.9 installed from CD ISO on ESXi 5.5 (8 vCPU, 16GB RAM, LSI SAS @IT), previously worked fine!
Real hardware: Supermicro X10SL7-F, 24GB ECC RAM, Xeon 1230v3.

Code:

Dec  3 20:53:01 freenas notifier: Stopping collectd.
Dec  3 21:21:31 freenas winbindd[2640]:   STATUS=daemon 'winbindd' finished starting up and ready to serve connections[ 5707]: request interface version
Dec  3 22:50:23 freenas notifier: Waiting for PIDS: 3025.
Dec  3 22:50:23 freenas notifier: Starting collectd.
Dec  3 22:50:41 freenas notifier: geli: Cannot access da1p1 (error=1).
Dec  3 22:50:41 freenas notifier: Stopping collectd.
Dec  3 22:50:43 freenas notifier: Waiting for PIDS: 8167.
Dec  3 22:50:43 freenas notifier: Starting collectd.

 

[Dr.T]

Right now it stuck at "stooping collectd" again.
Ok, trying to stop 'collectd' from ssh connection:

Code:

[root@freenas] ~# /usr/local/etc/rc.d/collectd restart
Stopping collectd.
Waiting for PIDS: 3047

can't stop, trying to find something with PID 3047

Code:

[root@freenas] ~# fstat -p 3047

USER     CMD          PID   FD MOUNT      INUM MODE         SZ|DV R/W
root     collectd    3047 text /        116122 -r-xr-xr-x  148984  r
root     collectd    3047   wd /var      15445 drwxr-xr-x     512  r
root     collectd    3047 root /             2 drwxr-xr-x     512  r
root     collectd    3047    0 /dev         15 crw-rw-rw-    null rw
root     collectd    3047    1 /dev         15 crw-rw-rw-    null rw
root     collectd    3047    2 /dev         15 crw-rw-rw-    null rw
root     collectd    3047    3 /dev         11 crw-r-----     mem  r
root     collectd    3047    4 /dev         12 crw-r-----    kmem  r

is everything ok here?

And "top" output:

Code:

[root@freenas] ~# top
last pid:  5459;  load averages:  0.08,  0.04,  0.01    up 0+00:55:23  21:03:55
49 processes:  1 running, 42 sleeping, 6 stopped
CPU:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  100% idle
Mem: 169M Active, 75M Inact, 371M Wired, 1168K Cache, 82M Buf, 15G Free
ARC: 3664K Total, 1824K MFU, 1209K MRU, 16K Anon, 104K Header, 511K Other
Swap: 14G Total, 14G Free

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME   WCPU COMMAND
 2808 root          6  20    0   279M   101M usem    4   0:03  0.00% python2.7
 2144 root          2  52    0 59504K  4748K select  4   0:01  0.00% vmtoolsd
 3011 root          2  52    0 87700K  8392K select  6   0:00  0.00% afpd
 3746 root          1  52    0   158M 46760K ttyin   4   0:00  0.00% python2.7
 3053 root          4  52    0   168M 46408K select  2   0:00  0.00% python2.7
 2984 www           1  20    0 26040K  5968K kqread  4   0:00  0.00% nginx
 2654 root          1  20    0   208M 12448K select  3   0:00  0.00% nmbd
 2336 root          1  20    0 22212K  3876K select  6   0:00  0.00% ntpd
 3004 root          1  20    0 36920K  4860K kqread  6   0:00  0.00% netatalk
 2684 root          1  32   10 18588K  3228K wait    0   0:00  0.00% sh
 2579 root          1  20    0 34320K  4992K select  3   0:00  0.00% proftpd
 4773 root          1  20    0 71708K  5996K select  0   0:00  0.00% sshd
 4075 root          1  52    0 14492K  2700K wait    7   0:00  0.00% sh
 4776 root          1  20    0 17516K  3476K pause   7   0:00  0.00% csh
 5346 www           1  20    0 26040K  5620K kqread  5   0:00  0.00% nginx

What else can I do? :(

 

[SweetAndLow]

Have you changed any seeing around the .system dataset or were you store collectd graph information?

 

[Dr.T]

Ok, got your point. I always had one encrypted zfs volume and therefore it was marked as system dataset in settings.
I just created a new 8GB disk for new unencrypted volume, attached encrypted volume, changed "system dataset" to new one. FreeNAS reported OK.
After reboot, problem still remains, right now for last 1h 09m still I see last message "stopping collectd". I can close "Unlock" window, and access my volume, but services are not restarted (shares, jails etc.)

 

[Dr.T]

Finally it ended. Took 2 hours:

Code:

...
Dec 7 08:23:23 freenas kernel: GEOM_ELI: Encryption: AES-XTS 128
Dec 7 08:23:23 freenas kernel: GEOM_ELI: Crypto: hardware
Dec 7 08:23:36 freenas notifier: Stopping collectd.
Dec 7 09:39:43 freenas winbindd[2837]: STATUS=daemon 'winbindd' finished starting up and ready to serve connections[ 5592]: request interface version
Dec 7 10:21:37 freenas nmbd[2831]: [2014/12/07 10:21:37.658768, 0] ../source3/nmbd/nmbd_become_lmb.c:397(become_local_master_stage2)
...