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:
LOGS:
Broken (i.e. before restarting service)
FIXED (i.e. after restarting service):
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: