9.2.0.1 Fresh Install Bug Report

[WarrenV]

Hello,

I've recently migrated back to NAS4Free from FreeNAS, and have the following bug to report:

1: When creating a ZFS Pool, the web configuration database easily seems to lose track of the current ZFS configuration, which leads to unresolvable "The configuration has been changed" messages.

My pool config:

pool: ppool
state: ONLINE
scan: none requested
config:

NAME STATE READ WRITE CKSUM
ppool ONLINE 0 0 0
mirror-0 ONLINE 0 0 0
ada0 ONLINE 0 0 0
da0 ONLINE 0 0 0
mirror-1 ONLINE 0 0 0
ada1 ONLINE 0 0 0
da1 ONLINE 0 0 0
mirror-2 ONLINE 0 0 0
ada2 ONLINE 0 0 0
da5 ONLINE 0 0 0
logs
mirror-3 ONLINE 0 0 0
ada3 ONLINE 0 0 0
da2 ONLINE 0 0 0
cache
da3 ONLINE 0 0 0
spares
da4 AVAIL

errors: No known data errors

Attempting to re-apply the config, changing the config, as well as deleting the zpool and starting over has no effect. I can see NAS4Free is umounting and mounting the pool in the system log, but the error persists.

Attempting synchronization has no effect.

Ultimately, I think there needs to be a mechanism to see exactly what the gui is attempting to do. I do not see any logging features for the gui, nor do I have a way to easily dump the configuration parameters that the gui is storing.

[WarrenV]

Additional bug has cropped up that is forcing me to bail out of 9.2.0.1 and revert to 9.1.0.1:

Over about a 24-hour period, a persistent performance loss accumulates to the point where the system becomes unresponsive.

Vmstat shows the following relevant stats based on 16GB of RAM:

sanbox: ~ # vmstat -m

Type InUse MemUse HighUse Requests Size(s)

temp 84 37K - 58848159 16,32,64,128,256,512,1024,2048,4096
cred 48 8K - 209254992 64,256
iov 0 0K - 504229590 16,64,128,256,512
solaris 44630270 7075053K - 1021203861 16,32,64,128,256,512,1024,2048,4096

sanbox: ~ # vmstat -z

ITEM SIZE LIMIT USED FREE REQ FAIL SLEEP

UMA Slabs: 568, 0, 655579, 110725,301253324, 0, 0

64 Bucket: 536, 0, 283, 4, 299, 187, 0
128 Bucket: 1048, 0, 8567, 226, 135547,190792, 0

KMAP ENTRY: 120, 576414, 77875, 12552,880446331, 0, 0
32: 32, 0,43534714, 63552,186353496, 0, 0
64: 64, 0, 193417, 111783,766097384, 0, 0
128: 128, 0, 29129, 973,234878158, 0, 0
256: 256, 0, 91145, 77095,289267097, 0, 0
mbuf_packet: 256, 0, 5115, 3333,584137705, 0, 0
mbuf: 256, 0, 21493, 1934,3451074161, 0, 0
mbuf_jumbo_page: 4096, 262144, 0, 804,25924861, 0, 0
mbuf_jumbo_9k: 9216, 131072, 21491, 1844,192855130, 0, 0
zio_cache: 944, 0, 1, 157503,372180485, 0, 0
zio_link_cache: 48, 0, 0, 159120,367251723, 0, 0
dmu_buf_impl_t: 224, 0, 712440, 105124,231915175, 0, 0
selfd: 56, 0, 164, 970,930701228, 0, 0


I think the large bucket fails are the giveaway. All other vmstat entries were small/normal. All configuration parameters are essentially default (no tuning, essentially default samba/zfs/iscsi config).

Here is my ZFS config:

sanbox: ~ # zpool status
pool: ppool
state: ONLINE
scan: none requested
config:

NAME STATE READ WRITE CKSUM
ppool ONLINE 0 0 0
mirror-0 ONLINE 0 0 0
ada0 ONLINE 0 0 0
da0 ONLINE 0 0 0
mirror-1 ONLINE 0 0 0
ada1 ONLINE 0 0 0
da1 ONLINE 0 0 0
mirror-2 ONLINE 0 0 0
ada2 ONLINE 0 0 0
da5 ONLINE 0 0 0
logs
mirror-3 ONLINE 0 0 0
ada3 ONLINE 0 0 0
da2 ONLINE 0 0 0
cache
da3 ONLINE 0 0 0
spares
da4 AVAIL

errors: No known data errors

The hardware is:
x64-embedded on Intel(R) Xeon(R) CPU E3-1240 v3 @ 3.40GHz
Supermicro X10SLH-F/X10SLM+-F

Six 3-TB Seagate Barracuda XTs in three mirror pairs
Two 120GB Kingston Hyper-X SSD in a ZIL Mirrored pair
One 120GB Kingston Hyper-X SSD for L2ARC
One 3-TB Seagate Barracuda XT as a Hotspare

This looks like a ZFS memory hole to me. I'll play with the ARC cache allocation numbers a bit, but I did not have this problem with 9.1.0.1, over several months of runtime.

[raulfg3]

do you try zfskerntune?

viewtopic.php?f=71&t=1278

[WarrenV]

Yes, I did, and it had no effect. I was able to get the following while reproducing the issue:

last pid: 22360; load averages: 0.10, 0.06, 0.03 up 0+23:51:3601:33:00
21 processes: 1 running, 20 sleeping
CPU: % user, % nice, % system, % interrupt, % idle
Mem: 42M Active, 131M Inact, 14G Wired, 49M Buf, 1477M Free
ARC: 10G Total, 302M MFU, 5122M MRU, 144K Anon, 5403M Header, 252M Other
Swap: 16G Total, 16G Free

PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND
5945 root 1 20 0 12084K 1484K select 1 2:57 0.59% powerd
22309 root 1 21 0 16612K 3488K pause 7 0:00 0.10% csh
14574 root 28 20 0 256M 99428K uwait 3 15:14 0.00% istgt
3531 root 1 31 0 39416K 6560K kqread 0 0:06 0.00% lighttpd
7010 root 1 22 0 56272K 5116K select 0 0:04 0.00% sshd
16085 root 1 21 0 71000K 5540K select 0 0:01 0.00% sshd
3028 root 1 20 0 12112K 1620K select 0 0:01 0.00% syslogd
4930 root 1 20 0 14176K 1772K nanslp 5 0:00 0.00% cron
7012 root 1 20 0 14508K 3428K ttyin 6 0:00 0.00% csh
2811 root 1 20 0 6280K 548K select 3 0:00 0.00% devd
16087 root 1 20 0 16612K 3424K ttyin 5 0:00 0.00% csh
17993 root 1 20 0 25984K 3768K nanslp 0 0:00 0.00% smartd
22311 root 1 52 0 91660K 19116K nanslp 4 0:00 0.00% php-cgi
22255 root 1 20 0 71000K 5492K select 5 0:00 0.00% sshd
3373 root 1 20 0 28908K 3992K select 2 0:00 0.00% sshd
3618 root 1 52 0 14508K 3124K pause 4 0:00 0.00% csh

A few comments:

1: Powerd has no effect on the issue, on or off.
2: I was able to check the vmstat entries against the latest 9.2 FreeNAS, and found comparable cluster allocation fails, so that may not be an indicator.
3: A few measurables: after nearly a day of uptime, when the top output was taken, ssh login time had gone from instantaneous to 50+ seconds. Also, generating top output from the gui would consistently hang, and most of the gui was sluggish, although some portions came up quickly.
4: I've never seen php-cgi be stuck in nanosleep on a NAS4Free build before, so I'm now thinking this is a php problem.
5: I reverted to build 943, and have been running for a few hours now without issue. I see the ARC picking up more memory, as expected:

last pid: 6622; load averages: 0.00, 0.02, 0.01 up 0+00:36:50 01:36:59
27 processes: 1 running, 26 sleeping
CPU: 0.0% user, 0.0% nice, 0.1% system, 0.0% interrupt, 99.9% idle
Mem: 50M Active, 91M Inact, 1998M Wired, 15M Buf, 13G Free
ARC: 1273M Total, 290M MFU, 908M MRU, 240K Anon, 42M Header, 32M Other
Swap: 16G Total, 16G Free

PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND
3216 root 28 20 0 215M 77964K uwait 1 0:03 0.00% istgt
6022 root 1 20 0 86572K 14072K select 7 0:00 0.00% smbd
5262 root 1 20 0 18700K 2572K ttyout 7 0:00 0.00% top
3644 root 1 52 0 39412K 5860K kqread 3 0:00 0.00% lighttpd
3363 root 1 20 0 78128K 10872K select 6 0:00 0.00% winbindd
3373 root 1 20 0 78128K 10844K select 2 0:00 0.00% winbindd
3360 root 1 20 0 79744K 11752K select 4 0:00 0.00% smbd
3045 root 1 20 0 12112K 1728K select 6 0:00 0.00% syslogd
4837 root 1 20 0 70988K 5416K select 1 0:00 0.00% sshd
3357 root 1 20 0 67576K 7368K select 4 0:00 0.00% nmbd
6107 root 1 20 0 70988K 5416K select 3 0:00 0.00% sshd
3447 root 1 20 0 25984K 3972K nanslp 6 0:00 0.00% smartd
6109 root 1 20 0 16612K 3492K pause 6 0:00 0.00% csh
4894 root 1 20 0 16612K 3488K pause 3 0:00 0.00% csh
3745 root 1 52 0 16612K 3164K pause 3 0:00 0.00% csh

I'm guessing that it was one of the three recent PHP updates, or the lighttp update that did it. Although, after reviewing r974, it could definitely be one of the added kernel modules:
ata/atapicam/atapicam.ko
aio/aio.ko
iscsi/isboot/isboot.ko
+ipmi/ipmi.ko

# Wireless
wpifw/wpifw.ko

ipmi

[WarrenV]

Actually, I'm seeing the slowdown in r943 as well.

[WarrenV]

Ok, it's a samba bug. The logs are full of winbind failures. The config is good on a vanilla FreeBSD install running samba 3.6, so it's just a goofy NAS4Free thing. Time to upgrade to 4.0, guys.

[raulfg3]

sure, but developers are a bit busy last months.

[Eliminateur]

yes i've seen my logs full of those winbindd errors, in fact there's some master browser problem where it doesnt becomes a MB until i restart the service(a reboot/powercycle wont make it a MB), logs are full of those errors.

so last version is not a good idea to install?

[b0ssman]

disable the master browser option on nas4free then.

i never enable this option because the native windows machines can handle this.