FreeNAS 9.3 STABLE upgrading issue (from 9.2.1.9)

[abcslayer]

Hi,

Maybe I am the only one meet with this issue (as I have search the bug tracker & googling too). Here below is my system config:

• I setup FreeNAS from 9.2.1.7, upgrade to 9.2.1.8 and 9.2.1.9 (I decided to upgrade to .9 as I think it would help upgrading to 9.3 smoother)
• The FreeNAS is a VM configured with PCI-E pass-through (LSI 9208)
• FreeNAS has ZFS pool with zvols for iSCSI. I have enable experimental target once then disable it as the connection with VMWare initiator is drop frequently. I use the igst target till now.
• The VM has only two services enable: SMART & iSCSI.

Today I decided to upgrade to 9.3 STABLE using .iso file installation as I saw some feedback from other users who have troubles with GUI upgrading. The upgrade process is OK. After the VM reboot 1 or 2 times it finally boot. I can access the Web config normally, it seems that all config is ported to new system fine. But the iSCSI target is not online any more, when I tried to start it or tried to save some config (I did not edit any thing, just open then save) and start it, it is always failed. There are two troubles:

• The initiator is nul, there is no group. I have to recreate new one.
• When I start iSCSI services, there is always syntax error of /usr/local/libexec/nas/generate_ctl_conf.py, line 64. Therefor there is no ctl.conf in /etc and the system threw error message about no ctl config. ctld could not be started.

I am very disappointed with the QA of FreeNAS, my system config is very basic. I only add VMWare .ko to have VMXNET3 enabled. It seems that FreeNAS 9.3 is sent out of your dev lab to catch the delayed release date.

 

[crumbz]

You might want to check out this post:

https://forums.freenas.org/index.ph...nas-in-production-as-a-virtual-machine.12484/

 

[lavicky]

When I start iSCSI services, there is always syntax error of /usr/local/libexec/nas/generate_ctl_conf.py, line 64. Therefor there is no ctl.conf in /etc and the system threw error message about no ctl config. ctld could not be started.

Patch and update is avalaible https://forums.freenas.org/index.php?threads/freenas-9-3-is-now-released.25447/#post-159704

I had to reboot after editing /usr/local/libexec/nas/generate_ctl_conf.py. iSCSI is working no but there's no "iscsid_enable=YES/NO" in /var/tmp/rc.conf.freenas.

 

[mav@]

iSCSI is working no but there's no "iscsid_enable=YES/NO" in /var/tmp/rc.conf.freenas.

iscsid is a daemon for iSCSI initiator. Daemon for iSCSI target is called ctld.

 

[abcslayer]

You might want to check out this post:
https://forums.freenas.org/index.ph...nas-in-production-as-a-virtual-machine.12484/

Hi,
Thank you for your suggestion, actually before I decide to use FreeNAS instead of NAS4free (I know what it is) or OMV in VM (as a VSA) I have read all post from him. Actually I dont see the threat clearly (the biggest trouble would be RDM not VT-d which I use).
The issue I meet with FreeNAS 9.3 STABLE is not because I am not following the suggestion of that topic, it is because the terrible QA of current FreeNAS team. The bug is very basic and not too hard to replicate or build a test case.

One more thing, the biggest change in 9.3 is new iSCSI target to make FreeNAS more enterprise friendly, especially VMWare environment so I really dont know how FreeNAS team test their code.

Patch and update is avalaible https://forums.freenas.org/index.php?threads/freenas-9-3-is-now-released.25447/#post-159704
I had to reboot after editing /usr/local/libexec/nas/generate_ctl_conf.py. iSCSI is working no but there's no "iscsid_enable=YES/NO" in /var/tmp/rc.conf.freenas.

I will try again. Thanks.

 

[abcslayer]

Update: the new update for 9.3 has done the jobs, iSCSI service (ctl) can be started. Now I face with another bug: the error message (freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware: ): no ping reply (NOP-Out) after 5 seconds; dropping connection), it seems to happen under load condition (I need to observe the system more). I have met this error message before with experimental target (similar to 9.3 iSCSI kernel target) in 9.2.1.x and iSCSI performance is lower than istgt target (maybe due to connection dropped & reconnect).

 

[mav@]

It would be interesting to know whether those messages disappear if you increase that timeout from 5 seconds to 60 via `sysctl kern.cam.ctl.iscsi.ping_timeout=60`. If it helps, then something just heavily congests the connection. If not, then there may be some problem.

Do you see any other errors? Any memory overflows or mbuf allocation problems?

 

[abcslayer]

I have changed the system control as you suggested, now Iam waiting for log result. I have not seen other errors yet (or I dont know where to find it?). As I found out the CPU load is pretty high when there is IO traffic (from 0.76 to 1.70), in old isgt I dont face trouble with resouces. My VM has 02 vCPU (Xeon E3-1231v3), 8GB, no dedup, compression (lz4) is enable for the iSCSI target.

I also check vmstat -i the interrupt rate of NICs is about 100/s, CPU0 timer is 1007/s (such very high?)
In my VM, I have sysctl config to: enable MSI, disable MSI-X (to reduce interrupt stomp fron NICs), enable VMXNET3

 

[mav@]

I have changed the system control as you suggested, now Iam waiting for log result. I have not seen other errors yet (or I dont know where to find it?).

/var/log/messages ? I am all waiting for result.

CPU0 timer is 1007/s (such very high?)

This is known effect of having DUMMYNET built into the kernel. Not a problem. It should be fixed in FreeBSD/FreeNAS 10 with new timer subsystem.

enable VMXNET3

I don't know much about this. Does it support some fancy acceleration that may work odd? Have you tried to switch to regular e1000?

 

[abcslayer]

/var/log/messages ? I am all waiting for result.


This is known effect of having DUMMYNET built into the kernel. Not a problem. It should be fixed in FreeBSD/FreeNAS 10 with new timer subsystem.


I don't know much about this. Does it support some fancy acceleration that may work odd? Have you tried to switch to regular e1000?

Thank you for the information. I use VMXNET3 as VMWare told people that VMXNET3 reduce the used host resource (CPU cycles mostly) during operation.
Here below is some most recent /var/log/messages:

Dec 10 00:43:49 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): no ping reply (NOP-Out) after 5 seconds; d
ropping connection
Dec 10 00:44:23 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): no ping reply (NOP-Out) after 5 seconds; d
ropping connection
Dec 10 00:44:57 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): no ping reply (NOP-Out) after 5 seconds; d
ropping connection
Dec 10 00:55:43 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): connection error; dropping conneWARNING: 1
92.168.10.2 (iqn.1998-01.com.vmware:5436d812-1b9d-676a-6755-0cc47a30227a-6413931
f): connection error; dropping connection
Dec 10 00:55:43 freenas ction
Dec 10 00:55:43 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): connection error; dropping connection
Dec 10 08:15:53 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): connection error; dropping connection
Dec 10 08:16:22 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): connection error; dropping connection
Dec 10 08:16:52 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): connection error; dropping connection

The dropping connection message happened when the SQL backup its databases.
Afterthat I apply the sysctl config as you suggested. The new error message (connection error) happened when I did some check disks.

 

[mav@]

So do I understand right, that after you increased the sysctl value old timeout messages disappeared, but new one arise?

Could you set one more `sysctl kern.icl.debug=2`. It may give some more details about cause of new errors.

 

[abcslayer]

So do I understand right, that after you increased the sysctl value old timeout messages disappeared, but new one arise?

Could you set one more `sysctl kern.icl.debug=2`. It may give some more details about cause of new errors.

Here you are (this time I set sysctl in the turntable section):

Dec 10 16:57:57 freenas notifier: kern.cam.ctl.iscsi.ping_timeout: 60 -> 60
Dec 10 16:57:57 freenas notifier: kern.icl.debug: 1 -> 2
Dec 10 17:01:57 freenas icl_conn_receive_pdus: connection error 54; dropping con
nection
Dec 10 17:01:57 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): connection error; dropping connectio

The error happened when I did a check disk.
My current system tweak:

hw.pci.enable_msi = 1
hw.pci.enable_msix = 0
vmxnet3_load = YES (to load vmxnet3.ko from /boot/modules)
VMXNET3 MTU = 9000​

P/S: this setting work well under isgt in 9.2.1.x and give same error when I enable the kernel target (experimental target in 9.2.1.x)

 

[mav@]

Error 54 is ECONNRESET (Connection reset by peer). I guess that remote side closed connection for some reason. May be the reason is the same as for previously seen timeouts on FreeNAS side.

How reproducible is this problem? Is it possible to reproduce it on a wish to get packet dump? That could probably explain what is going on. With packet dump I mean `tcpdump -pi <interface> -s 0 -w <file> port 3260`.

Note that dump will include all the transferred data, so may be very large.

 

[mav@]

OK. I analyzed 1.5GB of data you sent me. Thanks. I see repeatable pattern in each disconnection. I looks like a bug in new iSCSI transport code, not in SCSI emulation of CTL. That somewhat reduce area of search. Next step is probably some careful analysis of that area of code. I've sent request to original iSCSI code author and will look myself, but that can take some time. Especially since not many people experienced it, and I am not sure I be able to reproduce it either.

In any case you may revert timeout sysctl you set since it obvious does not help, but make things even worse by delaying recovery.

I would also try to experiment with disabling TSO/LRO acceleration on your virtual NIC, if they are supported, and may be try to switch to e1000 driver. I am not sure that may help, but may worth to try meanwhile.

 

[abcslayer]

Thank you for your help & suggestions. I will try them step by step to make thing easier to trace back if necessary.

PS: I notice some other messages like those (which I have not seen before):

Dec 11 00:55:39 freenas icl_conn_send_pdus: no space to send; have 34012, need 127024
Dec 11 00:55:39 freenas icl_conn_send_pdus: no space to send; have 14412, need 131120
Dec 11 00:55:39 freenas icl_conn_send_pdus: no space to send; have 107136, need 131120
Dec 11 00:55:39 freenas icl_conn_send_pdus: no space to send; have 92388, need 98352
Dec 11 00:55:47 freenas icl_conn_send_pdus: no space to send; have 84664, need 131120
Dec 11 00:55:47 freenas icl_conn_send_pdus: no space to send; have 34124, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 78912, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 1480, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 40468, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 34668, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 37816, need 45104
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 64296, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 4760, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 25804, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 55796, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 5208, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 53096, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 11456, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 59344, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 22460, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 88244, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 55552, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 22860, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 97592, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 73848, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 50104, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 26360, need 127024
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 6712, need 131120
Dec 11 00:55:48 freenas icl_conn_send_pdus: no space to send; have 99340, need 131120
Dec 11 00:56:07 freenas icl_conn_send_pdus: no space to send; have 13032, need 131120
Dec 11 00:56:07 freenas icl_conn_send_pdus: no space to send; have 43408, need 131120
Dec 11 00:56:07 freenas icl_conn_send_pdus: no space to send; have 88244, need 131120
Dec 11 00:56:07 freenas icl_conn_send_pdus: no space to send; have 1912, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 32096, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 26392, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 29636, need 127024
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 45924, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 67064, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 16524, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 46612, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 85648, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 44056, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 2464, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 50448, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 13612, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 79492, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 46848, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 14204, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 97980, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 74284, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 50588, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 26892, need 127024
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 7292, need 131120
Dec 11 00:56:08 freenas icl_conn_send_pdus: no space to send; have 108964, need 114736
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 111860, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 105964, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 46476, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 28196, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 93980, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 34492, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 46588, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 58684, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 70780, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 11196, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 32240, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 49092, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 70136, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 10648, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 31692, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 61684, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 11048, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 41040, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 71032, need 127024
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 24588, need 131120
Dec 11 00:56:11 freenas icl_conn_send_pdus: no space to send; have 54580, need 98352
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 7760, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 20192, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 50520, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 44912, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 107692, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 39160, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 6296, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 27532, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 57716, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 7224, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 46356, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 4812, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 52892, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 11348, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 73132, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 40536, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 7940, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 82864, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 59216, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 35568, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 11920, need 131120
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 95792, need 127024
Dec 11 00:56:21 freenas icl_conn_send_pdus: no space to send; have 85188, need 131120
Dec 11 00:56:30 freenas icl_conn_send_pdus: no space to send; have 7520, need 131120
Dec 11 00:56:30 freenas icl_conn_send_pdus: no space to send; have 10860, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 41044, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 103776, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 35340, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 101220, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 41732, need 77872
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 35492, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 65580, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 15040, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 45128, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 3536, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 51520, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 9928, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 66860, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 30024, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 95904, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 63260, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 39564, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 15868, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 99644, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 75948, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 52252, need 127024
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 41600, need 131120
Dec 11 00:56:31 freenas icl_conn_send_pdus: no space to send; have 26852, need 32816
Dec 11 00:56:42 freenas icl_conn_send_pdus: no space to send; have 66912, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 7520, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 52356, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 10860, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 41044, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 35340, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 38584, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 50776, need 127024
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 76012, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 25472, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 55560, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 5020, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 53004, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 11412, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 59396, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 26752, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 88440, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 55796, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 23152, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 106928, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 83232, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 59536, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 35840, need 131120
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 12144, need 127024
Dec 11 00:56:43 freenas icl_conn_send_pdus: no space to send; have 1492, need 114736
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 7520, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 19808, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 58940, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 121672, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 53236, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 56480, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 68672, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 9184, need 12336
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 77428, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 26888, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 56976, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 6436, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 54420, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 12828, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 60812, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 28168, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 89856, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 57212, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 24568, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 872, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 84648, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 60952, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 37256, need 131120
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 13560, need 127024
Dec 11 00:56:48 freenas icl_conn_send_pdus: no space to send; have 2908, need 98352
Dec 11 00:57:08 freenas icl_conn_send_pdus: no space to send; have 57964, need 131120
Dec 11 00:57:08 freenas icl_conn_send_pdus: no space to send; have 43408, need 131120
Dec 11 00:57:08 freenas icl_conn_send_pdus: no space to send; have 43408, need 131120
Dec 11 00:57:08 freenas icl_conn_send_pdus: no space to send; have 1912, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 32096, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 26392, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 29636, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 41828, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 62968, need 94256
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 49292, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 79380, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 28840, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 76824, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 35232, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 83216, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 50572, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 17928, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 79616, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 46972, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 23276, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 107052, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 83356, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 59660, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 35964, need 131120
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 21216, need 127024
Dec 11 00:57:09 freenas icl_conn_send_pdus: no space to send; have 10564, need 16432
Dec 11 00:57:17 freenas icl_conn_send_pdus: no space to send; have 84664, need 131120
Dec 11 00:57:17 freenas icl_conn_send_pdus: no space to send; have 34124, need 131120
Dec 11 00:57:17 freenas icl_conn_send_pdus: no space to send; have 1480, need 131120
Dec 11 00:57:17 freenas icl_conn_send_pdus: no space to send; have 1480, need 131120
Dec 11 00:57:17 freenas icl_conn_send_pdus: no space to send; have 40468, need 131120
Dec 11 00:57:17 freenas icl_conn_send_pdus: no space to send; have 34668, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 37816, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 49912, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 70956, need 127024
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 24464, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 54456, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 12816, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 60704, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 19064, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 75900, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 43208, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 10516, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 72108, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 39416, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 15672, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 99352, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 75608, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 51864, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 28120, need 131120
Dec 11 00:57:18 freenas icl_conn_send_pdus: no space to send; have 13324, need 110640
Dec 11 00:57:29 freenas icl_conn_send_pdus: no space to send; have 3108, need 131120
Dec 11 00:57:29 freenas icl_conn_send_pdus: no space to send; have 15396, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 54528, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 54528, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 48824, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 61016, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 1528, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 22668, need 127024
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 56852, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 6312, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 45348, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 3756, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 51740, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 10148, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 76028, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 43384, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 6548, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 81376, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 57680, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 33984, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 10288, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 94064, need 131120
Dec 11 00:57:30 freenas icl_conn_send_pdus: no space to send; have 79316, need 131120
Dec 11 00:57:33 freenas icl_conn_send_pdus: no space to send; have 73008, need 131120
Dec 11 00:57:33 freenas icl_conn_send_pdus: no space to send; have 31512, need 131120
Dec 11 00:57:33 freenas icl_conn_send_pdus: no space to send; have 52748, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 38096, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 32392, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 44584, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 56776, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 6236, need 127024
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 40420, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 70508, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 28916, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 76900, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 35308, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 92240, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 59596, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 26952, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 88640, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 64944, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 41248, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 17552, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 101328, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 77632, need 131120
Dec 11 00:57:34 freenas icl_conn_send_pdus: no space to send; have 62884, need 131120
Dec 11 00:57:53 freenas icl_conn_send_pdus: no space to send; have 5168, need 131120
Dec 11 00:57:53 freenas icl_conn_send_pdus: no space to send; have 136, need 131120
Dec 11 00:57:53 freenas icl_conn_send_pdus: no space to send; have 136, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 21948, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 7680, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 2360, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 14936, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 18276, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 48748, need 127024
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 2496, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 41916, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 516, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 48884, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 7484, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 73748, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 41296, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 8844, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 79864, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 56360, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 32856, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 9352, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 93512, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 78956, need 131120
Dec 11 00:57:54 freenas icl_conn_send_pdus: no space to send; have 64400, need 131120
Dec 11 00:58:06 freenas icl_conn_send_pdus: no space to send; have 7760, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 20192, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 59468, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 53860, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 57200, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 69488, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 10048, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 40232, need 127024
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 74512, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 32968, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 81048, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 39504, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 96532, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 63936, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 31340, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 97316, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 60528, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 36880, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 13232, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 97104, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 73456, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 49808, need 131120
Dec 11 00:58:07 freenas icl_conn_send_pdus: no space to send; have 35108, need 110640
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 71572, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 47972, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 47972, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 42268, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 45512, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 57704, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 78844, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 28304, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 58392, need 127024
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 11948, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 59932, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 18340, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 66324, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 33680, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 1036, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 66916, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 34272, need 131120
Dec 11 00:58:13 freenas icl_conn_send_pdus: no space to send; have 6384, need 131120

I am not sure it can help or not.

 

[abcslayer]

Update: I have added some options to disable the following things on VMXNET3: -tso4 -tso6 -vlan_hwtso (those are options that is automatically enable with VMXNET3 when I checked ifconfig), the MTU 9000 is still keep and I think it still work (ping -s 8992 or ping -s 9000 is OK).
I tried to do some disk intensive task (like check disk) and the situation happened, there are some new error messages:

Dec 11 13:32:20 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): no ping reply (NOP-Out) after 5 seconds; d
ropping connection
Dec 11 13:32:33 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): no ping reply (NOP-Out) after 5 seconds; d
ropping connection
Dec 11 13:32:39 freenas ctl_datamove: tag 0x44dd6b on (0:4:0:0) aborted
Dec 11 13:32:39 freenas ctl_datamove: tag 0x44dd6e on (0:4:0:0) aborted
Dec 11 13:33:16 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): no ping reply (NOP-Out) after 5 seconds; d
ropping connection
Dec 11 13:33:47 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): no ping reply (NOP-Out) after 5 seconds; d
ropping connection
Dec 11 13:34:03 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): no ping reply (NOP-Out) after 5 seconds; d
ropping connection
Dec 11 13:34:14 freenas WARNING: 192.168.10.2 (iqn.1998-01.com.vmware:5436d812-1
b9d-676a-6755-0cc47a30227a-6413931f): no ping reply (NOP-Out) after 5 seconds; d
ropping connection

(the new error messages appear when I repeat the check disk for 2nd time, it seems that when data transfer at high rate happened for a while then the error appear)

------------------
Hmm I've read all the messages and I think it is not related to the bug or appear due to the bug, they might not be the root cause.

 

[abcslayer]

Update:
1. I have removed the option MTU 9000 and test, in two cases (disable TSO and enable TSO like default). The problem is still happened, it just come later than MTU 9000.
2. I have update my ESXi from 5.5.0 U1 to U2 then 5.5.0 newest (build 2302651), update the vmxnet3.ko again, reboot FreeNAS and test, the issue still happened (when I do some disk benchmark).
So at this moment I temporary think the issue might not stay in VMWare side (as with 9.2.1.x, isgt target, everything is OK)

Until now, I can not replicate the error if I just do the check disk, I have to run AS SSD benchmark one or two times then it happened.

 

[mav@]

PS: I notice some other messages like those (which I have not seen before):
Dec 11 00:55:39 freenas icl_conn_send_pdus: no space to send; have 34012, need 127024
Dec 11 00:55:39 freenas icl_conn_send_pdus: no space to send; have 14412, need 131120
I am not sure it can help or not.

This is normal behavior when server has more data then TCP connection can pass.

I made some code review yesterday, but so far found no potential bugs. I will try more, but so far have no more clues. :(

 

[sybreeder]

Hi,

nly add VMWare .ko to have VMXNET3 enabled. It seems that FreeNAS 9.3 is sent out of your dev lab to catch the delayed release date.

I've upgraded FreeNAS fron 92.1.9 to 9.3 and vmxnet3 driver doesn't work at all. ESXi 5.5 recognize vmware driver and can tell that vmtools are enabled but only E1000 work properly. It's lika a 9.2*.* driver is not compatible

 

[abcslayer]

I've upgraded FreeNAS fron 92.1.9 to 9.3 and vmxnet3 driver doesn't work at all. ESXi 5.5 recognize vmware driver and can tell that vmtools are enabled but only E1000 work properly. It's lika a 9.2*.* driver is not compatible

I use the driver that come with VMWare. I extract the .ko files, put them in /boot/modules and add a loader.conf line (vmxnet3_load = YES). You might need to check your config.