Hi folks,
The smb.conf and other information after specification of the problems.
The journal on a AD domain member server is cluttered with permission
denied entries of this message pair:
Jan 31 07:02:26 konsrvfast smbd[436004]: [2023/01/31
07:02:26.083500,? 0, effective(11025, 10515), real(11025, 0)]
../../source3/smbd/smb2_service.c:168(chdir_current_service)
Jan 31 07:02:26 konsrvfast smbd[436004]:?? chdir_current_service:
vfs_ChDir(/data/samba/profiles) failed: Permission denied. Current
token: uid=11025, gid=10515, 5 groups: 11025 10515 3003 3004 3006
uid=11025 is a Windows 10 workstation, and gid=10515 is the domain
computers object.
There are also recurring entry blocks of the following type:
Jan 30 19:55:39 konsrvfast rpcd_classic[358632]: [2023/01/30
19:55:39.802586,? 0, effective(11006, 10513), real(11006, 0)]
../../lib/util/debug.c:1264(reopen_one_log)
Jan 30 19:55:39 konsrvfast rpcd_classic[358632]:?? reopen_one_log:
Unable to open new log file '/var/log/samba/log.rpcd_classic':
Permission denied
Jan 30 19:55:39 konsrvfast rpcd_classic[358632]: [2023/01/30
19:55:39.803020,? 0, effective(11006, 10513), real(11006, 0)]
../../lib/util/debug.c:1264(reopen_one_log)
Jan 30 19:55:39 konsrvfast rpcd_classic[358632]:?? reopen_one_log:
Unable to open new log file '/var/log/samba/log.rpcd_classic':
Permission denied
Jan 30 19:55:39 konsrvfast rpcd_classic[358632]: [2023/01/30
19:55:39.803056,? 0, effective(11006, 10513), real(11006, 0)]
../../lib/util/debug.c:1264(reopen_one_log)
Jan 30 19:55:39 konsrvfast rpcd_classic[358632]:?? reopen_one_log:
Unable to open new log file '/var/log/samba/log.rpcd_classic':
Permission denied
Jan 30 19:55:55 konsrvfast rpcd_classic[358632]: [2023/01/30
19:55:55.231090,? 0, effective(11006, 10513), real(11006, 0)]
../../source3/lib/sharesec.c:161(share_info_db_init)
Jan 30 19:55:55 konsrvfast rpcd_classic[358632]:?? Failed to open
share info database /var/lib/samba/share_info.tdb (Permission denied)
Jan 30 19:55:59 konsrvfast rpcd_classic[358632]: [2023/01/30
19:55:59.715024,? 0, effective(11006, 10513), real(11006, 0)]
../../source3/lib/sharesec.c:161(share_info_db_init)
After scanning the samba logs I found the following:
*/var/log/samba/log.rpcd_classic (those 2 entries occur frequently)*
[2023/01/30 15:15:28.729356,? 0, effective(11156, 10513),
real(11156, 0)] ../../lib/util/debug.c:1264(reopen_one_log)?
reopen_one_log: Unable to open new log file
'/var/log/samba/log.rpcd_classic': Permission denied
[2023/01/30 20:09:09.054259,? 0, effective(11006, 10513),
real(11006, 0)]
../../source3/lib/sharesec.c:161(share_info_db_init)? Failed to open
share info database /var/lib/samba/share_info.tdb (Permission denied)
*/var/log/samba/log.samba-dcerpcd (the following block repeats frequently)*
[2023/01/30 15:31:55.316639,? 1, effective(0, 0), real(0, 0)]
../../source3/rpc_client/cli_pipe.c:3014(rpc_pipe_open_ncalrpc)
rpc_pipe_open_ncalrpc: connect(/run/samba/ncalrpc/EPMAPPER) failed:
No such file or directory
[2023/01/30 15:31:55.341724,? 1, effective(0, 0), real(0, 0)]
../../source3/rpc_server/rpc_host.c:1763(rpc_worker_exited)
rpc_worker_exited: No worker with PID 328204
[2023/01/30 15:34:13,? 0] ../../source3/rpc_server/rpc_host.c:2966(main)
When checking the directory /run/samba/ncalrpc there is really no such
file as EPMAPPER, but there exists /run/samba/ncalrpc/np/epmapper
*/var/log/samba/smbd.log (the following entry is spawned thousands of
times within a second)*
[2023/01/30 20:07:59.636915,? 1, effective(11006, 10513), real(11006,
0)] ../../source3/auth/token_util.c:1020(create_token_from_sid)
? getpwuid(1011) failed
*/var/log/samba/winbindd (the entries below frequently occuring)*
[2023/01/30 23:34:57.527639,? 1, effective(0, 0), real(0, 0)]
../../source3/winbindd/winbindd_getpwuid.c:118(winbindd_getpwuid_recv)
? Could not convert sid S-0-0: NT_STATUS_NO_SUCH_USER
[2023/01/31 00:17:01.889654,? 1, effective(0, 0), real(0, 0)]
../../source3/winbindd/winbindd_getgroups.c:259(winbindd_getgroups_recv)
? Could not convert sid S-0-0: NT_STATUS_NONE_MAPPED
(occurs several times per second, hundreds of consecutive entries)
[2023/01/30 23:30:50.246781,? 1, effective(0, 0), real(0, 0)]
../../source3/winbindd/winbindd_getgrgid.c:124(winbindd_getgrgid_recv)
? Could not convert sid S-0-0: NT_STATUS_NO_SUCH_GROUP
From the users point of view everything seems normal, there have been
no complaints about inaccessible folders or files, or other permission
issues.
The server is a member of a AD domain, and everything in the domain is
managed via the RSAT tools. There are only Windows ACLs, no Posix ACLs.
There are only a couple of local linux accounts for server
administration, with user names that do not conflict with AD user names.
The domain is working, no DNS problems.
If would be grateful if somebody could point out what's going wrong here.
Best regards,
Peter
Server: HPE ProLiant DL325 with NVMe drives in a hardware RAID
configuration, 32GB RAM
OS: Debian Bookworm
Samba version: 4.17.4
smb.conf
# Global parameters
[global]
??????? client signing = required
??????? debug uid = Yes
??????? dedicated keytab file = /etc/krb5.keytab
??????? disable netbios = Yes
??????? disable spoolss = Yes
??????? kerberos method = secrets and keytab
??????? log level = 1
??????? panic action = /usr/share/samba/panic-action %d
??????? printcap name = /dev/null
??????? realm = SAMDOM.TALPS
??????? restrict anonymous = 2
??????? security = ADS
??????? server role = member server
??????? smb ports = 445
??????? template homedir = /home/%U
??????? template shell = /sbin/nologin
??????? winbind use default domain = true
??????? timestamp logs = Yes
??????? username map = /etc/samba/user.map
??????? winbind refresh tickets = Yes
??????? workgroup = SAMDOM
??????? idmap config samdom : range = 10000-99999
??????? idmap config samdom : backend = rid
??????? idmap config * : range = 3000-9999
??????? idmap config * : backend = tdb
??????? map acl inherit = Yes
??????? vfs objects = acl_xattr
??????? hide unreadable = yes
??????? veto files = /.bash_logout/.bash_profile/.bash_history/.bashrc/
[Homes$]
??????? readonly = no
??????? path = /data/samba/homes
??????? csc policy = disable
[Profiles$]
??????? readonly = no
??????? path = /data/samba/profiles
??????? csc policy = disable
[Users$]
??????? readonly = no
??????? path = /data/samba/users
??????? csc policy = disable
[Share1]
??????? readonly = no
??????? path = /data/samba/Share1
[Share2]
??????? readonly = no
??????? path = /data/samba/Share2
On 31/01/2023 06:59, Peter Milesson via samba wrote:> Hi folks, > > The smb.conf and other information after specification of the problems. > > The journal on a AD domain member server is cluttered with permission > denied entries of this message pair: > > ?? Jan 31 07:02:26 konsrvfast smbd[436004]: [2023/01/31 > ?? 07:02:26.083500,? 0, effective(11025, 10515), real(11025, 0)] > ?? ../../source3/smbd/smb2_service.c:168(chdir_current_service) > > ?? Jan 31 07:02:26 konsrvfast smbd[436004]:?? chdir_current_service: > ?? vfs_ChDir(/data/samba/profiles) failed: Permission denied. Current > ?? token: uid=11025, gid=10515, 5 groups: 11025 10515 3003 3004 3006 > > uid=11025 is a Windows 10 workstation, and gid=10515 is the domain > computers object. > > > There are also recurring entry blocks of the following type: > > ?? Jan 30 19:55:39 konsrvfast rpcd_classic[358632]: [2023/01/30 > ?? 19:55:39.802586,? 0, effective(11006, 10513), real(11006, 0)] > ?? ../../lib/util/debug.c:1264(reopen_one_log) > ?? Jan 30 19:55:39 konsrvfast rpcd_classic[358632]:?? reopen_one_log: > ?? Unable to open new log file '/var/log/samba/log.rpcd_classic': > ?? Permission denied > ?? Jan 30 19:55:39 konsrvfast rpcd_classic[358632]: [2023/01/30 > ?? 19:55:39.803020,? 0, effective(11006, 10513), real(11006, 0)] > ?? ../../lib/util/debug.c:1264(reopen_one_log) > ?? Jan 30 19:55:39 konsrvfast rpcd_classic[358632]:?? reopen_one_log: > ?? Unable to open new log file '/var/log/samba/log.rpcd_classic': > ?? Permission denied > ?? Jan 30 19:55:39 konsrvfast rpcd_classic[358632]: [2023/01/30 > ?? 19:55:39.803056,? 0, effective(11006, 10513), real(11006, 0)] > ?? ../../lib/util/debug.c:1264(reopen_one_log) > ?? Jan 30 19:55:39 konsrvfast rpcd_classic[358632]:?? reopen_one_log: > ?? Unable to open new log file '/var/log/samba/log.rpcd_classic': > ?? Permission denied > ?? Jan 30 19:55:55 konsrvfast rpcd_classic[358632]: [2023/01/30 > ?? 19:55:55.231090,? 0, effective(11006, 10513), real(11006, 0)] > ?? ../../source3/lib/sharesec.c:161(share_info_db_init) > ?? Jan 30 19:55:55 konsrvfast rpcd_classic[358632]:?? Failed to open > ?? share info database /var/lib/samba/share_info.tdb (Permission denied) > ?? Jan 30 19:55:59 konsrvfast rpcd_classic[358632]: [2023/01/30 > ?? 19:55:59.715024,? 0, effective(11006, 10513), real(11006, 0)] > ?? ../../source3/lib/sharesec.c:161(share_info_db_init) > > > After scanning the samba logs I found the following: > > */var/log/samba/log.rpcd_classic (those 2 entries occur frequently)* > > ?? [2023/01/30 15:15:28.729356,? 0, effective(11156, 10513), > ?? real(11156, 0)] ../../lib/util/debug.c:1264(reopen_one_log) > ?? reopen_one_log: Unable to open new log file > ?? '/var/log/samba/log.rpcd_classic': Permission denied > > ?? [2023/01/30 20:09:09.054259,? 0, effective(11006, 10513), > ?? real(11006, 0)] > ?? ../../source3/lib/sharesec.c:161(share_info_db_init)? Failed to open > ?? share info database /var/lib/samba/share_info.tdb (Permission denied) > > > */var/log/samba/log.samba-dcerpcd (the following block repeats frequently)* > > ?? [2023/01/30 15:31:55.316639,? 1, effective(0, 0), real(0, 0)] > ?? ../../source3/rpc_client/cli_pipe.c:3014(rpc_pipe_open_ncalrpc) > ?? rpc_pipe_open_ncalrpc: connect(/run/samba/ncalrpc/EPMAPPER) failed: > ?? No such file or directory > ?? [2023/01/30 15:31:55.341724,? 1, effective(0, 0), real(0, 0)] > ?? ../../source3/rpc_server/rpc_host.c:1763(rpc_worker_exited) > ?? rpc_worker_exited: No worker with PID 328204 > ?? [2023/01/30 15:34:13,? 0] > ../../source3/rpc_server/rpc_host.c:2966(main) > > When checking the directory /run/samba/ncalrpc there is really no such > file as EPMAPPER, but there exists /run/samba/ncalrpc/np/epmapper > > > */var/log/samba/smbd.log (the following entry is spawned thousands of > times within a second)* > > [2023/01/30 20:07:59.636915,? 1, effective(11006, 10513), real(11006, > 0)] ../../source3/auth/token_util.c:1020(create_token_from_sid) > ? getpwuid(1011) failed > > > */var/log/samba/winbindd (the entries below frequently occuring)* > > [2023/01/30 23:34:57.527639,? 1, effective(0, 0), real(0, 0)] > ../../source3/winbindd/winbindd_getpwuid.c:118(winbindd_getpwuid_recv) > ? Could not convert sid S-0-0: NT_STATUS_NO_SUCH_USER > > [2023/01/31 00:17:01.889654,? 1, effective(0, 0), real(0, 0)] > ../../source3/winbindd/winbindd_getgroups.c:259(winbindd_getgroups_recv) > ? Could not convert sid S-0-0: NT_STATUS_NONE_MAPPED > > (occurs several times per second, hundreds of consecutive entries) > [2023/01/30 23:30:50.246781,? 1, effective(0, 0), real(0, 0)] > ../../source3/winbindd/winbindd_getgrgid.c:124(winbindd_getgrgid_recv) > ? Could not convert sid S-0-0: NT_STATUS_NO_SUCH_GROUP > > > From the users point of view everything seems normal, there have been > no complaints about inaccessible folders or files, or other permission > issues. > > The server is a member of a AD domain, and everything in the domain is > managed via the RSAT tools. There are only Windows ACLs, no Posix ACLs. > There are only a couple of local linux accounts for server > administration, with user names that do not conflict with AD user names. > The domain is working, no DNS problems. > > If would be grateful if somebody could point out what's going wrong here. >I don't think anything is going wrong here, it just seems that, lately, Samba has got very chatty. You are about the third person to raise this 'problem', I wonder if it has something to do with all the changes there have been lately ??? Perhaps you would like to raise a bug report about this ? Rowland
31.01.2023 09:59, Peter Milesson via samba ?????:> The journal on a AD domain member server is cluttered with permission denied entries of this message pair: > > ?? Jan 31 07:02:26 konsrvfast smbd[436004]: [2023/01/31 > ?? 07:02:26.083500,? 0, effective(11025, 10515), real(11025, 0)] > ?? ../../source3/smbd/smb2_service.c:168(chdir_current_service) > > ?? Jan 31 07:02:26 konsrvfast smbd[436004]:?? chdir_current_service: > ?? vfs_ChDir(/data/samba/profiles) failed: Permission denied. Current > ?? token: uid=11025, gid=10515, 5 groups: 11025 10515 3003 3004 3006 > > uid=11025 is a Windows 10 workstation, and gid=10515 is the domain computers object.This will be logged as long as you keep this dir inaccessible. I don't know why but win workstations also tries to access profile shares for their accounts. It's okay if there's no profile for them, but the share itself should be accessible, or else this type of message will be logged by samba. It is just the permission problem. A user with uid 11025 and the specified set of groups can't access the specified directory, that's all.> There are also recurring entry blocks of the following type: > > ?? Jan 30 19:55:39 konsrvfast rpcd_classic[358632]: [2023/01/30 > ?? 19:55:39.802586,? 0, effective(11006, 10513), real(11006, 0)] > ?? ../../lib/util/debug.c:1264(reopen_one_log) > ?? Jan 30 19:55:39 konsrvfast rpcd_classic[358632]:?? reopen_one_log: > ?? Unable to open new log file '/var/log/samba/log.rpcd_classic': > ?? Permission deniedAnd this one is interesting. Does this file exist? Can you tell under which uid this process is running? I'm still new to samba process model, and I don't even see rpcd_classic process running here, - I don't know what it is doing and under which uid it is running. But the file exists on my system, and the last entry in there is [2023/01/04 16:07:20, 0] ../../source3/rpc_server/rpc_worker.c:1105(rpc_worker_main) rpcd_classic version 4.17.3-Debian started. which was before 4.17.4 upgrade (it is debian system). If it is running as root, it shuldn't have issues opening files in there.> ?? Jan 30 19:55:55 konsrvfast rpcd_classic[358632]:?? Failed to open > ?? share info database /var/lib/samba/share_info.tdb (Permission denied)And it's the same thing. This file is owned by root:root, mode 0600, so if rpcd_classic is not run as root, it wont be able to open this file and the log file. Can someone tell which process it is and under which uid should it run?> */var/log/samba/smbd.log (the following entry is spawned thousands of times within a second)* > > [2023/01/30 20:07:59.636915,? 1, effective(11006, 10513), real(11006, 0)] ../../source3/auth/token_util.c:1020(create_token_from_sid) > ? getpwuid(1011) failed> */var/log/samba/winbindd (the entries below frequently occuring)* > > [2023/01/30 23:34:57.527639,? 1, effective(0, 0), real(0, 0)] ../../source3/winbindd/winbindd_getpwuid.c:118(winbindd_getpwuid_recv) > ? Could not convert sid S-0-0: NT_STATUS_NO_SUCH_USER > > [2023/01/31 00:17:01.889654,? 1, effective(0, 0), real(0, 0)] ../../source3/winbindd/winbindd_getgroups.c:259(winbindd_getgroups_recv) > ? Could not convert sid S-0-0: NT_STATUS_NONE_MAPPED > > (occurs several times per second, hundreds of consecutive entries) > [2023/01/30 23:30:50.246781,? 1, effective(0, 0), real(0, 0)] ../../source3/winbindd/winbindd_getgrgid.c:124(winbindd_getgrgid_recv) > ? Could not convert sid S-0-0: NT_STATUS_NO_SUCH_GROUPI've seen those too (incl. EPMAPPER thing), fixed some of them by changing configs after googling. But it was lots of many small changes due to various other issues, I don't recall the details anymore. Lemme take a look at this rpcd_classic first.. /mjt