[Samba] winbind filling up log with "Possible deadlock: Trying to lookup SID xxx with passdb backend"

[Michael Wood]

On 13 December 2010 12:38, Andre Fonseca de Oliveira
<andre.f.oliveira at cgu.gov.br> wrote:
> Appreciate your reply.
>
>> On 6 December 2010 14:54, Andre Fonseca de Oliveira
>> <andre.f.oliveira at cgu.gov.br>  wrote:
>>>
>>> Hello,
>>>
>>> I have samba 3.3.8 installed on CentOS 5.5 on a production server.
>>>
>>> Winbind is filling up the logs with these messages:
>>>
>>> [2010/12/06 10:43:28,  0] winbindd/winbindd_passdb.c:sid_to_name(159)
>>>  Possible deadlock: Trying to lookup SID
>>> S-1-5-21-2106371596-187675891-3351287853 with passdb backend
>>
>> If you enable debug level 10, do you get this just before each of
>> those messages?
>>
>> Converting SID S-1-5-21-2106371596-187675891-3351287853
>
> Yes. Here is a snippet:
>
> [2010/12/13 08:28:59, 10]
> winbindd/winbindd_dual.c:child_process_request(452)
>  child_process_request: request fn LOOKUPSID
> [2010/12/13 08:28:59,  3]
> winbindd/winbindd_async.c:winbindd_dual_lookupsid(239)
>  [13229]: lookupsid S-1-5-21-2106371596-187675891-3351287853
> [2010/12/13 08:28:59, 10] winbindd/winbindd_passdb.c:sid_to_name(147)
> *Converting SID S-1-5-21-2106371596-187675891-3351287853*
> [2010/12/13 08:28:59,  0] winbindd/winbindd_passdb.c:sid_to_name(159)
>  Possible deadlock: Trying to lookup SID
> S-1-5-21-2106371596-187675891-3351287853 with passdb backend

OK, so it looks like it's coming from the sid_to_name() function
(which I should have realised from the line number (159) in the first
place).

>>> We have been having problems when activating winbind daemon.
>>>
>>> Could this error message be causing trouble?
>>
>> I don't think so.  I'm not sure what would cause this, but the code
>> logs that message if the SID is not in the BUILTIN domain and is not
>> in your domain and is not a local user/group and is not a well known
>> SID (like "Everybody").
>>
>> It looks like just a sanity check.  I have no idea what it has to do
>> with deadlocks, but perhaps someone familiar with the code could
>> comment.
>>
> The SID that appears in the logs is the domain SID:
>
> [root at phoenix samba]# net getdomainsid
> SID for local machine PHOENIX is: S-1-5-21-2106371596-187675891-3351287853
> SID for domain DF-CGU is: S-1-5-21-2106371596-187675891-3351287853

Strange.  So instead of the SID being e.g. a user or group, it is the
domain itself.  That explains why you're getting the message, but not
why someone is calling sid_to_name() on the domain SID.

I'm out of my depth here.  I don't know if it's normal to call
sid_to_name() on a domain SID.

>>> Attached is smb.conf globals section (shares removed).
>>>
>>> Thanks in advance

-- 
Michael Wood <esiotrot at gmail.com>