[Samba] winbind error after startup on Samba member server

[Peter Milesson]

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