Peter Milesson
2024-Jun-13 18:33 UTC
[Samba] winbind error after startup on Samba member server
On 13.06.2024 17:21, Rowland Penny via samba wrote:> On Thu, 13 Jun 2024 16:26:17 +0200 > Peter Milesson via samba <samba at lists.samba.org> wrote: > >> Hi folks, >> >> The last log record from journalctl -xeu winbind directly after >> winbind startup is: >> >> Jun 13 12:41:36 datasrv winbindd[582]: gpupdate_cmd_done: gpupdate >> failed with exit status 1 >> >> For completeness, the log entries for winbind startup is displayed >> below. >> >> Things seem to work though, but I have never seen it before (I don't >> like error messages). When I noticed the message I ran a sysvolcheck, >> but that was OK. After restart of winbind the message sequence was >> the same. There were no messages in the DC, that could be linked to >> the error. >> >> I would be grateful for a clarification, if the message is important, >> or I just shouldn't care. >> >> Best regards, >> >> Peter >> >> OS: Debian Bookworm with bookworm-backports (updated) >> Forest and domain levels 2016. >> >> smb.conf below >> >> [global] >> ??????? apply group policies = Yes >> ??????? debug pid = Yes >> ??????? debug uid = Yes >> ??????? dedicated keytab file = /etc/krb5.keytab >> ??????? disable netbios = Yes >> ??????? disable spoolss = Yes >> ??????? smb ports = 445 >> ??????? kerberos method = secrets and keytab >> ??????? printcap name = /dev/null >> ??????? realm = PRIVATE.TALPS >> ??????? restrict anonymous = 2 >> ??????? security = ADS >> ??????? server role = member server >> ??????? template homedir = /home/%U >> ??????? template shell = /bin/bash >> ??????? username map = /etc/samba/user.map >> ??????? min domain uid = 0 >> ??????? winbind enum groups = Yes >> ??????? winbind enum users = Yes >> ??????? winbind expand groups = 4 >> ??????? winbind refresh tickets = Yes >> ??????? winbind use default domain = Yes >> ??????? workgroup = PRIVATE >> ??????? idmap config private : range = 10000-99999 >> ??????? idmap config private : backend = rid >> ??????? idmap config * : range = 3000-9999 >> ??????? idmap config * : backend = tdb >> ??????? map acl inherit = Yes >> ??????? vfs objects = acl_xattr >> >> (and yes, I sincerely dislike how testparm is messing up smb.conf) >> winbind enum is just during on for testing >> >> >> excerpt from journalctl -xeu winbind on the member server >> >> Jun 13 12:41:35 datasrv samba-dcerpcd[597]:?? samba-dcerpcd version >> 4.20.1-Debian started. >> Jun 13 12:41:35 datasrv samba-dcerpcd[597]:?? Copyright Andrew >> Tridgell and the Samba Team 1992-2024 >> Jun 13 12:41:36 datasrv rpcd_lsad[610]: [2024/06/13 12:41:36.064459, >> 0, pid=610, effective(0, 0), real(0, 0)] >> source3/rpc_server/rpc_worker.c:1155(rpc_worker_main) >> Jun 13 12:41:36 datasrv rpcd_lsad[610]:?? rpcd_lsad version >> 4.20.1-Debian started. >> Jun 13 12:41:36 datasrv rpcd_lsad[610]:?? Copyright Andrew Tridgell >> and the Samba Team 1992-2024 >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.207955, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]:?? /usr/sbin/samba-gpupdate: >> Traceback (most recent call last): >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208001, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]:?? /usr/sbin/samba-gpupdate: >> File "/usr/sbin/samba-gpupdate", line 135, in <module> >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208019, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >> apply_gp(lp, creds, store, gp_extensions, username, >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208030, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]:?? /usr/sbin/samba-gpupdate: >> File "/usr/lib/python3/dist-packages/samba/gp/gpclass.py", line 1011, >> in apply_gp Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 >> 12:41:36.208413, 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >> gpos = get_gpo_list(dc_hostname, creds, lp, username) >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208434, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208444, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]:?? /usr/sbin/samba-gpupdate: >> File "/usr/lib/python3/dist-packages/samba/gp/gpclass.py", line 850, >> in get_gpo_list >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208597, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >> uac, dn = find_samaccount(samdb, username.split('\\')[-1]) >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208612, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208621, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]:?? /usr/sbin/samba-gpupdate: >> File "/usr/lib/python3/dist-packages/samba/gp/gpclass.py", line 694, >> in find_samaccount >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208633, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >> res = samdb.search(samdb.get_default_basedn(), ldb.SCOPE_SUBTREE, >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208650, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208660, >> 0, pid=582, effective(0, 0), real(0, 0)] >> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >> Jun 13 12:41:36 datasrv winbindd[582]:?? /usr/sbin/samba-gpupdate: >> _ldb.LdbError: (1, '00002020: Operation unavailable without >> authentication') Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 >> 12:41:36.230755, 0, pid=582, effective(0, 0), real(0, 0)] >> source3/winbindd/winbindd_gpupdate.c:182(gpupdate_cmd_done) >> Jun 13 12:41:36 datasrv winbindd[582]:?? gpupdate_cmd_done: gpupdate >> failed with exit status 1 > If you wade through all the log output it tells you the reason that > gpupdate is failing: > > (1, '00002020: Operation unavailable without authentication') > > Now why it is failing is another question. > Have you recently upgrading Samba and it has started doing this, or was > it working previously on 4.20.1 and is now failing ? > > Rowland >Hi Rowland, It's a completely new installation with the most recent Samba from Bookworm backports. I cannot compare with the previous installation, as the SSD died, and I had to set it up from scratch. Yes, I noticed that the failure is due to unavailable authentication, but why? And what are the consequences, if any? I can compare with another member server that started its life as a Debian Bullseye with Samba 4.17.x. It has been upgraded to keep up with the current status of Debian and Samba. The smb.conf is almost identical. But instead, it continues the old nagging (all the way from start): Jun 13 20:25:07 linuxdev winbindd[704]: [2024/06/13 20:25:07.417641,? 0] lib/util/util_runcmd.c:355(samba_runcmd_io_handler) Jun 13 20:25:07 linuxdev winbindd[704]:?? /usr/sbin/samba-gpupdate: ldb: Failed to connect to '/var/lib/samba/private/secrets.ldb' with backend 'tdb': Unable to open tdb '/var/lib/samba/private/secrets.ldb': No such file or directory The two winbindd logs seem to have samba-gpupdate in common, however. But why are they different? Both are now 4.20.1, and should behave similarly. But it does not seem to have any practical impact. BTW, secrets.ldb never existed. There is a secrets.tdb file, however. I'm not in the position to dig down in the Samba source code, but hopefully somebody with a deeper knowledge could explain what's going on. Best regards, Peter
Peter Milesson
2024-Jun-14 19:05 UTC
[Samba] winbind error after startup on Samba member server
On 13.06.2024 20:33, Peter Milesson via samba wrote:> > > On 13.06.2024 17:21, Rowland Penny via samba wrote: >> On Thu, 13 Jun 2024 16:26:17 +0200 >> Peter Milesson via samba <samba at lists.samba.org> wrote: >> >>> Hi folks, >>> >>> The last log record from journalctl -xeu winbind directly after >>> winbind startup is: >>> >>> ???? Jun 13 12:41:36 datasrv winbindd[582]: gpupdate_cmd_done: gpupdate >>> ???? failed with exit status 1 >>> >>> For completeness, the log entries for winbind startup is displayed >>> below. >>> >>> Things seem to work though, but I have never seen it before (I don't >>> like error messages). When I noticed the message I ran a sysvolcheck, >>> but that was OK. After restart of winbind the message sequence was >>> the same. There were no messages in the DC, that could be linked to >>> the error. >>> >>> I would be grateful for a clarification, if the message is important, >>> or I just shouldn't care. >>> >>> Best regards, >>> >>> Peter >>> >>> OS: Debian Bookworm with bookworm-backports (updated) >>> Forest and domain levels 2016. >>> >>> smb.conf below >>> >>> [global] >>> ? ??????? apply group policies = Yes >>> ? ??????? debug pid = Yes >>> ? ??????? debug uid = Yes >>> ? ??????? dedicated keytab file = /etc/krb5.keytab >>> ? ??????? disable netbios = Yes >>> ? ??????? disable spoolss = Yes >>> ? ??????? smb ports = 445 >>> ? ??????? kerberos method = secrets and keytab >>> ? ??????? printcap name = /dev/null >>> ? ??????? realm = PRIVATE.TALPS >>> ? ??????? restrict anonymous = 2 >>> ? ??????? security = ADS >>> ? ??????? server role = member server >>> ? ??????? template homedir = /home/%U >>> ? ??????? template shell = /bin/bash >>> ? ??????? username map = /etc/samba/user.map >>> ? ??????? min domain uid = 0 >>> ? ??????? winbind enum groups = Yes >>> ? ??????? winbind enum users = Yes >>> ? ??????? winbind expand groups = 4 >>> ? ??????? winbind refresh tickets = Yes >>> ? ??????? winbind use default domain = Yes >>> ? ??????? workgroup = PRIVATE >>> ? ??????? idmap config private : range = 10000-99999 >>> ? ??????? idmap config private : backend = rid >>> ? ??????? idmap config * : range = 3000-9999 >>> ? ??????? idmap config * : backend = tdb >>> ? ??????? map acl inherit = Yes >>> ? ??????? vfs objects = acl_xattr >>> >>> (and yes, I sincerely dislike how testparm is messing up smb.conf) >>> winbind enum is just during on for testing >>> >>> >>> excerpt from journalctl -xeu winbind on the member server >>> >>> Jun 13 12:41:35 datasrv samba-dcerpcd[597]:?? samba-dcerpcd version >>> 4.20.1-Debian started. >>> Jun 13 12:41:35 datasrv samba-dcerpcd[597]:?? Copyright Andrew >>> Tridgell and the Samba Team 1992-2024 >>> Jun 13 12:41:36 datasrv rpcd_lsad[610]: [2024/06/13 12:41:36.064459, >>> 0, pid=610, effective(0, 0), real(0, 0)] >>> source3/rpc_server/rpc_worker.c:1155(rpc_worker_main) >>> Jun 13 12:41:36 datasrv rpcd_lsad[610]:?? rpcd_lsad version >>> 4.20.1-Debian started. >>> Jun 13 12:41:36 datasrv rpcd_lsad[610]:?? Copyright Andrew Tridgell >>> and the Samba Team 1992-2024 >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.207955, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> Traceback (most recent call last): >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208001, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> File "/usr/sbin/samba-gpupdate", line 135, in <module> >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208019, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> apply_gp(lp, creds, store, gp_extensions, username, >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208030, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> File "/usr/lib/python3/dist-packages/samba/gp/gpclass.py", line 1011, >>> in apply_gp Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 >>> 12:41:36.208413, 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> gpos = get_gpo_list(dc_hostname, creds, lp, username) >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208434, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208444, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> File "/usr/lib/python3/dist-packages/samba/gp/gpclass.py", line 850, >>> in get_gpo_list >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208597, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> uac, dn = find_samaccount(samdb, username.split('\\')[-1]) >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208612, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208621, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> File "/usr/lib/python3/dist-packages/samba/gp/gpclass.py", line 694, >>> in find_samaccount >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208633, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> res = samdb.search(samdb.get_default_basedn(), ldb.SCOPE_SUBTREE, >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208650, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ >>> Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 12:41:36.208660, >>> 0, pid=582, effective(0, 0), real(0, 0)] >>> lib/util/util_runcmd.c:355(samba_runcmd_io_handler) >>> Jun 13 12:41:36 datasrv winbindd[582]: /usr/sbin/samba-gpupdate: >>> _ldb.LdbError: (1, '00002020: Operation unavailable without >>> authentication') Jun 13 12:41:36 datasrv winbindd[582]: [2024/06/13 >>> 12:41:36.230755, 0, pid=582, effective(0, 0), real(0, 0)] >>> source3/winbindd/winbindd_gpupdate.c:182(gpupdate_cmd_done) >>> Jun 13 12:41:36 datasrv winbindd[582]:?? gpupdate_cmd_done: gpupdate >>> failed with exit status 1 >> If you wade through all the log output it tells you the reason that >> gpupdate is failing: >> >> (1, '00002020: Operation unavailable without authentication') >> >> Now why it is failing is another question. >> Have you recently upgrading Samba and it has started doing this, or was >> it working previously on 4.20.1 and is now failing ? >> >> Rowland >> > Hi Rowland, > > It's a completely new installation with the most recent Samba from > Bookworm backports. I cannot compare with the previous installation, > as the SSD died, and I had to set it up from scratch. > > Yes, I noticed that the failure is due to unavailable authentication, > but why? And what are the consequences, if any? > > I can compare with another member server that started its life as a > Debian Bullseye with Samba 4.17.x. It has been upgraded to keep up > with the current status of Debian and Samba. The smb.conf is almost > identical. But instead, it continues the old nagging (all the way from > start): > > Jun 13 20:25:07 linuxdev winbindd[704]: [2024/06/13 20:25:07.417641,? > 0] lib/util/util_runcmd.c:355(samba_runcmd_io_handler) > Jun 13 20:25:07 linuxdev winbindd[704]: /usr/sbin/samba-gpupdate: ldb: > Failed to connect to '/var/lib/samba/private/secrets.ldb' with backend > 'tdb': Unable to open tdb '/var/lib/samba/private/secrets.ldb': No > such file or directory > > The two winbindd logs seem to have samba-gpupdate in common, however. > But why are they different? Both are now 4.20.1, and should behave > similarly. But it does not seem to have any practical impact. BTW, > secrets.ldb never existed. There is a secrets.tdb file, however. > > I'm not in the position to dig down in the Samba source code, but > hopefully somebody with a deeper knowledge could explain what's going on. > > Best regards, > > Peter > > >Hi folks, I think I have sorted it out. Hopefully. I installed samba-dsdb-modules, and then the complaints stopped. I had the impression that samba-dsdb-modules are only required on a AD DC, but that's probably not completely true. On the other server with frequent complaints about "Failed to connect to '/var/lib/samba/private/secrets.ldb'", it was a dangling misconfiguration in smb.conf. The parameter "inherit acls" seems to be the culprit. I set ACLs exclusively from Windows and this parameter is used when setting POSIX ACLs. Now, Samba seems to be satisfied. I wish everybody a nice weekend. Peter