SemiArticulate

Random Musings
January 12th, 2013 by Lucas

Samba4 replication problems

I’ve been trying to get my two Samba4 DCs to replicate between each other.

The output of the drs showrepl command:

root@ns0:/usr/local/samba # bin/samba-tool drs showrepl ns0
Default-First-Site-Name\NS0
DSA Options: 0x00000001
DSA object GUID: 3b0c70a3-2ecf-4fd9-b87d-7fd2fc063d1f
DSA invocationId: cd9f36c5-30ad-4b1c-a35a-ba807406b34c
==== INBOUND NEIGHBORS ====
ERROR(runtime): DsReplicaGetInfo of type 0 failed - (-1073610723, 'NT_STATUS_RPC_PROTOCOL_ERROR')

and in the -D7 logs we get:

../librpc/rpc/dcerpc_util.c:140: auth_pad_length 0
ldb: Added timed event "ltdb_callback": 0x81d68fde0
ldb: Added timed event "ltdb_timeout": 0x81d68ff60
ldb: Destroying timer event 0x81d68ff60 "ltdb_timeout"
ldb: Ending timer event 0x81d68fde0 "ltdb_callback"
Starting GENSEC mechanism spnego
Starting GENSEC submechanism ntlmssp
Got NTLMSSP neg_flags=0x60088235
 NTLMSSP_NEGOTIATE_UNICODE
 NTLMSSP_REQUEST_TARGET
 NTLMSSP_NEGOTIATE_SIGN
 NTLMSSP_NEGOTIATE_SEAL
 NTLMSSP_NEGOTIATE_NTLM
 NTLMSSP_NEGOTIATE_ALWAYS_SIGN
 NTLMSSP_NEGOTIATE_NTLM2
 NTLMSSP_NEGOTIATE_128
 NTLMSSP_NEGOTIATE_KEY_EXCH
../librpc/rpc/dcerpc_util.c:140: auth_pad_length 0
Got user=[NS0$] domain=[LDJCS] workstation=[NS0] len1=24 len2=136
auth_check_password_send: Checking password for unmapped user [LDJCS]\[NS0$]@[NS0]
map_user_info_cracknames: Mapping user [LDJCS]\[NS0$] from workstation [NS0]
gendb_search_v: DC=ldjcs,DC=com,DC=au NULL -> 1
auth_check_password_send: mapped user is: [LDJCS]\[NS0$]@[NS0]
auth_get_challenge: returning previous challenge by module random (normal)
[0000] 3B 1B 24 E8 0F E6 EA DB ;.$..... 
ntlm_password_check: Checking NTLMv2 password with domain [LDJCS]
authsam_account_ok: Checking SMB password for user NS0$
logon_hours_ok: No hours restrictions for user NS0$
gendb_search_v: DC=ldjcs,DC=com,DC=au NULL -> 1
auth_check_password_recv: sam_ignoredomain authentication for user [LDJCS\NS0$] succeeded
NTLMSSP Sign/Seal - Initialising with flags:
Got NTLMSSP neg_flags=0x60088235
 NTLMSSP_NEGOTIATE_UNICODE
 NTLMSSP_REQUEST_TARGET
 NTLMSSP_NEGOTIATE_SIGN
 NTLMSSP_NEGOTIATE_SEAL
 NTLMSSP_NEGOTIATE_NTLM
 NTLMSSP_NEGOTIATE_ALWAYS_SIGN
 NTLMSSP_NEGOTIATE_NTLM2
 NTLMSSP_NEGOTIATE_128
 NTLMSSP_NEGOTIATE_KEY_EXCH
ldb: Added timed event "ltdb_callback": 0x81d6907a0
ldb: Added timed event "ltdb_timeout": 0x81d690c20
ldb: Destroying timer event 0x81d690c20 "ltdb_timeout"
ldb: Ending timer event 0x81d6907a0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\05\00\00\00\00\00\05\15\00\00\00j\C6\EE3gB\B5\E8\CFT\2A\E4\E8\03\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81d6907a0
ldb: Added timed event "ltdb_timeout": 0x81d690c20
ldb: Destroying timer event 0x81d690c20 "ltdb_timeout"
ldb: Ending timer event 0x81d6907a0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\05\00\00\00\00\00\05\15\00\00\00j\C6\EE3gB\B5\E8\CFT\2A\E4\04\02\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81d6907a0
ldb: Added timed event "ltdb_timeout": 0x81d690c20
ldb: Destroying timer event 0x81d690c20 "ltdb_timeout"
ldb: Ending timer event 0x81d6907a0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\05\00\00\00\00\00\05\15\00\00\00j\C6\EE3gB\B5\E8\CFT\2A\E4<\02\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81d6907a0
ldb: Added timed event "ltdb_timeout": 0x81d690c20
ldb: Destroying timer event 0x81d690c20 "ltdb_timeout"
ldb: Ending timer event 0x81d6907a0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\09\00\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81d6907a0
ldb: Added timed event "ltdb_timeout": 0x81d690c20
ldb: Destroying timer event 0x81d690c20 "ltdb_timeout"
ldb: Ending timer event 0x81d6907a0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\01\00\00\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81d6907a0
ldb: Added timed event "ltdb_timeout": 0x81d690c20
ldb: Destroying timer event 0x81d690c20 "ltdb_timeout"
ldb: Ending timer event 0x81d6907a0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\02\00\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81d6907a0
ldb: Added timed event "ltdb_timeout": 0x81d690c20
ldb: Destroying timer event 0x81d690c20 "ltdb_timeout"
ldb: Ending timer event 0x81d6907a0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\0B\00\00\00 -> 0
../librpc/rpc/dcerpc_util.c:140: auth_pad_length 4
../source4/rpc_server/drsuapi/dcesrv_drsuapi.c:74: doing DsBind with system_session
ldb: Added timed event "ltdb_callback": 0x81d6ab4a0
ldb: Added timed event "ltdb_timeout": 0x81d6ab560
ldb: Destroying timer event 0x81d6ab560 "ltdb_timeout"
ldb: Ending timer event 0x81d6ab4a0 "ltdb_callback"
ldb_request BASE dn= filter=(|(objectClass=*)(distinguishedName=*))
Starting GENSEC mechanism spnego
Starting GENSEC submechanism ntlmssp
Got NTLMSSP neg_flags=0x60088205
 NTLMSSP_NEGOTIATE_UNICODE
 NTLMSSP_REQUEST_TARGET
 NTLMSSP_NEGOTIATE_NTLM
 NTLMSSP_NEGOTIATE_ALWAYS_SIGN
 NTLMSSP_NEGOTIATE_NTLM2
 NTLMSSP_NEGOTIATE_128
 NTLMSSP_NEGOTIATE_KEY_EXCH
Got user=[NS0$] domain=[LDJCS] workstation=[NS0] len1=24 len2=136
auth_check_password_send: Checking password for unmapped user [LDJCS]\[NS0$]@[NS0]
map_user_info_cracknames: Mapping user [LDJCS]\[NS0$] from workstation [NS0]
gendb_search_v: DC=ldjcs,DC=com,DC=au NULL -> 1
auth_check_password_send: mapped user is: [LDJCS]\[NS0$]@[NS0]
auth_get_challenge: returning previous challenge by module random (normal)
[0000] D3 0A 74 06 BC 3E 3F DD ..t..>?. 
ntlm_password_check: Checking NTLMv2 password with domain [LDJCS]
authsam_account_ok: Checking SMB password for user NS0$
logon_hours_ok: No hours restrictions for user NS0$
gendb_search_v: DC=ldjcs,DC=com,DC=au NULL -> 1
auth_check_password_recv: sam_ignoredomain authentication for user [LDJCS\NS0$] succeeded
NTLMSSP Sign/Seal - Initialising with flags:
Got NTLMSSP neg_flags=0x60088205
 NTLMSSP_NEGOTIATE_UNICODE
 NTLMSSP_REQUEST_TARGET
 NTLMSSP_NEGOTIATE_NTLM
 NTLMSSP_NEGOTIATE_ALWAYS_SIGN
 NTLMSSP_NEGOTIATE_NTLM2
 NTLMSSP_NEGOTIATE_128
 NTLMSSP_NEGOTIATE_KEY_EXCH
ldb: Added timed event "ltdb_callback": 0x81dc85be0
ldb: Added timed event "ltdb_timeout": 0x81dc85d60
ldb: Destroying timer event 0x81dc85d60 "ltdb_timeout"
ldb: Ending timer event 0x81dc85be0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\05\00\00\00\00\00\05\15\00\00\00j\C6\EE3gB\B5\E8\CFT\2A\E4\E8\03\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81dc85be0
ldb: Added timed event "ltdb_timeout": 0x81dc85d60
ldb: Destroying timer event 0x81dc85d60 "ltdb_timeout"
ldb: Ending timer event 0x81dc85be0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\05\00\00\00\00\00\05\15\00\00\00j\C6\EE3gB\B5\E8\CFT\2A\E4\04\02\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81dc85be0
ldb: Added timed event "ltdb_timeout": 0x81dc85d60
ldb: Destroying timer event 0x81dc85d60 "ltdb_timeout"
ldb: Ending timer event 0x81dc85be0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\05\00\00\00\00\00\05\15\00\00\00j\C6\EE3gB\B5\E8\CFT\2A\E4<\02\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81dc85be0
ldb: Added timed event "ltdb_timeout": 0x81dc85d60
ldb: Destroying timer event 0x81dc85d60 "ltdb_timeout"
ldb: Ending timer event 0x81dc85be0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\09\00\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81dc85be0
ldb: Added timed event "ltdb_timeout": 0x81dc85d60
ldb: Destroying timer event 0x81dc85d60 "ltdb_timeout"
ldb: Ending timer event 0x81dc85be0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\01\00\00\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81dc85be0
ldb: Added timed event "ltdb_timeout": 0x81dc85d60
ldb: Destroying timer event 0x81dc85d60 "ltdb_timeout"
ldb: Ending timer event 0x81dc85be0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\02\00\00\00 -> 0
ldb: Added timed event "ltdb_callback": 0x81dc85be0
ldb: Added timed event "ltdb_timeout": 0x81dc85d60
ldb: Destroying timer event 0x81dc85d60 "ltdb_timeout"
ldb: Ending timer event 0x81dc85be0 "ltdb_callback"
gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\0B\00\00\00 -> 0
ldb_request BASE dn= filter=(objectClass=*)
ldb_request BASE dn= filter=(|(objectClass=*)(distinguishedName=*))
ldb_request BASE dn= filter=(|(objectClass=*)(distinguishedName=*))
ldb_request BASE dn=CN=NTDS Settings,CN=NS1,CN=Servers,CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=ldjcs,DC=com,DC=au filter=(|(objectClass=*)(distinguishedName=*))
ldb_request SUB dn=CN=NTDS Settings,CN=NS1,CN=Servers,CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=ldjcs,DC=com,DC=au filter=(objectClass=nTDSConnection)
../librpc/rpc/dcerpc_util.c:140: auth_pad_length 12
function drsuapi_DsReplicaGetInfo will reply async
dreplsrv_notify_schedule(5) scheduled for: Sat Jan 12 12:46:36 2013 EST
dreplsrv_notify_schedule(5) scheduled for: Sat Jan 12 12:46:41 2013 EST
IRPC callback failed for DsReplicaGetInfo - NT_STATUS_IO_TIMEOUT
function drsuapi_DsReplicaGetInfo replied async
dcerpc_fault WERR_EPT_S_CANT_PERFORM_OP in drsuapi_DsReplicaGetInfo
Terminating connection - 'ldapsrv_call_loop: tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
imessaging: cleaning up /usr/local/samba/private/smbd.tmp/msg/msg.0.77
single_terminate: reason[ldapsrv_call_loop: tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
Terminating connection - 'NT_STATUS_CONNECTION_DISCONNECTED'
imessaging: cleaning up /usr/local/samba/private/smbd.tmp/msg/msg.0.75
single_terminate: reason[NT_STATUS_CONNECTION_DISCONNECTED]

 

We all so get a RID allocation failure:

Mapped to DCERPC endpoint 135
added interface em0 ip=203.17.30.18 bcast=203.17.30.255 netmask=255.255.255.0
added interface em0 ip=203.17.30.18 bcast=203.17.30.255 netmask=255.255.255.0
dns child failed to find name '3b0c70a3-2ecf-4fd9-b87d-7fd2fc063d1f._msdcs.ldjcs.com.au' of type A
dreplsrv_op_pull_source(WERR_BADFILE) for CN=RID Manager$,CN=System,DC=ldjcs,DC=com,DC=au
../source4/dsdb/repl/drepl_ridalloc.c:43: RID Manager failed RID allocation - WERR_BADFILE - extended_ret[0x0]

Which is a bit strange as that host does exist. Sort of:

root@ns1:/usr/local/samba # nslookup 3b0c70a3-2ecf-4fd9-b87d-7fd2fc063d1f._msdcs.ldjcs.com.au
Server: 203.17.30.32
Address: 203.17.30.32#53
3b0c70a3-2ecf-4fd9-b87d-7fd2fc063d1f._msdcs.ldjcs.com.au canonical name = ns0.ldjcs.com.au.
Name: ns0.ldjcs.com.au
Address: 203.17.30.32
root@ns1:/usr/local/samba # bin/samba-tool dns query ns1 ldjcs.com.au 3b0c70a3-2ecf-4fd9-b87d-7fd2fc063d1f._msdcs.ldjcs.com.au A
ERROR(runtime): uncaught exception - (9714, 'WERR_DNS_ERROR_NAME_DOES_NOT_EXIST')
 File "/usr/local/samba/lib/python2.7/site-packages/samba/netcmd/__init__.py", line 175, in _run
 return self.run(*args, **kwargs)
 File "/usr/local/samba/lib/python2.7/site-packages/samba/netcmd/dns.py", line 974, in run
 None, record_type, select_flags, None, None)

This is with the internal DNS server, so there shouldn’t be any differences between nslookup and the samba-tool dns query.

 

I don’t know where to go to from here.  I get similar results on ns0 (the primary DC).


The full log is available here: samba.d7

 

UPDATE 03Feb13: I pulled down a fresh copy of ubuntu and samba-git, and it seem to work correctly.  This seems like an issue when building on FreeBSD. 🙁