Intermittent FreeNAS/Samba/Windows domain permissions issues

evan5599

Cadet
Joined
Mar 28, 2018
Messages
2
Hi all,

I'm at my wit's end with this. For quite a while we've had issues with FreeNAS/Samba serving SMB/CIFS shares to our users. Issues are intermittent and usually manifest with "permissions issues"/"access denied". This is only with certain shares. I haven't found much rhyme or reason to it.

It happens occasionally with a small subset of users on certain folders. ACLs with the folders in question are the same as accessible folders. Everyone is domain joined. FreeNAS has no issue communicating with the domain. We have recently rebuilt the entire domain from scratch, including the SMB shares. Ruled out everything I could think of, including DNS, NTP, and auth.

Thanks for any ideas you can offer!

SYMPTOMS:
Occasionally, certain users will receive an "access denied" when attempting to access FreeNAS/Samba shares over SMB. Rebooting FreeNAS, reapplying ACLs via Windows, and restarting the Samba service fixes the issue. Only a few SMB shares are affected. These shares have been mapped as "home" shares through AD mapping in the past (now mapped through GPO) and the issues are still occurring. Shares have been rebuilt from scratch.

ATTEMPTED FIXES:

-Rebuilding share

-Changing drive mapping

-Wiping out all ACLs on the share and reapplying with samba guidance

-Limiting SMB version

-Many, many more

smb.conf:
Code:
root@SERVER:/usr/local/etc # cat smb4.conf
[global]

	encrypt passwords = yes

	dns proxy = no

	strict locking = no


	oplocks = yes

	deadtime = 15

	max log size = 51200

	max open files = 940790

	logging = file

	load printers = no

	printing = bsd

	printcap name = /dev/null

	disable spoolss = yes

	getwd cache = yes

	guest account = nobody

	map to guest = Bad User

	obey pam restrictions = yes

	ntlm auth = no

	directory name cache size = 0

	kernel change notify = no

	panic action = /usr/local/libexec/samba/samba-backtrace

	nsupdate command = /usr/local/bin/samba-nsupdate -g
	server string =  Fileshare

	ea support = yes

	store dos attributes = yes

	lm announce = yes

	unix extensions = no

	acl allow execute always = true

	dos filemode = yes

	multicast dns register = no

	domain logons = no

	idmap config *: backend = tdb

	idmap config *: range = 90000001-100000000

	server role = member server

	workgroup = WKG

	realm = DOMAIN.COM

	security = ADS

	client use spnego = yes

	local master = no

	domain master = no

	preferred master = no

	ads dns update = yes

	winbind cache time = 7200

	winbind offline logon = yes

	winbind enum users = yes

	winbind enum groups = yes

	winbind nested groups = yes

	winbind use default domain = no

	winbind refresh tickets = yes

	idmap config WKG: backend = rid

	idmap config WKG: range = 20000-90000000

	allow trusted domains = no

	client ldap sasl wrapping = seal

	template shell = /bin/sh

	template homedir = /home/%D/%U

	netbios name = NAME

	create mask = 0666

	directory mask = 0777

	client ntlmv2 auth = yes

	dos charset = CP437

	unix charset = UTF-8

	log level = 2

	inherit acls = no

	nfs4:chown = yes

	nfs4:acedup = merge

	log level = 3

	



[SHARE1]

	path = "/mnt/vPool/SHARE1"

	printable = no

	veto files = /.snapshot/.windows/.mac/.zfs/

	writeable = yes

	browseable = yes

	access based share enum = no

	recycle:repository = .recycle/%U

	recycle:keeptree = yes

	recycle:versions = yes

	recycle:touch = yes

	recycle:directory_mode = 0777

	recycle:subdir_mode = 0700

	vfs objects = zfs_space zfsacl streams_xattr recycle

	hide dot files = no

	guest ok = no

	nfs4:mode = special

	nfs4:acedup = merge

	nfs4:chown = true

	zfsacl:acesort = dontcare

	



[SHARE2]

	path = "/mnt/vPool/SHARE2"

	printable = no

	veto files = /.snapshot/.windows/.mac/.zfs/

	writeable = yes

	browseable = yes


	access based share enum = yes

	recycle:repository = .recycle/%U

	recycle:keeptree = yes

	recycle:versions = yes

	recycle:touch = yes

	recycle:directory_mode = 0777

	recycle:subdir_mode = 0700

	vfs objects = zfs_space zfsacl streams_xattr recycle

	hide dot files = yes

	guest ok = no

	nfs4:mode = special

	nfs4:acedup = merge

	nfs4:chown = true

	zfsacl:acesort = dontcare

	=

LOGS:

Broken (i.e. before restarting service)
Code:
[2018/03/28 16:58:21.620649,  1] ../source3/smbd/vfs.c:926(vfs_GetWd)

  vfs_GetWd: couldn't stat "." error Permission denied (NFS problem ?)

[2018/03/28 16:58:21.620759,  1] ../source3/smbd/vfs.c:926(vfs_GetWd)

  vfs_GetWd: couldn't stat "." error Permission denied (NFS problem ?)

[2018/03/28 16:58:21.620926,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at
../source3/smbd/smb2_create.c:293

[2018/03/28 16:58:22.148983,  1] ../source3/smbd/vfs.c:926(vfs_GetWd)

  vfs_GetWd: couldn't stat "." error Permission denied (NFS problem ?)

[2018/03/28 16:58:36.429675,  3] ../source3/smbd/service.c:1120(close_cnum)

  10.1.3.33 (ipv4:10.1.3.33:49935) closed connection to service IPC$



[2018/03/28 16:59:40.720579,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:40.720651,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at

../source3/smbd/smb2_server.c:2467


[2018/03/28 16:59:40.732228,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied


[2018/03/28 16:59:40.732277,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:43.285658,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.285744,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467
[2018/03/28 16:59:43.287752,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.287801,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:43.294563,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.294612,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:43.294912,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.294960,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:43.295849,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.295897,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:43.296828,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.296877,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at

../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:43.297801,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.297850,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:43.298712,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.298760,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at ../source3/smbd/smb2_server.c:2467


[2018/03/28 16:59:43.299624,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.299677,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467
[2018/03/28 16:59:43.300465,  3] ../source3/smbd/service.c:120(set_current_service)


  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.300509,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at ../source3/smbd/smb2_server.c:2467


[2018/03/28 16:59:43.301808,  3] ../source3/smbd/service.c:120(set_current_service)
  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.301861,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:43.307916,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:43.307968,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:44.340485,  3] ../source3/smbd/service.c:120(set_current_service)

  chdir (/mnt/vPool/SHARE1) failed, reason: Permission denied

[2018/03/28 16:59:44.340531,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)
  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2467

[2018/03/28 16:59:44.588218,  3] ../lib/util/access.c:361(allow_access)

  Allowed connection from 10.1.3.7 (10.1.3.7)

[2018/03/28 16:59:44.588363,  3] ../source3/smbd/service.c:595(make_connection_snum)

  Connect path is '/tmp' for service [IPC$]

[2018/03/28 16:59:44.588436,  3] ../source3/smbd/vfs.c:113(vfs_init_default)

  Initialising default vfs hooks

[2018/03/28 16:59:44.588467,  3] ../source3/smbd/vfs.c:139(vfs_init_custom)
 no


FIXED (i.e. after restarting service):
Code:
[2018/03/28 17:01:15.996338,  3] ../source3/smbd/service.c:1120(close_cnum)

  10.1.3.29 (ipv4:10.1.3.29:54834) closed connection to service IPC$

[2018/03/28 17:01:16.395297,  3] ../lib/util/access.c:361(allow_access)

  Allowed connection from 10.1.3.9 (10.1.3.9)

[2018/03/28 17:01:16.395478,  3] ../source3/smbd/oplock.c:1329(init_oplocks)

  init_oplocks: initializing messages.

[2018/03/28 17:01:16.395567,  3] ../source3/smbd/process.c:1959(process_smb)

  Transaction 0 of length 178 (0 toread)

[2018/03/28 17:01:16.395803,  3] ../source3/smbd/smb2_negprot.c:290(smbd_smb2_request_process_negprot)

  Selected protocol SMB3_11

[2018/03/28 17:01:16.396936,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'gssapi_spnego' registered

[2018/03/28 17:01:16.396975,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'gssapi_krb5' registered

[2018/03/28 17:01:16.397025,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'gssai_krb5_sasl' registered

[2018/03/28 17:01:16.397089,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'spnego' registered


[2018/03/28 17:01:16.397140,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'schannel' registered

[2018/03/28 17:01:16.397192,  3] ../auth/gensec/gensec_start.c:977(gensec_register)
  GENSEC backend 'naclrpc_as_system' registered


[2018/03/28 17:01:16.397243,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'sasl-EXTERNAL' registered

[2018/03/28 17:01:16.397310,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'ntlmssp' registered

[2018/03/28 17:01:16.397340,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'ntlmssp_resume_ccache' registered

[2018/03/28 17:01:16.397386,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'http_basic' registered

[2018/03/28 17:01:16.397434,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'http_ntlm' registered

[2018/03/28 17:01:16.397466,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'krb5' registered

[2018/03/28 17:01:16.397512,  3] ../auth/gensec/gensec_start.c:977(gensec_register)

  GENSEC backend 'fake_gssapi_krb5' registered

[2018/03/28 17:01:16.406711,  3] ../auth/kerberos/kerberos_pac.c:409(kerberos_decode_pac)

  Found account name from PAC: USERACCT [USERNAME]

[2018/03/28 17:01:16.406764,  3] ../source3/auth/user_krb5.c:51(get_user_from_kerberos_info)

  Kerberos ticket principal name is [USERACCT@DOMAIN.COM]

[2018/03/28 17:01:16.428100,  3] ../source3/param/loadparm.c:1598(lp_add_ipc)

  adding IPC service

[2018/03/28 17:01:16.429372,  3] ../source3/smbd/password.c:144(register_homes_share)

  Adding homes service for user 'DOMAINNETBIOIS\USERACCT' using home directory: '/home/DOMAINNETBIOIS/USERACCT'

[2018/03/28 17:01:16.436040,  3] ../lib/util/access.c:361(allow_access)

  Allowed connection from 10.1.3.9 (10.1.3.9)

[2018/03/28 17:01:16.436161,  3] ../source3/smbd/service.c:595(make_connection_snum)
  Connect path is '/mnt/vPool/SHARE3' for service [SHARE3]

[2018/03/28 17:01:16.436228,  3] ../source3/smbd/vfs.c:113(vfs_init_default)

  Initialising default vfs hooks

[2018/03/28 17:01:16.436263,  3] ../source3/smbd/vfs.c:139(vfs_init_custom)
  Initialising custom vfs hooks from [/[Default VFS]/]

[2018/03/28 17:01:16.436301,  3] ../source3/smbd/vfs.c:139(vfs_init_custom)

  Initialising custom vfs hooks from [recycle]

[2018/03/28 17:01:16.436568,  3] ../lib/util/modules.c:167(load_module_absolute_path)

  load_module_absolute_path: Module '/usr/local/lib/shared-modules/vfs/recycle.so' loaded

[2018/03/28 17:01:16.436639,  3] ../source3/smbd/vfs.c:139(vfs_init_custom)


  Initialising custom vfs hooks from [streams_xattr]

[2018/03/28 17:01:16.436977,  3] ../lib/util/modules.c:167(load_module_absolute_path)
  load_module_absolute_path: Module '/usr/local/lib/shared-modules/vfs/streams_xattr.so' loaded

[2018/03/28 17:01:16.437024,  3] ../source3/smbd/vfs.c:139(vfs_init_custom)
  Initialising custom vfs hooks from [zfsacl]

[2018/03/28 17:01:16.437500,  3] ../lib/util/modules.c:167(load_module_absolute_path)

  load_module_absolute_path: Module '/usr/local/lib/shared-modules/vfs/zfsacl.so' loaded

[2018/03/28 17:01:16.437561,  3] ../source3/smbd/vfs.c:139(vfs_init_custom)

  Initialising custom vfs hooks from [zfs_space]

[2018/03/28 17:01:16.451593,  3] ../lib/util/modules.c:167(load_module_absolute_path)

  load_module_absolute_path: Module '/usr/local/lib/shared-modules/vfs/zfs_space.so' loaded

[2018/03/28 17:01:16.451929,  2] ../source3/smbd/service.c:841(make_connection_snum)
  10.1.3.9 (ipv4:10.1.3.9:50214) connect to service SHARE3 initially as user DOMAINNETBIOIS\USERACCT (uid=21692,
gid=90000009) (pid 70718)

[2018/03/28 17:01:16.454254,  3] ../source3/smbd/smb2_server.c:3115(smbd_smb2_request_error_ex)

  smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_OBJECT_NAME_NOT_FOUND] || at
../source3/smbd/smb2_create.c:293


  DOMAINNETBIOIS\USERACCT opened file SHARE3(DOMAINNETBIOISSERVER) (T) - Shortcut.lnk read=Yes write=No
(numopen=2)


[2018/03/28 17:01:16.494907,  3] ../source3/smbd/trans2.c:3456(smbd_do_qfsinfo)

  smbd_do_qfsinfo: level = 1001
[2018/03/28 17:01:16.494982,  3] ../source3/smbd/trans2.c:3456(smbd_do_qfsinfo)

  smbd_do_qfsinfo: level = 1005

[2018/03/28 17:01:16.545361,  2] ../source3/smbd/open.c:1404(open_file)




  DOMAINNETBIOIS\USERACCT opened file SHARE (DOMAINNETBIOISSERVER) (T) - Shortcut.lnk read=Yes write=No


(numopen=4)
 
Last edited by a moderator:

Mirfster

Doesn't know what he's talking about
Joined
Oct 2, 2015
Messages
3,215
-Limiting SMB version
Can you elaborate on this? Are you setting minimum and maximum versions from within the CIFS service?

Also:
  1. What version of FreeNAS?
  2. What are the client versions (Windows 10, Window 7, etc)?

Everyone is domain joined. FreeNAS has no issue communicating with the domain. We have recently rebuilt the entire domain from scratch, including the SMB shares.
Is this an actual MS Domain or are you using FreeNAS as the Primary Domain Controller?
 

evan5599

Cadet
Joined
Mar 28, 2018
Messages
2
Thanks for responding. FreeNAS is 11.1-U2, and the clients are all Windows 10 on an actual MS domain at a 2012r2 functional level.
 
Joined
Jan 5, 2017
Messages
1
Hi there, I having the same problem, it only happens with one user, it's totally random. In the most cases when fails in \\freenas we can connect from \\IP-OF-FREENAS bu sometime fails too. This problem can happen with any computer, new fresh installation of windows 10, pc that works fine with other users, clients pc with windows 7, etc. It only happen with that user.
I sure it's a windows problem.
 
Top