Dustin Howett
2025-Apr-23 02:09 UTC
[Samba] Fwd: Domain member fails to map SID>*ID after DC migrated from Server 2022 to 2025
Hey all,
I have a samba (tested 4.17+debian, 4.22.1+debian) domain member of a
very small domain.
I recently upgraded the PDC from Windows Server 2022 to 2025, and
began to observe widespread user mapping failures on the samba domain
member.
Given that my production environment ranges from "annoying" to
"hard
to turn into a lab," I reproduced the problem from first principles in
an isolated lab environment.
For this lab, I built a single DC on Server 2022 and a single member
server running Debian 12.
After verifying it worked, I cloned both of the nodes to a new
isolated network and upgraded the DC to Server 2025. Hopefully this
will clarify why the log snippets below contain the same machine names
but interleaved/inconsistent timestamps (considering that the 2022
snippet was taken after the 2025 one...)
I'm not sure what I am looking at, or looking *for*, but I've made a
few observations:
- The proximal failing call seems to be sids2xids.
- It does not have a cached domain controller, so it attempts to find one
- It attempts to find one using DsGetDcName
- On Server 2022, DsGetDcName returns a netr_DsRGetDCNameInfo
- On Server 2025, it returns a failure instead: NT_STATUS_NO_SUCH_DOMAIN
The outgoing request looks the same. This is true of 4.17 (Debian 12)
and 4.22 (Debian sid).
Any ideas? What can I capture to help troubleshoot? Happy to keep labbing.
Logs follow,
d
---8< failure log (server 2025, client 4.17) ---
[2025/04/23 01:42:44.721118, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:676(new_connection)
Accepted client socket 22
[2025/04/23 01:42:44.721177, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:524(process_request_send)
process_request_send: process_request: request fn INTERFACE_VERSION
[2025/04/23 01:42:44.721185, 3, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_misc.c:355(winbindd_interface_version)
winbindd_interface_version: [wbinfo (648)]: request interface
version (version = 32)
[2025/04/23 01:42:44.721216, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:608(process_request_written)
process_request_written: [wbinfo(648):INTERFACE_VERSION]: delivered
response to client
[2025/04/23 01:42:44.721232, 3, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:496(process_request_send)
process_request_send: [wbinfo (648)] Handling async request: GETPWNAM
[2025/04/23 01:42:44.721244, 3, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_getpwnam.c:59(winbindd_getpwnam_send)
[wbinfo (648)] Winbind external command GETPWNAM start.
Query username 'domtest\dustin'.
[2025/04/23 01:42:44.721253, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_lookupname.c:52(wb_lookupname_send)
WB command lookupname start.
Search namespace 'domtest' and domain 'DOMTEST' for name
'dustin'.
[2025/04/23 01:42:44.721271, 1, pid=631, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_LookupName: struct wbint_LookupName
in: struct wbint_LookupName
domain : *
domain : 'DOMTEST'
name : *
name : 'DUSTIN'
flags : 0x00000008 (8)
[2025/04/23 01:42:44.722815, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd_cache.c:4779(wcache_store_ndr)
could not fetch seqnum for domain DOMTEST
[2025/04/23 01:42:44.722826, 1, pid=631, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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-2560703367-3512107002-2871390249-1103
result : NT_STATUS_OK
[2025/04/23 01:42:44.722854, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_lookupname.c:118(wb_lookupname_recv)
WB command lookupname end.
Found SID S-1-5-21-2560703367-3512107002-2871390249-1103 with SID type 1.
[2025/04/23 01:42:44.722924, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_getpwsid.c:49(wb_getpwsid_send)
WB command getpwsid start.
Query user SID S-1-5-21-2560703367-3512107002-2871390249-1103.
[2025/04/23 01:42:44.722980, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:56(wb_queryuser_send)
WB command queryuser start.
Query user sid S-1-5-21-2560703367-3512107002-2871390249-1103
[2025/04/23 01:42:44.723037, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_queryuser.c:95(wb_queryuser_idmap_setup_done)
Convert the user SID S-1-5-21-2560703367-3512107002-2871390249-1103 to XID.
[2025/04/23 01:42:44.723046, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:84(wb_sids2xids_send)
WB command sids2xids start.
Resolving 1 SID(s).
[2025/04/23 01:42:44.723054, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:156(wb_sids2xids_send)
0: SID S-1-5-21-2560703367-3512107002-2871390249-1103
[2025/04/23 01:42:44.723063, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:175(wb_sids2xids_send)
Found 0 (out of 1) SID(s) in cache.
[2025/04/23 01:42:44.723070, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:206(wb_sids2xids_idmap_setup_done)
We will loop over 1 SID(s) (skipping those already resolved via
cache) and over 3 domain(s).
[2025/04/23 01:42:44.723078, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:223(wb_sids2xids_idmap_setup_done)
0: Processing SID S-1-5-21-2560703367-3512107002-2871390249-1103
[2025/04/23 01:42:44.723083, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:236(wb_sids2xids_idmap_setup_done)
0: Split SID S-1-5-21-2560703367-3512107002-2871390249-1103 into
domain SID S-1-5-21-2560703367-3512107002-2871390249 and RID 1103
[2025/04/23 01:42:44.723092, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:263(wb_sids2xids_idmap_setup_done)
Looping over 3 domain(s) to find domain SID
S-1-5-21-2560703367-3512107002-2871390249.
[2025/04/23 01:42:44.723097, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:277(wb_sids2xids_idmap_setup_done)
Found domain 'domtest'.
[2025/04/23 01:42:44.723102, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:308(wb_sids2xids_idmap_setup_done)
Setting type hint ID_TYPE_BOTH for domain 'domtest'.
[2025/04/23 01:42:44.723108, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:470(wb_sids2xids_next_sids2unix)
Processing next domain (dom_index=0, idmap_doms.count=1, lookup_count=0).
[2025/04/23 01:42:44.723116, 1, pid=631, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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 : 0x000e (14)
size : 0x0010 (16)
string : *
string :
'domtest'
sid : *
sid :
S-1-5-21-2560703367-3512107002-2871390249
max_size : 0x00000001 (1)
ids : *
ids: struct wbint_TransIDArray
num_ids : 0x00000001 (1)
ids: ARRAY(1)
ids: struct wbint_TransID
type_hint : ID_TYPE_BOTH (3)
domain_index : 0x00000000 (0)
rid : 0x0000044f (1103)
xid: struct unixid
id :
0xffffffff (4294967295)
type :
ID_TYPE_NOT_SPECIFIED (0)
[2025/04/23 01:42:44.723217, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd_dual.c:1667(fork_domain_child)
fork_domain_child called without domain.
[2025/04/23 01:42:44.723804, 10, pid=649, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd_dual.c:1739(fork_domain_child)
Child process 649
[2025/04/23 01:42:44.723921, 10, pid=649, effective(0, 0), real(0, 0)]
../../lib/messaging/messages_dgm_ref.c:163(msg_dgm_ref_destructor)
msg_dgm_ref_destructor: refs=0x5c675f7388f0
[2025/04/23 01:42:44.723992, 10, pid=649, effective(0, 0), real(0, 0)]
../../lib/messaging/messages_dgm_ref.c:80(messaging_dgm_ref)
messaging_dgm_ref: messaging_dgm_init returned Success
[2025/04/23 01:42:44.724004, 10, pid=649, effective(0, 0), real(0, 0)]
../../lib/messaging/messages_dgm_ref.c:109(messaging_dgm_ref)
messaging_dgm_ref: unique = 775737577211272171
[2025/04/23 01:42:44.724018, 2, pid=649, effective(0, 0), real(0, 0)]
../../source3/lib/tallocmsg.c:84(register_msg_pool_usage)
Registered MSG_REQ_POOL_USAGE
[2025/04/23 01:42:44.724032, 5, pid=649, effective(0, 0), real(0, 0),
class=passdb] ../../source3/passdb/pdb_interface.c:157(make_pdb_method_name)
Attempting to find a passdb backend to match tdbsam (tdbsam)
[2025/04/23 01:42:44.724040, 5, pid=649, effective(0, 0), real(0, 0),
class=passdb] ../../source3/passdb/pdb_interface.c:178(make_pdb_method_name)
Found pdb backend tdbsam
[2025/04/23 01:42:44.724054, 5, pid=649, effective(0, 0), real(0, 0),
class=passdb] ../../source3/passdb/pdb_interface.c:190(make_pdb_method_name)
pdb backend tdbsam has a valid init
[2025/04/23 01:42:44.726337, 1, pid=631, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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_hint : ID_TYPE_BOTH (3)
domain_index : 0x00000000 (0)
rid : 0x0000044f (1103)
xid: struct unixid
id :
0xffffffff (4294967295)
type :
ID_TYPE_NOT_SPECIFIED (0)
result : NT_STATUS_DOMAIN_CONTROLLER_NOT_FOUND
[2025/04/23 01:42:44.726399, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:616(wb_sids2xids_done)
Domain controller not found. Calling wb_dsgetdcname_send() to get it.
[2025/04/23 01:42:44.726407, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_dsgetdcname.c:50(wb_dsgetdcname_send)
WB command dsgetdcname start.
Search domain name domtest and site name (null).
[2025/04/23 01:42:44.726470, 1, pid=631, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_DsGetDcName: struct wbint_DsGetDcName
in: struct wbint_DsGetDcName
domain_name : *
domain_name : 'domtest'
domain_guid : NULL
site_name : NULL
flags : 0x40000000 (1073741824)
[2025/04/23 01:42:44.778765, 10, pid=631, effective(0, 0), real(0, 0)]
../../source4/lib/messaging/messaging.c:790(imessaging_dgm_recv)
imessaging_dgm_recv: dst 631 matches my id: 631, type=0x40b
[2025/04/23 01:42:44.778783, 10, pid=631, effective(0, 0), real(0, 0)]
../../source3/lib/messages.c:421(messaging_recv_cb)
messaging_recv_cb: Received message 0x40b len 8 (num_fds:0) from 634
[2025/04/23 01:42:44.778802, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_cm.c:147(winbind_msg_domain_online)
winbind_msg_domain_online: Domain DOMTEST was online, marking as online now!
[2025/04/23 01:42:44.840352, 10, pid=631, effective(0, 0), real(0, 0)]
../../source4/lib/messaging/messaging.c:790(imessaging_dgm_recv)
imessaging_dgm_recv: dst 631 matches my id: 631, type=0x40b
[2025/04/23 01:42:44.840370, 10, pid=631, effective(0, 0), real(0, 0)]
../../source3/lib/messages.c:421(messaging_recv_cb)
messaging_recv_cb: Received message 0x40b len 8 (num_fds:0) from 634
[2025/04/23 01:42:44.840389, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_cm.c:147(winbind_msg_domain_online)
winbind_msg_domain_online: Domain DOMTEST was online, marking as online now!
[2025/04/23 01:42:44.844145, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd_cache.c:4779(wcache_store_ndr)
could not fetch seqnum for domain DOMTEST
[2025/04/23 01:42:44.844167, 1, pid=631, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_DsGetDcName: struct wbint_DsGetDcName
out: struct wbint_DsGetDcName
dc_info : *
dc_info : NULL
result : NT_STATUS_NO_SUCH_DOMAIN
[2025/04/23 01:42:44.844187, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_dsgetdcname.c:126(wb_dsgetdcname_recv)
WB command dsgetdcname end.
[2025/04/23 01:42:44.844195, 1, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_dsgetdcname.c:128(wb_dsgetdcname_recv)
Failed with NT_STATUS_NO_SUCH_DOMAIN.
[2025/04/23 01:42:44.844201, 1, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:765(wb_sids2xids_recv)
Failed with NT_STATUS_NO_SUCH_DOMAIN.
[2025/04/23 01:42:44.844209, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:466(wb_queryuser_recv)
WB command queryuser end.
[2025/04/23 01:42:44.844214, 5, pid=631, effective(0, 0), real(0, 0),
class=rpc_parse]
../../source3/winbindd/wb_queryuser.c:467(wb_queryuser_recv)
state->info: struct wbint_userinfo
domain_name : NULL
acct_name : NULL
full_name : NULL
homedir : NULL
shell : NULL
uid : 0x0000000000000000 (0)
primary_gid : 0x00000000ffffffff (4294967295)
primary_group_name : NULL
user_sid :
S-1-5-21-2560703367-3512107002-2871390249-1103
group_sid : S-0-0
[2025/04/23 01:42:44.844248, 5, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_getpwsid.c:154(wb_getpwsid_recv)
WB command getpwsid end.
Return status NT_STATUS_NO_SUCH_DOMAIN.
[2025/04/23 01:42:44.844261, 1, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_getpwnam.c:142(winbindd_getpwnam_recv)
Could not convert sid
S-1-5-21-2560703367-3512107002-2871390249-1103:
NT_STATUS_NO_SUCH_DOMAIN
[2025/04/23 01:42:44.844267, 3, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:563(process_request_done)
process_request_done: [wbinfo(648):GETPWNAM]: NT_STATUS_NO_SUCH_DOMAIN
[2025/04/23 01:42:44.844290, 1, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:122(wb_queryuser_got_uid)
wb_sids2xids_recv() failed with NT_STATUS_NO_SUCH_DOMAIN.
[2025/04/23 01:42:44.844297, 1, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:715(wb_sids2xids_gotdc)
Failed with NT_STATUS_NO_SUCH_DOMAIN.
[2025/04/23 01:42:44.844304, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:608(process_request_written)
process_request_written: [wbinfo(648):GETPWNAM]: delivered response to client
[2025/04/23 01:42:44.845106, 6, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd.c:724(winbind_client_request_read)
closing socket 22, client exited
[2025/04/23 01:43:07.875857, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_util.c:715(winbindd_ping_offline_domains)
winbindd_ping_offline_domains: Domain BUILTIN is online
[2025/04/23 01:43:07.875959, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_cache.c:3521(get_global_winbindd_state_offline)
get_global_winbindd_state_offline: Offline state not set.
[2025/04/23 01:43:07.875967, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_util.c:715(winbindd_ping_offline_domains)
winbindd_ping_offline_domains: Domain DOM2MEM is online
[2025/04/23 01:43:07.875973, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_cache.c:3521(get_global_winbindd_state_offline)
get_global_winbindd_state_offline: Offline state not set.
[2025/04/23 01:43:07.875985, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_util.c:715(winbindd_ping_offline_domains)
winbindd_ping_offline_domains: Domain DOMTEST is online
[2025/04/23 01:43:07.875991, 10, pid=631, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_cache.c:3521(get_global_winbindd_state_offline)
get_global_winbindd_state_offline: Offline state not set.
--->8 failure log ends ---
---8< success log (server 2022, client 4.17) ---
[2025/04/23 01:46:10.530783, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:676(new_connection)
Accepted client socket 24
[2025/04/23 01:46:10.530870, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:524(process_request_send)
process_request_send: process_request: request fn INTERFACE_VERSION
[2025/04/23 01:46:10.530879, 3, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_misc.c:355(winbindd_interface_version)
winbindd_interface_version: [wbinfo (511)]: request interface
version (version = 32)
[2025/04/23 01:46:10.530905, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:608(process_request_written)
process_request_written: [wbinfo(511):INTERFACE_VERSION]: delivered
response to client
[2025/04/23 01:46:10.530922, 3, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:496(process_request_send)
process_request_send: [wbinfo (511)] Handling async request: GETPWNAM
[2025/04/23 01:46:10.530929, 3, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_getpwnam.c:59(winbindd_getpwnam_send)
[wbinfo (511)] Winbind external command GETPWNAM start.
Query username 'DOMTEST\dustin'.
[2025/04/23 01:46:10.530938, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_lookupname.c:52(wb_lookupname_send)
WB command lookupname start.
Search namespace 'DOMTEST' and domain 'DOMTEST' for name
'dustin'.
[2025/04/23 01:46:10.530955, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_LookupName: struct wbint_LookupName
in: struct wbint_LookupName
domain : *
domain : 'DOMTEST'
name : *
name : 'DUSTIN'
flags : 0x00000008 (8)
[2025/04/23 01:46:10.532225, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd_cache.c:4779(wcache_store_ndr)
could not fetch seqnum for domain DOMTEST
[2025/04/23 01:46:10.532238, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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-2560703367-3512107002-2871390249-1103
result : NT_STATUS_OK
[2025/04/23 01:46:10.532263, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_lookupname.c:118(wb_lookupname_recv)
WB command lookupname end.
Found SID S-1-5-21-2560703367-3512107002-2871390249-1103 with SID type 1.
[2025/04/23 01:46:10.532278, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_getpwsid.c:49(wb_getpwsid_send)
WB command getpwsid start.
Query user SID S-1-5-21-2560703367-3512107002-2871390249-1103.
[2025/04/23 01:46:10.532289, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:56(wb_queryuser_send)
WB command queryuser start.
Query user sid S-1-5-21-2560703367-3512107002-2871390249-1103
[2025/04/23 01:46:10.532299, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_queryuser.c:95(wb_queryuser_idmap_setup_done)
Convert the user SID S-1-5-21-2560703367-3512107002-2871390249-1103 to XID.
[2025/04/23 01:46:10.532306, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:84(wb_sids2xids_send)
WB command sids2xids start.
Resolving 1 SID(s).
[2025/04/23 01:46:10.532314, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:156(wb_sids2xids_send)
0: SID S-1-5-21-2560703367-3512107002-2871390249-1103
[2025/04/23 01:46:10.532322, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:175(wb_sids2xids_send)
Found 0 (out of 1) SID(s) in cache.
[2025/04/23 01:46:10.532329, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:206(wb_sids2xids_idmap_setup_done)
We will loop over 1 SID(s) (skipping those already resolved via
cache) and over 3 domain(s).
[2025/04/23 01:46:10.532335, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:223(wb_sids2xids_idmap_setup_done)
0: Processing SID S-1-5-21-2560703367-3512107002-2871390249-1103
[2025/04/23 01:46:10.532341, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:236(wb_sids2xids_idmap_setup_done)
0: Split SID S-1-5-21-2560703367-3512107002-2871390249-1103 into
domain SID S-1-5-21-2560703367-3512107002-2871390249 and RID 1103
[2025/04/23 01:46:10.532348, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:263(wb_sids2xids_idmap_setup_done)
Looping over 3 domain(s) to find domain SID
S-1-5-21-2560703367-3512107002-2871390249.
[2025/04/23 01:46:10.532353, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:277(wb_sids2xids_idmap_setup_done)
Found domain 'domtest'.
[2025/04/23 01:46:10.532359, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:308(wb_sids2xids_idmap_setup_done)
Setting type hint ID_TYPE_BOTH for domain 'domtest'.
[2025/04/23 01:46:10.532365, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:470(wb_sids2xids_next_sids2unix)
Processing next domain (dom_index=0, idmap_doms.count=1, lookup_count=0).
[2025/04/23 01:46:10.532372, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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 : 0x000e (14)
size : 0x0010 (16)
string : *
string :
'domtest'
sid : *
sid :
S-1-5-21-2560703367-3512107002-2871390249
max_size : 0x00000001 (1)
ids : *
ids: struct wbint_TransIDArray
num_ids : 0x00000001 (1)
ids: ARRAY(1)
ids: struct wbint_TransID
type_hint : ID_TYPE_BOTH (3)
domain_index : 0x00000000 (0)
rid : 0x0000044f (1103)
xid: struct unixid
id :
0xffffffff (4294967295)
type :
ID_TYPE_NOT_SPECIFIED (0)
[2025/04/23 01:46:10.532767, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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_hint : ID_TYPE_BOTH (3)
domain_index : 0x00000000 (0)
rid : 0x0000044f (1103)
xid: struct unixid
id :
0xffffffff (4294967295)
type :
ID_TYPE_NOT_SPECIFIED (0)
result : NT_STATUS_DOMAIN_CONTROLLER_NOT_FOUND
[2025/04/23 01:46:10.532815, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:616(wb_sids2xids_done)
Domain controller not found. Calling wb_dsgetdcname_send() to get it.
[2025/04/23 01:46:10.532821, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_dsgetdcname.c:50(wb_dsgetdcname_send)
WB command dsgetdcname start.
Search domain name domtest and site name (null).
[2025/04/23 01:46:10.532832, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_DsGetDcName: struct wbint_DsGetDcName
in: struct wbint_DsGetDcName
domain_name : *
domain_name : 'domtest'
domain_guid : NULL
site_name : NULL
flags : 0x40000000 (1073741824)
[2025/04/23 01:46:10.534537, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd_cache.c:4779(wcache_store_ndr)
could not fetch seqnum for domain DOMTEST
[2025/04/23 01:46:10.534568, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_DsGetDcName: struct wbint_DsGetDcName
out: struct wbint_DsGetDcName
dc_info : *
dc_info : *
dc_info: struct netr_DsRGetDCNameInfo
dc_unc : *
dc_unc :
'\\WIN-NAFS39H19IE.domtest.howett.net'
dc_address : *
dc_address : '\\192.168.1.2'
dc_address_type : DS_ADDRESS_TYPE_INET (1)
domain_guid :
ca8ac1ea-3bcd-4a7f-8675-31a30b64493f
domain_name : *
domain_name :
'domtest.howett.net'
forest_name : *
forest_name :
'domtest.howett.net'
dc_flags : 0xe003f3fd (3758355453)
1: DS_SERVER_PDC
1: DS_SERVER_GC
1: DS_SERVER_LDAP
1: DS_SERVER_DS
1: DS_SERVER_KDC
1: DS_SERVER_TIMESERV
1: DS_SERVER_CLOSEST
1: DS_SERVER_WRITABLE
1: DS_SERVER_GOOD_TIMESERV
0: DS_SERVER_NDNC
0: DS_SERVER_SELECT_SECRET_DOMAIN_6
1: DS_SERVER_FULL_SECRET_DOMAIN_6
1: DS_SERVER_WEBSERV
1: DS_SERVER_DS_8
1: DS_SERVER_DS_9
1: DS_SERVER_DS_10
1: DS_DNS_CONTROLLER
1: DS_DNS_DOMAIN
1: DS_DNS_FOREST_ROOT
dc_site_name : *
dc_site_name :
'Default-First-Site-Name'
client_site_name : *
client_site_name :
'Default-First-Site-Name'
result : NT_STATUS_OK
[2025/04/23 01:46:10.534789, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_dsgetdcname.c:126(wb_dsgetdcname_recv)
WB command dsgetdcname end.
[2025/04/23 01:46:10.534804, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse]
../../source3/winbindd/wb_dsgetdcname.c:149(wb_dsgetdcname_gencache_set)
dcinfo: struct netr_DsRGetDCNameInfo
dc_unc : *
dc_unc :
'\\WIN-NAFS39H19IE.domtest.howett.net'
dc_address : *
dc_address : '\\192.168.1.2'
dc_address_type : DS_ADDRESS_TYPE_INET (1)
domain_guid : ca8ac1ea-3bcd-4a7f-8675-31a30b64493f
domain_name : *
domain_name : 'domtest.howett.net'
forest_name : *
forest_name : 'domtest.howett.net'
dc_flags : 0xe003f3fd (3758355453)
1: DS_SERVER_PDC
1: DS_SERVER_GC
1: DS_SERVER_LDAP
1: DS_SERVER_DS
1: DS_SERVER_KDC
1: DS_SERVER_TIMESERV
1: DS_SERVER_CLOSEST
1: DS_SERVER_WRITABLE
1: DS_SERVER_GOOD_TIMESERV
0: DS_SERVER_NDNC
0: DS_SERVER_SELECT_SECRET_DOMAIN_6
1: DS_SERVER_FULL_SECRET_DOMAIN_6
1: DS_SERVER_WEBSERV
1: DS_SERVER_DS_8
1: DS_SERVER_DS_9
1: DS_SERVER_DS_10
1: DS_DNS_CONTROLLER
1: DS_DNS_DOMAIN
1: DS_DNS_FOREST_ROOT
dc_site_name : *
dc_site_name : 'Default-First-Site-Name'
client_site_name : *
client_site_name : 'Default-First-Site-Name'
[2025/04/23 01:46:10.534915, 10, pid=481, effective(0, 0), real(0, 0),
class=tdb] ../../source3/lib/gencache.c:279(gencache_set_data_blob)
gencache_set_data_blob: Adding cache entry with key=[DCINFO/DOMTEST]
and timeout=[Wed Apr 23 02:46:10 2025 UTC] (3600 seconds ahead)
[2025/04/23 01:46:10.534932, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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 : 0x000e (14)
size : 0x0010 (16)
string : *
string :
'domtest'
sid : *
sid :
S-1-5-21-2560703367-3512107002-2871390249
max_size : 0x00000001 (1)
ids : *
ids: struct wbint_TransIDArray
num_ids : 0x00000001 (1)
ids: ARRAY(1)
ids: struct wbint_TransID
type_hint : ID_TYPE_BOTH (3)
domain_index : 0x00000000 (0)
rid : 0x0000044f (1103)
xid: struct unixid
id :
0xffffffff (4294967295)
type :
ID_TYPE_NOT_SPECIFIED (0)
[2025/04/23 01:46:10.607623, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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_hint : ID_TYPE_BOTH (3)
domain_index : 0x00000000 (0)
rid : 0x0000044f (1103)
xid: struct unixid
id : 0x000001f5 (501)
type : ID_TYPE_UID (1)
result : NT_STATUS_OK
[2025/04/23 01:46:10.607675, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:678(wb_sids2xids_done)
0: Setting XID 501
[2025/04/23 01:46:10.607686, 10, pid=481, effective(0, 0), real(0, 0),
class=tdb] ../../source3/lib/gencache.c:279(gencache_set_data_blob)
gencache_set_data_blob: Adding cache entry with
key=[IDMAP/SID2XID/S-1-5-21-2560703367-3512107002-2871390249-1103] and
timeout=[Wed Apr 30 01:46:10 2025 UTC] (604800 seconds ahead)
[2025/04/23 01:46:10.607706, 10, pid=481, effective(0, 0), real(0, 0),
class=tdb] ../../source3/lib/gencache.c:279(gencache_set_data_blob)
gencache_set_data_blob: Adding cache entry with
key=[IDMAP/UID2SID/501] and timeout=[Wed Apr 30 01:46:10 2025 UTC]
(604800 seconds ahead)
[2025/04/23 01:46:10.607717, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:470(wb_sids2xids_next_sids2unix)
Processing next domain (dom_index=1, idmap_doms.count=1, lookup_count=0).
[2025/04/23 01:46:10.607723, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:499(wb_sids2xids_next_sids2unix)
Prepared 0 SID(s) for lookup wb_lookupsids_send().
[2025/04/23 01:46:10.607729, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:775(wb_sids2xids_recv)
WB command sids2xids end.
[2025/04/23 01:46:10.607734, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:779(wb_sids2xids_recv)
0: Found XID 501 for SID S-1-5-21-2560703367-3512107002-2871390249-1103
[2025/04/23 01:46:10.607742, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:134(wb_queryuser_got_uid)
Received XID 501 for SID S-1-5-21-2560703367-3512107002-2871390249-1103.
[2025/04/23 01:46:10.607749, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:148(wb_queryuser_got_uid)
Preconfigured 'Domain Users' RID 513 was used to create group SID
S-1-5-21-2560703367-3512107002-2871390249-513 from user SID
S-1-5-21-2560703367-3512107002-2871390249-1103.
[2025/04/23 01:46:10.607756, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:154(wb_queryuser_got_uid)
Setting 'homedir' to the template '/home/%D/%U'.
[2025/04/23 01:46:10.607761, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:160(wb_queryuser_got_uid)
Setting 'shell' to the template '/bin/false'.
[2025/04/23 01:46:10.607768, 10, pid=481, effective(0, 0), real(0, 0)]
../../source3/libsmb/samlogon_cache.c:252(netsamlogon_cache_get)
netsamlogon_cache_get: SID [S-1-5-21-2560703367-3512107002-2871390249-1103]
[2025/04/23 01:46:10.607776, 10, pid=481, effective(0, 0), real(0, 0)]
../../source3/libsmb/samlogon_cache.c:256(netsamlogon_cache_get)
tdb fetch for S-1-5-21-2560703367-3512107002-2871390249-1103 is empty
[2025/04/23 01:46:10.607781, 10, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse]
../../source3/winbindd/wb_queryuser.c:181(wb_queryuser_got_uid)
state->info: struct wbint_userinfo
domain_name : NULL
acct_name : NULL
full_name : NULL
homedir : *
homedir : '/home/%D/%U'
shell : *
shell : '/bin/false'
uid : 0x00000000000001f5 (501)
primary_gid : 0x00000000ffffffff (4294967295)
primary_group_name : NULL
user_sid :
S-1-5-21-2560703367-3512107002-2871390249-1103
group_sid :
S-1-5-21-2560703367-3512107002-2871390249-513
[2025/04/23 01:46:10.607822, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:183(wb_queryuser_got_uid)
Domain name is empty, calling wb_lookupsid_send() to get it.
[2025/04/23 01:46:10.607828, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_lookupsid.c:49(wb_lookupsid_send)
WB command lookupsid start.
[2025/04/23 01:46:10.607833, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_util.c:1432(find_lookup_domain_from_sid)
find_lookup_domain_from_sid: SID
[S-1-5-21-2560703367-3512107002-2871390249-1103]
[2025/04/23 01:46:10.607844, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_util.c:1475(find_lookup_domain_from_sid)
calling find_our_domain
[2025/04/23 01:46:10.607849, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_lookupsid.c:61(wb_lookupsid_send)
Looking up SID S-1-5-21-2560703367-3512107002-2871390249-1103 in
domain DOMTEST.
[2025/04/23 01:46:10.607857, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_LookupSid: struct wbint_LookupSid
in: struct wbint_LookupSid
sid : *
sid :
S-1-5-21-2560703367-3512107002-2871390249-1103
[2025/04/23 01:46:10.608049, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd_cache.c:4779(wcache_store_ndr)
could not fetch seqnum for domain DOMTEST
[2025/04/23 01:46:10.608060, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_LookupSid: struct wbint_LookupSid
out: struct wbint_LookupSid
type : *
type : SID_NAME_USER (1)
domain : *
domain : *
domain : 'DOMTEST'
name : *
name : *
name : 'dustin'
result : NT_STATUS_OK
[2025/04/23 01:46:10.608092, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_lookupsid.c:100(wb_lookupsid_recv)
WB command lookupsid end.
[2025/04/23 01:46:10.608098, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_lookupsid.c:108(wb_lookupsid_recv)
SID S-1-5-21-2560703367-3512107002-2871390249-1103 has name 'dustin'
with type '1' in domain 'DOMTEST'.
[2025/04/23 01:46:10.608104, 10, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse]
../../source3/winbindd/wb_queryuser.c:227(wb_queryuser_got_domain)
state->info: struct wbint_userinfo
domain_name : *
domain_name : 'DOMTEST'
acct_name : *
acct_name : 'dustin'
full_name : NULL
homedir : *
homedir : '/home/%D/%U'
shell : *
shell : '/bin/false'
uid : 0x00000000000001f5 (501)
primary_gid : 0x00000000ffffffff (4294967295)
primary_group_name : NULL
user_sid :
S-1-5-21-2560703367-3512107002-2871390249-1103
group_sid :
S-1-5-21-2560703367-3512107002-2871390249-513
[2025/04/23 01:46:10.608146, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_queryuser.c:256(wb_queryuser_got_domain)
About to call dcerpc_wbint_GetNssInfo_send()
[2025/04/23 01:46:10.608154, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_GetNssInfo: struct wbint_GetNssInfo
in: struct wbint_GetNssInfo
info : *
info: struct wbint_userinfo
domain_name : *
domain_name : 'DOMTEST'
acct_name : *
acct_name : 'dustin'
full_name : NULL
homedir : *
homedir : '/home/%D/%U'
shell : *
shell : '/bin/false'
uid : 0x00000000000001f5 (501)
primary_gid : 0x00000000ffffffff (4294967295)
primary_group_name : NULL
user_sid :
S-1-5-21-2560703367-3512107002-2871390249-1103
group_sid :
S-1-5-21-2560703367-3512107002-2871390249-513
[2025/04/23 01:46:10.608653, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(ndr_print_function_debug)
wbint_GetNssInfo: struct wbint_GetNssInfo
out: struct wbint_GetNssInfo
info : *
info: struct wbint_userinfo
domain_name : *
domain_name : 'DOMTEST'
acct_name : *
acct_name : 'dustin'
full_name : NULL
homedir : *
homedir : '/home/dustin'
shell : *
shell : '/bin/bash'
uid : 0x00000000000001f5 (501)
primary_gid : 0x00000000ffffffff (4294967295)
primary_group_name : NULL
user_sid :
S-1-5-21-2560703367-3512107002-2871390249-1103
group_sid :
S-1-5-21-2560703367-3512107002-2871390249-513
result : NT_STATUS_OK
[2025/04/23 01:46:10.608712, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:302(wb_queryuser_done)
Calling wb_sids2xids_send() to resolve primary gid.
[2025/04/23 01:46:10.608717, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:84(wb_sids2xids_send)
WB command sids2xids start.
Resolving 1 SID(s).
[2025/04/23 01:46:10.608726, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:156(wb_sids2xids_send)
0: SID S-1-5-21-2560703367-3512107002-2871390249-513
[2025/04/23 01:46:10.608735, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:175(wb_sids2xids_send)
Found 0 (out of 1) SID(s) in cache.
[2025/04/23 01:46:10.608742, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:206(wb_sids2xids_idmap_setup_done)
We will loop over 1 SID(s) (skipping those already resolved via
cache) and over 3 domain(s).
[2025/04/23 01:46:10.608748, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:223(wb_sids2xids_idmap_setup_done)
0: Processing SID S-1-5-21-2560703367-3512107002-2871390249-513
[2025/04/23 01:46:10.608754, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:236(wb_sids2xids_idmap_setup_done)
0: Split SID S-1-5-21-2560703367-3512107002-2871390249-513 into
domain SID S-1-5-21-2560703367-3512107002-2871390249 and RID 513
[2025/04/23 01:46:10.608761, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:263(wb_sids2xids_idmap_setup_done)
Looping over 3 domain(s) to find domain SID
S-1-5-21-2560703367-3512107002-2871390249.
[2025/04/23 01:46:10.608767, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:277(wb_sids2xids_idmap_setup_done)
Found domain 'domtest'.
[2025/04/23 01:46:10.608772, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:308(wb_sids2xids_idmap_setup_done)
Setting type hint ID_TYPE_BOTH for domain 'domtest'.
[2025/04/23 01:46:10.608778, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:470(wb_sids2xids_next_sids2unix)
Processing next domain (dom_index=0, idmap_doms.count=1, lookup_count=0).
[2025/04/23 01:46:10.608786, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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 : 0x000e (14)
size : 0x0010 (16)
string : *
string :
'domtest'
sid : *
sid :
S-1-5-21-2560703367-3512107002-2871390249
max_size : 0x00000001 (1)
ids : *
ids: struct wbint_TransIDArray
num_ids : 0x00000001 (1)
ids: ARRAY(1)
ids: struct wbint_TransID
type_hint : ID_TYPE_BOTH (3)
domain_index : 0x00000000 (0)
rid : 0x00000201 (513)
xid: struct unixid
id :
0xffffffff (4294967295)
type :
ID_TYPE_NOT_SPECIFIED (0)
[2025/04/23 01:46:10.609433, 1, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse] ../../librpc/ndr/ndr.c:490(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_hint : ID_TYPE_BOTH (3)
domain_index : 0x00000000 (0)
rid : 0x00000201 (513)
xid: struct unixid
id : 0x000001f5 (501)
type : ID_TYPE_GID (2)
result : NT_STATUS_OK
[2025/04/23 01:46:10.609477, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:678(wb_sids2xids_done)
0: Setting XID 501
[2025/04/23 01:46:10.609485, 10, pid=481, effective(0, 0), real(0, 0),
class=tdb] ../../source3/lib/gencache.c:279(gencache_set_data_blob)
gencache_set_data_blob: Adding cache entry with
key=[IDMAP/SID2XID/S-1-5-21-2560703367-3512107002-2871390249-513] and
timeout=[Wed Apr 30 01:46:10 2025 UTC] (604800 seconds ahead)
[2025/04/23 01:46:10.609499, 10, pid=481, effective(0, 0), real(0, 0),
class=tdb] ../../source3/lib/gencache.c:279(gencache_set_data_blob)
gencache_set_data_blob: Adding cache entry with
key=[IDMAP/GID2SID/501] and timeout=[Wed Apr 30 01:46:10 2025 UTC]
(604800 seconds ahead)
[2025/04/23 01:46:10.609509, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:470(wb_sids2xids_next_sids2unix)
Processing next domain (dom_index=1, idmap_doms.count=1, lookup_count=0).
[2025/04/23 01:46:10.609514, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/wb_sids2xids.c:499(wb_sids2xids_next_sids2unix)
Prepared 0 SID(s) for lookup wb_lookupsids_send().
[2025/04/23 01:46:10.609520, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:775(wb_sids2xids_recv)
WB command sids2xids end.
[2025/04/23 01:46:10.609525, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_sids2xids.c:779(wb_sids2xids_recv)
0: Found XID 501 for SID S-1-5-21-2560703367-3512107002-2871390249-513
[2025/04/23 01:46:10.609532, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:400(wb_queryuser_got_gid)
Got XID 501 with type 2.
[2025/04/23 01:46:10.609538, 10, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse]
../../source3/winbindd/wb_queryuser.c:419(wb_queryuser_got_gid)
state->info: struct wbint_userinfo
domain_name : *
domain_name : 'DOMTEST'
acct_name : *
acct_name : 'dustin'
full_name : NULL
homedir : *
homedir : '/home/dustin'
shell : *
shell : '/bin/bash'
uid : 0x00000000000001f5 (501)
primary_gid : 0x00000000000001f5 (501)
primary_group_name : NULL
user_sid :
S-1-5-21-2560703367-3512107002-2871390249-1103
group_sid :
S-1-5-21-2560703367-3512107002-2871390249-513
[2025/04/23 01:46:10.609579, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:434(wb_queryuser_got_gid)
No need to lookup primary group name. Request is done!
[2025/04/23 01:46:10.609585, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_queryuser.c:466(wb_queryuser_recv)
WB command queryuser end.
[2025/04/23 01:46:10.609591, 5, pid=481, effective(0, 0), real(0, 0),
class=rpc_parse]
../../source3/winbindd/wb_queryuser.c:467(wb_queryuser_recv)
state->info: struct wbint_userinfo
domain_name : *
domain_name : 'DOMTEST'
acct_name : *
acct_name : 'dustin'
full_name : NULL
homedir : *
homedir : '/home/dustin'
shell : *
shell : '/bin/bash'
uid : 0x00000000000001f5 (501)
primary_gid : 0x00000000000001f5 (501)
primary_group_name : NULL
user_sid :
S-1-5-21-2560703367-3512107002-2871390249-1103
group_sid :
S-1-5-21-2560703367-3512107002-2871390249-513
[2025/04/23 01:46:10.609637, 5, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/wb_getpwsid.c:154(wb_getpwsid_recv)
WB command getpwsid end.
Return status NT_STATUS_OK.
[2025/04/23 01:46:10.609645, 3, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_getpwnam.c:149(winbindd_getpwnam_recv)
Winbind external command GETPWNAM end.
(name:passwd:uid:gid:gecos:dir:shell)
DOMTEST\dustin:*:501:501::/home/dustin:/bin/bash
[2025/04/23 01:46:10.609655, 3, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:563(process_request_done)
process_request_done: [wbinfo(511):GETPWNAM]: NT_STATUS_OK
[2025/04/23 01:46:10.609670, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind] ../../source3/winbindd/winbindd.c:608(process_request_written)
process_request_written: [wbinfo(511):GETPWNAM]: delivered response to client
[2025/04/23 01:46:10.610466, 6, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd.c:724(winbind_client_request_read)
closing socket 24, client exited
[2025/04/23 01:46:26.341331, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_util.c:715(winbindd_ping_offline_domains)
winbindd_ping_offline_domains: Domain BUILTIN is online
[2025/04/23 01:46:26.341418, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_cache.c:3521(get_global_winbindd_state_offline)
get_global_winbindd_state_offline: Offline state not set.
[2025/04/23 01:46:26.341425, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_util.c:715(winbindd_ping_offline_domains)
winbindd_ping_offline_domains: Domain DOM-TEST-MEMBER is online
[2025/04/23 01:46:26.341431, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_cache.c:3521(get_global_winbindd_state_offline)
get_global_winbindd_state_offline: Offline state not set.
[2025/04/23 01:46:26.341436, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_util.c:715(winbindd_ping_offline_domains)
winbindd_ping_offline_domains: Domain DOMTEST is online
[2025/04/23 01:46:26.341442, 10, pid=481, effective(0, 0), real(0, 0),
class=winbind]
../../source3/winbindd/winbindd_cache.c:3521(get_global_winbindd_state_offline)
get_global_winbindd_state_offline: Offline state not set.
---8< success log ends ---
Rowland Penny
2025-Apr-23 07:49 UTC
[Samba] Fwd: Domain member fails to map SID>*ID after DC migrated from Server 2022 to 2025
On Tue, 22 Apr 2025 21:09:26 -0500 Dustin Howett via samba <samba at lists.samba.org> wrote:> Hey all, > I have a samba (tested 4.17+debian, 4.22.1+debian) domain member of a > very small domain. > I recently upgraded the PDC from Windows Server 2022 to 2025, and > began to observe widespread user mapping failures on the samba domain > member. > Given that my production environment ranges from "annoying" to "hard > to turn into a lab," I reproduced the problem from first principles in > an isolated lab environment. > > For this lab, I built a single DC on Server 2022 and a single member > server running Debian 12. > After verifying it worked, I cloned both of the nodes to a new > isolated network and upgraded the DC to Server 2025. Hopefully this > will clarify why the log snippets below contain the same machine names > but interleaved/inconsistent timestamps (considering that the 2022 > snippet was taken after the 2025 one...) > > I'm not sure what I am looking at, or looking *for*, but I've made a > few observations: > > - The proximal failing call seems to be sids2xids. > - It does not have a cached domain controller, so it attempts to find > one > - It attempts to find one using DsGetDcName > - On Server 2022, DsGetDcName returns a netr_DsRGetDCNameInfo > - On Server 2025, it returns a failure instead: > NT_STATUS_NO_SUCH_DOMAIN >It seems that your DC cannot be found, so for a start, can you post the /etc/resolv.conf, /etc/krb5.conf and smb.conf from the client. Rowland