Timeouts on SMB Share from Ubuntu

[Ammign]

Hello,

I have an odd problem that has only begun to occur recently. I have a Plex install in a Ubuntu VM with a cifs mount that points to a SMB share on my FreeNAS host. It was working well for many months. Now all of a sudden, I am finding that if I have not read or written a file to the share from the VM in the past few minutes, the share becomes inaccessible for 2+ minutes. Watching a packet capture, during this period, FreeNAS appears to quit responding to SMB requests and the Ubuntu host starts spewing thousands of SMBEcho requests that go unanswered.

FreeNAS-9.10.2-U3 (e1497f269) but it also occurred on FreeNAS Corral for the past week, It was what prompted me to try rebuilding on 9.10.


Watching logs on FreeNAS, it appears that the SMB process either exits or crashes during this period of time.


I have a packet capture of the behavior.
And attached are the logs from my FreeNAS host.

 

[anodos]

Hello,

I have an odd problem that has only begun to occur recently. I have a Plex install in a Ubuntu VM with a cifs mount that points to a SMB share on my FreeNAS host. It was working well for many months. Now all of a sudden, I am finding that if I have not read or written a file to the share from the VM in the past few minutes, the share becomes inaccessible for 2+ minutes. Watching a packet capture, during this period, FreeNAS appears to quit responding to SMB requests and the Ubuntu host starts spewing thousands of SMBEcho requests that go unanswered.

FreeNAS-9.10.2-U3 (e1497f269) but it also occurred on FreeNAS Corral for the past week, It was what prompted me to try rebuilding on 9.10.


Watching logs on FreeNAS, it appears that the SMB process either exits or crashes during this period of time.


I have a packet capture of the behavior.
And attached are the logs from my FreeNAS host.

Post a debug file. "System" -> "Advanced" -> "Save Debug"

 

[Ammign]

Thanks, I have attached it now.

 

[anodos]

Haven't gotten a chance to look at it in detail, but thought it worthwhile to advise that your Hitachi Deskstar 7K200, serial number JK1174YAHM09GW has a reallocated sector count of 321. It is beginning to pine for the fjords. You really should consider configuring SMART tests.

 

[Ammign]

There is a reason why I call them deathstars, thanks I have one in shipping.

 

[Ammign]

I am uploading another debug that shows two hosts having the problem in the network dump, 192.168.0.135 and 192.168.0.80 are two different Ubuntu 16.04 hosts showing the same symptoms, If I try to manually mount the share during this "outage period" I get message "mount error(122): host is down" Please note that I do not seem to be seeing the same issue when browsing from a Windows host.

 

[maydo]

i had similar problems on fn11 nightlies & fn11-RC.
timeouts on ubuntu vm to cifs share for docker volume mounts.
switched to nfsv4 solved for me :)

 

[Jeff Hallam]

Can you clarify how you switched to nfsv4? Do you mean on ubuntu or on freenas? I'm having a similar issue (I believe) and it's causing high cpu use on the freenas box.

 

[Ammign]

For sure, when the mount is down there is an enormous spike in SMB Echo requests on the Network interface which is causing 20-30% CPU usage on the NAS. Once it finally mounts, CPU usage drops again. I appreciate that knowing NFSv4 does not pose the same issue, however that won't work for me as I have many Windows Home Clients that will be accessing the share as well.

What grinds my gears is that I was running this for quite awhile before this starting occurring on Corral and then 9.10. The only thing that changed in the meantime may have been an increase in storage usage on the volume.

 

[Geek Baba]

i had similar problems on fn11 nightlies & fn11-RC.
timeouts on ubuntu vm to cifs share for docker volume mounts.
switched to nfsv4 solved for me :)

I tired that but NFS mounts have incorrect permissions, so unless I make the mount 777, I can not use NFS. I am using FreeNAS-9.10.2-U3

 

[maydo]

Can you clarify how you switched to nfsv4? Do you mean on ubuntu or on freenas? I'm having a similar issue (I believe) and it's causing high cpu use on the freenas box.

yes it was same issues using cifs, high cpu usage and timeouts.

the fstab mount for nfs

ip:/yourshare /path/mount nfs auto,nofail,nfsvers=4,noatime,intr,tcp,actimeo=1800,bg 0 0

activate nfsv4 on nfs services

maproot user & groupis set to 1001 user which has permission to this dataset

this works good on my end

 

[Geek Baba]

Looks like its the latest Ubuntu kernel have issue with cifs, NFS is not an option for me as mounted drive shows root as owner and I have not been able to mount specific user share. After struggling for past 1 week and limiting protocol to SMB2 on both client (Ubuntu) and server (freenas), finally I had to remove latest kernel on Ubuntu and update the grub, its seems its stable now with linux-image-4.4.0-62-generic. Steps to do it on Ubuntu is as follows:

1. check that there is a second older kernel:

Code:

dpkg --list | grep linux-image

2. if there is an older one, remove the newest:

Code:

sudo apt remove --purge 4.4.0-75-*

3.update grub:

Code:

sudo update-grub

I will update if I still have issues with stability of cifs connections.

UPDATE: linux-image-4.4.0-62-generic has been stable for past 3 days, I will try to move to 4.8 kernel and let everyone know if that has problems or not.

 

[Jeff Hallam]

CIFS shares would appear to be stable after I worked on them but then it seemed to eventually revert to a problem state. I've attached a screenshot of my CPU demand at the time before and after. Note that it was pegged at 100% for quite a while. The places where it returns to idle is when I turned SMB service off. ** Also note that running

Code:

netstat -p tcp

before and during showed a completely different situation with new sockets being continually placed in TIME WAIT concurrent with the high CPU use. An excerpt of the netstat command is below (imagine it scrolling to infinity!):

Code:

tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49034	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49032	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49030	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49028	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49026	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49024	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49022	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49020	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49018	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49016	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49014	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49012	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49010	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49008	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49006	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49004	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49002	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.49000	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48998	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48996	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48994	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48992	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48990	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48988	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48986	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48984	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48982	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48980	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48978	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48976	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48974	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48972	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48970	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48968	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48966	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48964	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48962	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48960	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48958	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48956	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48954	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48952	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48950	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48948	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48946	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48944	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48942	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48940	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48938	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48936	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48934	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48932	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48930	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48928	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48926	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48924	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48922	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48920	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48918	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48916	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48914	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48912	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48910	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48908	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48906	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48904	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48902	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48900	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48898	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48896	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48894	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48892	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48890	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48888	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48886	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48884	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48882	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48880	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48878	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48876	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48874	 TIME_WAIT
tcp4	   0	  0 freenas.microsoft-ds   main-desktop.48872	 TIME_WAIT

 

[Spearfoot]

I'm experiencing the same high CPU utilization and dropped connections with a Ubuntu 16.04 LTS VM using a CIFS-based share on my main FreeNAS 9.10.2-U3 server. I've reverted to the earlier Ubuntu kernel per @shwetkprabhat's instructions and everything seems to be running the way it ought to now. The SMBD process was running the CPU utilization up to ~28% before I made the change:

 

[Geek Baba]

So I kept digging more and tried different kernels and here is the findings:

1. 4.4.0-62-generic - cifs works as expected
2. 4.4.0-75-generic - its installed with automatic security update and cifs shares starts to drop
3. 4.4.0-77-generic - when you try to remove 4.4.0-75-generic, ubuntu asks you to install 4.4.0-77-generic, shares still not stable
4. 4.8.0-51-generic - I enforced the RollingLTSEnablementStack to check if the latest stable kernel has the same issue and alas, it crashed the smbd.

I hope this is fixed with the freenas 11, if someone could test/confirm that, it would be great!

 

[anodos]

So I kept digging more and tried different kernels and here is the findings:

1. 4.4.0-62-generic - cifs works as expected
2. 4.4.0-75-generic - its installed with automatic security update and cifs shares starts to drop
3. 4.4.0-77-generic - when you try to remove 4.4.0-75-generic, ubuntu asks you to install 4.4.0-77-generic, shares still not stable
4. 4.8.0-51-generic - I enforced the RollingLTSEnablementStack to check if the latest stable kernel has the same issue and alas, it crashed the smbd.

I hope this is fixed with the freenas 11, if someone could test/confirm that, it would be great!

Increase logging to "debug" in SMB config, reproduce the problem, then post /var/log/samba4/log.smbd here.

 

[Jeff Hallam]

I am running FreeNAS 11 and the problem was not resolved. It seems that the problem is actually the Ubuntu machine trying to access the shares rather than FreeNAS itself. I've since switched to NFS shares only and it is running like clockwork.

 

[anodos]

I am running FreeNAS 11 and the problem was not resolved. It seems that the problem is actually the Ubuntu machine trying to access the shares rather than FreeNAS itself. I've since switched to NFS shares only and it is running like clockwork.

I haven't seen anything in the samba mailing lists about this issue. I'm wondering if there's a bug here specifically related to FreeNAS + Samba and new features in the latest cifs-utils.

 

[BrianAz1]

I'm experiencing issues like this as well for the past day or so after updating Ubuntu. I got alerts that my FreeNAS was running nearly 100% CPU all the time.

Looking at the processes it was almost all smbd. When I turned the SMB service off on FreeNAS, my CPU dropped immediately to near 0 (around 21:20 in graph below). I then shutdown my two Ubuntu boxes and re-enabled FreeNAS SMB service. CPU stayed around 0.

Finally, I turned on one of my UbuntuVMs and you can see the FreeNAS CPU shot back up to about 50-60%.

For the moment, I've killed the SMB mounts I had configured while I decide if I want to mess around with the Kernel or just move to nfs.

After unmounting the FreeNAS smb shares on my Ubuntu boxes my FreeNAS CPU is back where I expect it... (I am still using them from Windows and Mac without issue):

Will be watching this thread closely.

 

[anodos]

I'm experiencing issues like this as well for the past day or so after updating Ubuntu. I got alerts that my FreeNAS was running nearly 100% CPU all the time.

Looking at the processes it was almost all smbd. When I turned the SMB service off on FreeNAS, my CPU dropped immediately to near 0 (around 21:20 in graph below). I then shutdown my two Ubuntu boxes and re-enabled FreeNAS SMB service. CPU stayed around 0.

Finally, I turned on one of my UbuntuVMs and you can see the FreeNAS CPU shot back up to about 50-60%.

For the moment, I've killed the SMB mounts I had configured while I decide if I want to mess around with the Kernel or just move to nfs.

After unmounting the FreeNAS smb shares on my Ubuntu boxes my FreeNAS CPU is back where I expect it... (I am still using them from Windows and Mac without issue):

Will be watching this thread closely.

How about increasing samba logging to "debug", reproducing the problem, then posting a debug file? ;)