Register for the iXsystems Community to get an ad-free experience and exclusive discounts in our eBay Store.

bug? - SMB connection gets closed and reopened as a guest

AndroGen

Member
Joined
Jan 19, 2019
Messages
32
I am experiencing rather strange behavior, and looking into the logs this is really strange.

Problem:
Inconsistent system behavior during the file copy from the Windows 10 computer(s) to NAS.
In some cases (not always) copying of existing folders, files (overwriting) is stopped due to the "Destination Folder Access Denied"
In some cases pop-up allows to retry and it is successful (copying continues), in some - retry is not possible.
When pressing "skip" - process continues and files and folders can be copied into even the folder, which has been previously indicated as "Access Denied"

2021-01-13_22-02-23.jpg


Use case:
- fresh TrueNAS install (Xeon-D system; 10xHDDs, enough memory)
- all tester users experience this behavior from different Windows 10 computers (connected to the domain, or standalone)
- authentication is local, on TrueNAS
- user has been created with the "Microsoft Account" on
- user has access to the dataset shared via SMB
- use is the owner of the data set and the share with write ACL permissions

a bit more details:

When this user copies data to the folder for the first time - all works (usually) fine.
When user copies the same files once again - all works fine if these are just files. System checks, asks whether user would like to overwrite and after the confirmation all is copied, also including new files.
When user copies the same set of files, and there are directories, some directories start issuing the message "Destination Folder Access Denied" no permission to write into this directory. The retry in some cases works, in some - not.
If "skip" is pressed - in some cases files are copied further, also the ones, which are in the folder, where just seconds ago "Destination Folder Access Denied" message was popping up... the new files and/or directories are copied to the NAS (usually) with no issue.

Checking the authorization on the Windows side - settings confirm that user has a full control and ownership of this folders.
2021-01-13_23-44-39.jpg


but Effective access fails with message: "Code: 0x80070534 No Mapping between account name and security IDs was done." - and I am not sure whether this is normal.
2021-01-13_23-40-12.jpg

However, in the log - all looks fine, authentications seems to be working (from /var/log/samba4/log.smbd):
Note: IP addresses, path and file names, also a user name have been replaced by <DummyText>

Code:
[2021/01/13 23:43:41.070561,  4] ../../auth/auth_log.c:753(log_successful_authz_event_human_readable)
  Successful AuthZ: [lsarpc,ncacn_np] user [TRUENAS]\[<USER>] [S-1-5-21-3114513318-368794300-941185933-1005] at [Wed, 13 Jan 2021 23:43:41.070550 CET] Remote host [ipv4:<Source_IP>:54888] local host [ipv4:<Destination_IP>:445]
[2021/01/13 23:43:41.849590,  4] ../../auth/auth_log.c:753(log_successful_authz_event_human_readable)
  Successful AuthZ: [lsarpc,ncacn_np] user [TRUENAS]\[<USER>] [S-1-5-21-3114513318-368794300-941185933-1005] at [Wed, 13 Jan 2021 23:43:41.849579 CET] Remote host [ipv4:<Source_IP>:54888] local host [ipv4:<Destination_IP>:445]
[2021/01/13 23:43:42.700606,  4] ../../auth/auth_log.c:753(log_successful_authz_event_human_readable)
  Successful AuthZ: [lsarpc,ncacn_np] user [TRUENAS]\[<USER>] [S-1-5-21-3114513318-368794300-941185933-1005] at [Wed, 13 Jan 2021 23:43:42.700595 CET] Remote host [ipv4:<Source_IP>:54888] local host [ipv4:<Destination_IP>:445]


SMB logging has been activated as suggested in the thread: https://www.truenas.com/community/threads/windows-error-no-mapping-between-account-names-and-
security-ids-was-done.57947/
SMB gets additional aux: log level = 2 auth_audit:5

After the analyzing the /var/log/samba4/log.smbd I am bit confused.
It looks like session is disconnected an re-connected again as a "guest" / "ANONYMOUS LOGON", and gets rejected.

Code:
[2021/01/13 22:45:05.451742,  3] ../../auth/auth_log.c:653(log_authentication_event_human_readable)
  Auth: [SMB2,(null)] user []\[] at [Wed, 13 Jan 2021 22:45:05.451729 CET] with [(null)] status [NT_STATUS_OK] workstation [COMPUTERNAME] remote host [ipv4:<Source_IP>:54198] became [TRUENAS]\[nobody] [S-1-5-21-3114513318-368794300-941185933-501]. local host [ipv4:<Destination_IP>:445]
[2021/01/13 22:45:05.451893,  5] ../../auth/auth_log.c:753(log_successful_authz_event_human_readable)
  Successful AuthZ: [SMB2,NTLMSSP] user [NT AUTHORITY]\[ANONYMOUS LOGON] [S-1-5-7] at [Wed, 13 Jan 2021 22:45:05.451887 CET] Remote host [ipv4:<Source_IP>:54198] local host [ipv4:<Destination_IP>:445]
[2021/01/13 22:45:05.454008,  1] ../../source3/smbd/service.c:369(create_connection_session_info)
  create_connection_session_info: guest user (from session setup) not permitted to access this share (Home)
[2021/01/13 22:45:05.454060,  1] ../../source3/smbd/service.c:557(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED



By whatever reason the session is no longer properly authenticated... for the folders, but...
In the same time, the copying seems to be going further (when e.g. "Skip" button is pressed).

Code:
[2021/01/13 22:45:38.051765,  2] ../../source3/smbd/close.c:828(close_normal_file)
  <username> closed file <FullPass>/<FileName1> (numopen=5) NT_STATUS_OK
[2021/01/13 22:45:42.230499,  2] ../../source3/smbd/close.c:828(close_normal_file)
  <username> closed file <FullPass>/<FileName2> (numopen=59) NT_STATUS_OK


Where log indicates that the files have been copied with proper user attached to it.
I've tried to add new files / folders into also "wrong" folders - they are copied fine, even when the access issue persists.

This behavior is not consistent in term what folders trigger issues, some initiate issue more often than others.
in some cases it can be a big number of folders gets copied, in some... this access issue appears almost instantly.

Any idea how to fix it?
 
Top