On Sat, Oct 17, 2020 at 06:40:39AM +1300, Andrew Bartlett wrote:
> On Thu, 2020-10-15 at 15:37 +0200, Josip Rodin wrote:
> > On Thu, Oct 15, 2020 at 10:06:12AM +0200, Josip Rodin wrote:
> > > Further down the line, I also enabled more debugging, and observed
> > > messages like these:
> > >
> > > [2020/10/15 08:00:57.669098, 3, pid=29639, effective(0, 0),
> > > real(0, 0)] ../libcli/security/dom_sid.c:210(dom_sid_parse_endp)
> > > string_to_sid: SID root is not in a valid format
> > >
> > > [2020/10/15 08:00:57.669313, 3, pid=29639, effective(0, 0),
> > > real(0, 0)] ../libcli/security/dom_sid.c:210(dom_sid_parse_endp)
> > > string_to_sid: SID @users is not in a valid format
> > >
> > > I guess I'm gonna have to UTSL to figure that one out
> >
> > Err, I must be missing something, but I've been trying to add a few
> > changes
> > to libcli/security/dom_sid.c in the unpacked source, and then build
> > and
> > install that, and restart all daemons, but nothing changes in the
> > logs.
> >
> > How do I debug this?
>
> I wouldn't automatically assume this is catastrophic, it could just as
> easily be code that wants to parse something as a SID if it is a SID
> (avoiding a remote name lookup for a SID).
Yeah, in the meantime I figured out my mistake, I wasn't installing the
rebuilt samba-libs package (d'oh). You're right, those two SID resolutions
aren't fatal there, instead it can't seem to look up the users group
correctly.
That behavior looks like this at log level 10 (I added a few messages extra):
[2020/10/17 10:26:37.516221, 3, pid=16890, effective(0, 0), real(0, 0)]
../source3/smbd/share_access.c:98(token_contains_name)
token_contains_name: string_to_sid failed for @users
[2020/10/17 10:26:37.516338, 5, pid=16890, effective(0, 0), real(0, 0)]
../source3/auth/user_util.c:160(user_in_netgroup)
Unable to get default yp domain, let's try without specifying it
[2020/10/17 10:26:37.516370, 5, pid=16890, effective(0, 0), real(0, 0)]
../source3/auth/user_util.c:164(user_in_netgroup)
looking for user joy of domain (ANY) in netgroup users
[2020/10/17 10:26:37.516850, 3, pid=16890, effective(0, 0), real(0, 0)]
../source3/passdb/lookup_sid.c:476(lookup_name_smbconf)
lookup_name_smbconf: trying with winbind default domain name for users
[2020/10/17 10:26:37.516889, 10, pid=16890, effective(0, 0), real(0, 0)]
../source3/passdb/lookup_sid.c:113(lookup_name)
lookup_name: IMAGO\users => domain=[IMAGO], name=[users]
[2020/10/17 10:26:37.516909, 10, pid=16890, effective(0, 0), real(0, 0)]
../source3/passdb/lookup_sid.c:114(lookup_name)
lookup_name: flags = 0x077
[2020/10/17 10:26:37.521971, 3, pid=16890, effective(0, 0), real(0, 0)]
../source3/smbd/share_access.c:151(token_contains_name)
token_contains_name: returning false for users
[2020/10/17 10:26:37.522069, 10, pid=16890, effective(0, 0), real(0, 0)]
../source3/smbd/share_access.c:222(user_ok_token)
User joy not in 'valid users'
I'm afraid I haven't had the time yet to figure out why the netgroup code
can't resolve the users group (I'll keep at it). Yet this is particularly
surprising given that:
% sudo wbinfo -g | grep ^users$
users
...does seem to basically work... Unlike:
% sudo wbinfo -i root
failed to call wbcGetpwnam: WBC_ERR_DOMAIN_NOT_FOUND
Could not get info for user root
...which in turn logs the following:
[2020/10/17 10:58:00.352810, 6, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd.c:912(new_connectio
accepted socket 21
[2020/10/17 10:58:00.353036, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd.c:763(process_reque
process_request_send: process_request: request fn INTERFACE_VERSION
[2020/10/17 10:58:00.353141, 3, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd_misc.c:419(winbindd
[ 4727]: request interface version (version = 30)
[2020/10/17 10:58:00.353287, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd.c:846(process_reque
process_request_written: [4727:unknown request]: delivered response to client
[2020/10/17 10:58:00.353501, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd.c:739(process_reque
process_request: Handling async request 4727:GETPWNAM
[2020/10/17 10:58:00.353554, 3, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd_getpwnam.c:58(winbi
getpwnam root
[2020/10/17 10:58:00.353633, 1, pid=638, effective(0, 0), real(0, 0),
class=rpc_parse] ../librpc/ndr/ndr.c:471(ndr_print_function_deb
wbint_LookupName: struct wbint_LookupName
in: struct wbint_LookupName
domain : *
domain : 'IMAGO'
name : *
name : 'ROOT'
flags : 0x00000008 (8)
[2020/10/17 10:58:00.364890, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd_cache.c:4803(wcache_store_ndr)
could not fetch seqnum for domain IMAGO
[2020/10/17 10:58:00.365002, 1, pid=638, effective(0, 0), real(0, 0),
class=rpc_parse] ../librpc/ndr/ndr.c:471(ndr_print_function_debug)
wbint_LookupName: struct wbint_LookupName
out: struct wbint_LookupName
type : *
type : SID_NAME_USER (1)
sid : *
sid :
S-1-5-21-145766654-2861277506-3272706772-500
result : NT_STATUS_OK
[2020/10/17 10:58:00.365184, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/wb_sids2xids.c:113(wb_sids2xids_send)
SID 0: S-1-5-21-145766654-2861277506-3272706772-500
[2020/10/17 10:58:00.365281, 10, pid=638, effective(0, 0), real(0, 0),
class=tdb] ../source3/lib/gencache.c:301(gencache_set_data_blob)
Adding cache entry with
key=[IDMAP/SID2XID/S-1-5-21-145766654-2861277506-3272706772-500] and
timeout=[Thu Jan 1 00:00:00 1970 UTC] (-1602932280 seconds in the past)
[2020/10/17 10:58:00.365375, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind]
../source3/winbindd/winbindd_util.c:1458(find_lookup_domain_from_sid)
find_lookup_domain_from_sid: SID
[S-1-5-21-145766654-2861277506-3272706772-500]
[2020/10/17 10:58:00.365424, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind]
../source3/winbindd/winbindd_util.c:1501(find_lookup_domain_from_sid)
calling find_our_domain
[2020/10/17 10:58:00.365476, 1, pid=638, effective(0, 0), real(0, 0),
class=rpc_parse] ../librpc/ndr/ndr.c:471(ndr_print_function_debug)
wbint_LookupSids: struct wbint_LookupSids
in: struct wbint_LookupSids
sids : *
sids: struct lsa_SidArray
num_sids : 0x00000001 (1)
sids : *
sids: ARRAY(1)
sids: struct lsa_SidPtr
sid : *
sid :
S-1-5-21-145766654-2861277506-3272706772-500
[2020/10/17 10:58:00.369413, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd_cache.c:4803(wcache_store_ndr)
could not fetch seqnum for domain IMAGO
[2020/10/17 10:58:00.369539, 1, pid=638, effective(0, 0), real(0, 0),
class=rpc_parse] ../librpc/ndr/ndr.c:471(ndr_print_function_debug)
wbint_LookupSids: struct wbint_LookupSids
out: struct wbint_LookupSids
domains : *
domains: struct lsa_RefDomainList
count : 0x00000001 (1)
domains : *
domains: ARRAY(1)
domains: struct lsa_DomainInfo
name: struct lsa_StringLarge
length : 0x000a (10)
size : 0x000c (12)
string : *
string : 'IMAGO'
sid : *
sid :
S-1-5-21-145766654-2861277506-3272706772
max_size : 0x00000020 (32)
names : *
names: struct lsa_TransNameArray
count : 0x00000001 (1)
names : *
names: ARRAY(1)
names: struct lsa_TranslatedName
sid_type : SID_NAME_USER (1)
name: struct lsa_String
length : 0x0008 (8)
size : 0x0008 (8)
string : *
string : 'root'
sid_index : 0x00000000 (0)
result : NT_STATUS_OK
[2020/10/17 10:58:00.370022, 1, pid=638, effective(0, 0), real(0, 0),
class=rpc_parse] ../librpc/ndr/ndr.c:471(ndr_print_function_debug)
wbint_Sids2UnixIDs: struct wbint_Sids2UnixIDs
in: struct wbint_Sids2UnixIDs
domains : *
domains: struct lsa_RefDomainList
count : 0x00000001 (1)
domains : *
domains: ARRAY(1)
domains: struct lsa_DomainInfo
name: struct lsa_StringLarge
length : 0x000a (10)
size : 0x000c (12)
string : *
string : 'IMAGO'
sid : *
sid :
S-1-5-21-145766654-2861277506-3272706772
max_size : 0x00000001 (1)
ids : *
ids: struct wbint_TransIDArray
num_ids : 0x00000001 (1)
ids: ARRAY(1)
ids: struct wbint_TransID
type : ID_TYPE_UID (1)
domain_index : 0x00000000 (0)
rid : 0x000001f4 (500)
xid: struct unixid
id : 0xffffffff
(4294967295)
type : ID_TYPE_UID (1)
[2020/10/17 10:58:00.372004, 1, pid=638, effective(0, 0), real(0, 0),
class=rpc_parse] ../librpc/ndr/ndr.c:471(ndr_print_function_debug)
wbint_Sids2UnixIDs: struct wbint_Sids2UnixIDs
out: struct wbint_Sids2UnixIDs
ids : *
ids: struct wbint_TransIDArray
num_ids : 0x00000001 (1)
ids: ARRAY(1)
ids: struct wbint_TransID
type : ID_TYPE_UID (1)
domain_index : 0x00000000 (0)
rid : 0x000001f4 (500)
xid: struct unixid
id : 0xffffffff
(4294967295)
type :
ID_TYPE_NOT_SPECIFIED (0)
result : NT_STATUS_OK
[2020/10/17 10:58:00.372327, 10, pid=638, effective(0, 0), real(0, 0),
class=tdb] ../source3/lib/gencache.c:301(gencache_set_data_blob)
Adding cache entry with
key=[IDMAP/SID2XID/S-1-5-21-145766654-2861277506-3272706772-500] and
timeout=[Sat Oct 17 11:00:00 2020 UTC] (120 seconds ahead)
[2020/10/17 10:58:00.372412, 5, pid=638, effective(0, 0), real(0, 0),
class=winbind]
../source3/winbindd/winbindd_getpwnam.c:137(winbindd_getpwnam_recv)
Could not convert sid S-1-5-21-145766654-2861277506-3272706772-500:
NT_STATUS_NO_SUCH_USER
[2020/10/17 10:58:00.372488, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd.c:804(process_request_done)
process_request_done: [4727:GETPWNAM]: NT_STATUS_NO_SUCH_USER
[2020/10/17 10:58:00.372610, 10, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd.c:846(process_request_written)
process_request_written: [4727:GETPWNAM]: delivered response to client
[2020/10/17 10:58:00.372966, 6, pid=638, effective(0, 0), real(0, 0),
class=winbind] ../source3/winbindd/winbindd.c:961(winbind_client_request_read)
closing socket 21, client exited
This is weird on first look, because I certainly have a root user in LDAP
with the exact same SID as mentioned above... What is it converting?
I wonder what the message about not being able to find "seqnum" really
means?
I'm hoping this is something simple, like the SIDs in the LDAP being
malformed, but I still haven't figured out exactly how... any hints would
be welcome.
--
Josip Rodin
