Hello everyone,
I use winbind against a Samba DC for nsswich, and on one client it works
perfectly (Samba 3.5.15 on all systems). On another client, everything works
except SID_TO_UID (i.e. wbinfo -i, -S ... which breaks directory listings,
too). I've now tried to narrow down the problem in a level 10 log, but I
need
some help interpreting. In log.winbindd, I see the following when running
wbinfo -S S-1-5-21-555555555-5555555555-5555555555-3032 (SID changed):
==========================================================[2012/12/06
17:43:12.841393, 3]
winbindd/winbindd_sid_to_uid.c:47(winbindd_sid_to_uid_send)
sid to uid S-1-5-21-555555555-5555555555-5555555555-3032
[2012/12/06 17:43:12.841517, 10] lib/gencache.c:334(gencache_get_data_blob)
Cache entry with key =
IDMAP/SID2UID/S-1-5-21-555555555-5555555555-5555555555-3032 couldn't be
found
[2012/12/06 17:43:12.841564, 10]
winbindd/winbindd_util.c:843(find_lookup_domain_from_sid)
find_lookup_domain_from_sid(S-1-5-21-555555555-5555555555-5555555555-3032)
[2012/12/06 17:43:12.841605, 10]
winbindd/winbindd_util.c:853(find_lookup_domain_from_sid)
calling find_our_domain
[2012/12/06 17:43:12.841679, 10]
winbindd/winbindd_cache.c:4805(wcache_fetch_ndr)
Entry has timed out
[2012/12/06 17:43:12.852143, 5]
winbindd/winbindd_sid_to_uid.c:90(winbindd_sid_to_uid_recv)
Could not convert sid S-1-5-21-555555555-5555555555-5555555555-3032:
NT_STATUS_NONE_MAPPED
[2012/12/06 17:43:12.852201, 10] winbindd/winbindd.c:655(wb_request_done)
wb_request_done[10630:SID_TO_UID]: NT_STATUS_NONE_MAPPED
==========================================================
wbinfo -S then yields:
Could not convert sid S-1-5-21-555555555-5555555555-5555555555-3032 to uid
Now I'm not sure what "Entry has timed out" means. This occurs
even when I do
"net cache flush" before. In the meantime, /var/log/samba/log.wb-SGI
looks
like the request is correctly answered by the server. The request comes in:
==========================================================[2012/12/06
17:43:12.841812, 10]
winbindd/winbindd_dual.c:62(child_read_request)
Need to read 28 extra bytes
[2012/12/06 17:43:12.841921, 4]
winbindd/winbindd_dual.c:1528(fork_domain_child)
child daemon request 63
[2012/12/06 17:43:12.841956, 10]
winbindd/winbindd_dual.c:485(child_process_request)
child_process_request: request fn NDRCMD
[2012/12/06 17:43:12.841986, 10]
winbindd/winbindd_dual_ndr.c:263(winbindd_dual_ndrcmd)
winbindd_dual_ndrcmd: Running command WBINT_LOOKUPSID (SGI)
[2012/12/06 17:43:12.842034, 1]
../librpc/ndr/ndr.c:251(ndr_print_function_debug)
wbint_LookupSid: struct wbint_LookupSid
in: struct wbint_LookupSid
sid : *
sid :
S-1-5-21-555555555-5555555555-5555555555-3032
==========================================================
... Then there's a lot of parsing and other noise, until we return with the
correct answer:
==========================================================[2012/12/06
17:43:12.850133, 10]
rpc_client/cli_lsarpc.c:191(rpccli_lsa_lookup_sids_noalloc)
LSA_LOOKUPSIDS returned 'NT_STATUS_OK', mapped count = 1'
[2012/12/06 17:43:12.850170, 5]
winbindd/winbindd_rpc.c:373(msrpc_sid_to_name)
Mapped sid to [SGI]\[matare]
[2012/12/06 17:43:12.850205, 10]
winbindd/winbindd_cache.c:555(refresh_sequence_number)
refresh_sequence_number: SGI time ok
[2012/12/06 17:43:12.850234, 10]
winbindd/winbindd_cache.c:600(refresh_sequence_number)
refresh_sequence_number: SGI seq number is now 1354812192
[2012/12/06 17:43:12.850375, 10]
winbindd/winbindd_cache.c:969(wcache_save_sid_to_name)
wcache_save_sid_to_name: S-1-5-21-555555555-5555555555-5555555555-3032 ->
matare (NT_STATUS_OK)
[2012/12/06 17:43:12.850410, 1]
../librpc/ndr/ndr.c:251(ndr_print_function_debug)
wbint_LookupSid: struct wbint_LookupSid
out: struct wbint_LookupSid
type : *
type : SID_NAME_USER (1)
domain : *
domain : *
domain : 'SGI'
name : *
name : *
name : 'matare'
result : NT_STATUS_OK
==========================================================
Note the times, which show that the mapping is retrieved from the DC by the
child process before the parent returns NT_STATUS_NONE_MAPPED. I find this
really confusing and frankly, I'm out of ideas where to look. Please, if you
have any idea let me know. Maybe I'm looking entirely in the wrong
direction...
Thanks,
Victor
