thr3ads.net - samba - [Samba] AD replication problem "WERR_DS_DRA_ACCESS_DENIED"

If this information is useful, please help other people find it:
Share via:

Dr. Johannes-Ulrich Menzebach

2017-Dec-27 08:59 UTC

[Samba] AD replication problem "WERR_DS_DRA_ACCESS_DENIED" - need help debugging

We have 3 ADCs based on Samba-4.7.4 (compiled from source,internal DNS)/ 
CentOS7: dcdo1,dcnh1 and dcge1. dcge1 holds all FSMO roles. The 3 ADCs 
are on different locations connected via IPSec based VPN. No traffic is 
filtered out.

All 3 ADCs replicate fine except dcdo1 -->dcnh1. Symptom:

[root at dcdo1 ~]# samba-tool drs replicate dcnh1.ad.kdu.com 
dcdo1.ad.kdu.com dc=ad,dc=kdu,dc=com
ERROR(<class 'samba.drs_utils.drsException'>): DsReplicaSync
failed -
drsException: DsReplicaSync failed (8453, 'WERR_DS_DRA_ACCESS_DENIED')
   File "/usr/lib64/python2.7/site-packages/samba/netcmd/drs.py", line
386, in run
     drs_utils.sendDsReplicaSync(server_bind, server_bind_handle, 
source_dsa_guid, NC, req_options)
   File "/usr/lib64/python2.7/site-packages/samba/drs_utils.py", line 
85, in sendDsReplicaSync
     raise drsException("DsReplicaSync failed %s" % estr)

Log on dcdo1:
=============[2017/12/27 08:20:56.335895,  0] 
../source4/rpc_server/drsuapi/updaterefs.c:374(dcesrv_drsuapi_DsReplicaUpdateRefs)
   ../source4/rpc_server/drsuapi/updaterefs.c:374: Refusing 
DsReplicaUpdateRefs for sid S-1-5-21-454945863-777199239-1595221609-1112 
with GUID 0acce4bc-1193-4609-8e4d-a0771bb6fb76

Log on target DC dcnh1:
=============[2017/12/27 08:20:55.278559,  5] 
../auth/auth_log.c:860(log_successful_authz_event_human_readable)
   Successful AuthZ: [DCE/RPC,ncacn_ip_tcp] user [NT 
AUTHORITY]\[ANONYMOUS LOGON] [S-1-5-7] at [Wed, 27 Dec 2017 
08:20:55.278538 CET] Remote host [ipv4:192.168.172.14:36196] local host 
[ipv4:192.168.152.15:135]
[2017/12/27 08:20:55.278641,  5] ../auth/auth_log.c:220(log_json)
   JSON Authorization: {"timestamp":
"2017-12-27T08:20:55.278587+0100",
"type": "Authorization", "Authorization":
{"version": {"major": 1,
"minor": 0}, "localAddress":
"ipv4:192.168.152.15:135", "remoteAddress":
"ipv4:192.168.172.14:36196", "serviceDescription":
"DCE/RPC",
"authType": "ncacn_ip_tcp", "domain": "NT
AUTHORITY", "account":
"ANONYMOUS LOGON", "sid": "S-1-5-7",
"logonServer": "DCNH1",
"transportProtection": "NONE", "accountFlags":
"0x00000010"}}
[2017/12/27 08:20:55.278660,  3] 
../auth/auth_log.c:139(get_auth_event_server)
   get_auth_event_server: Failed to find 'auth_event' registered on the 
message bus to send JSON authentication events to: 
NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/12/27 08:20:55.337740,  3] 
../source4/smbd/service_stream.c:65(stream_terminate_connection)
   Terminating connection - 'dcesrv: NT_STATUS_CONNECTION_DISCONNECTED'
[2017/12/27 08:20:55.337873,  3] 
../source4/smbd/process_single.c:114(single_terminate)
   single_terminate: reason[dcesrv: NT_STATUS_CONNECTION_DISCONNECTED]
[2017/12/27 08:20:55.506117,  3] 
../lib/ldb-samba/ldb_wrap.c:326(ldb_wrap_connect)
   ldb_wrap open of secrets.ldb
[2017/12/27 08:20:55.506420,  5] 
../auth/gensec/gensec_start.c:739(gensec_start_mech)
   Starting GENSEC mechanism spnego
[2017/12/27 08:20:55.506501,  5] 
../auth/gensec/gensec_start.c:739(gensec_start_mech)
   Starting GENSEC submechanism gssapi_krb5
[2017/12/27 08:20:55.536259,  5] 
../source4/auth/gensec/gensec_gssapi.c:668(gensec_gssapi_update_internal)
   gensec_gssapi: credentials were delegated
[2017/12/27 08:20:55.536320,  5] 
../source4/auth/gensec/gensec_gssapi.c:685(gensec_gssapi_update_internal)
   GSSAPI Connection will be cryptographically sealed
[2017/12/27 08:20:55.538591,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_T\04\00\00
-> 0
[2017/12/27 08:20:55.538644,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_\04\02\00\00
-> 0
[2017/12/27 08:20:55.538712,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_<\02\00\00
-> 0
[2017/12/27 08:20:55.538762,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\09\00\00\00 -> 0
[2017/12/27 08:20:55.538819,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\01\00\00\00\00 -> 0
[2017/12/27 08:20:55.538864,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\02\00\00\00 -> 0
[2017/12/27 08:20:55.538909,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\0B\00\00\00 -> 0
[2017/12/27 08:20:55.538967,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\02\00\00\00\00\00\05\20\00\00\000\02\00\00 -> 0
[2017/12/27 08:20:55.539029,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\2A\02\00\00 -> 1
[2017/12/27 08:20:55.539087,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\21\02\00\00 -> 0
[2017/12/27 08:20:55.539289,  4] 
../auth/auth_log.c:860(log_successful_authz_event_human_readable)
   Successful AuthZ: [DCE/RPC,krb5] user [AD]\[DCDO1$] 
[S-1-5-21-454945863-777199239-1595221609-1108] at [Wed, 27 Dec 2017 
08:20:55.539277 CET] Remote host [ipv4:192.168.172.14:57364] local host 
[ipv4:192.168.152.15:49152]
[2017/12/27 08:20:55.539359,  4] ../auth/auth_log.c:220(log_json)
   JSON Authorization: {"timestamp":
"2017-12-27T08:20:55.539334+0100",
"type": "Authorization", "Authorization":
{"version": {"major": 1,
"minor": 0}, "localAddress":
"ipv4:192.168.152.15:49152",
"remoteAddress": "ipv4:192.168.172.14:57364",
"serviceDescription":
"DCE/RPC", "authType": "krb5", "domain":
"AD", "account": "DCDO1$",
"sid": "S-1-5-21-454945863-777199239-1595221609-1108",
"logonServer":
"DCDO1", "transportProtection": "SEAL",
"accountFlags": "0x00002100"}}
[2017/12/27 08:20:55.539398,  3] 
../auth/auth_log.c:139(get_auth_event_server)
   get_auth_event_server: Failed to find 'auth_event' registered on the 
message bus to send JSON authentication events to: 
NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/12/27 08:20:55.568937,  3] 
../source4/rpc_server/drsuapi/dcesrv_drsuapi.c:89(dcesrv_drsuapi_DsBind)
   ../source4/rpc_server/drsuapi/dcesrv_drsuapi.c:89: doing DsBind with 
system_session
[2017/12/27 08:20:55.641297,  3] 
../lib/ldb-samba/ldb_wrap.c:326(ldb_wrap_connect)
   ldb_wrap open of secrets.ldb
[2017/12/27 08:20:55.644257,  5] 
../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
   ldb_request BASE dn= filter=(|(objectClass=*)(distinguishedName=*))
[2017/12/27 08:20:55.706421,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.706573,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.706777,  3] 
../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
   Kerberos: TGS-REQ DCDO1$@AD.kdu.COM from ipv4:192.168.172.14:48486 
for ldap/dcnh1.ad.kdu.com at AD.kdu.COM [canonicalize]
[2017/12/27 08:20:55.708186,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.708670,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.708795,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.709594,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.710027,  3] 
../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
   Kerberos: TGS-REQ authtime: 2017-12-27T08:20:54 starttime: 
2017-12-27T08:20:55 endtime: 2017-12-27T18:20:54 renew till: unset
[2017/12/27 08:20:55.740222,  3] 
../source4/smbd/service_stream.c:65(stream_terminate_connection)
   Terminating connection - 'kdc_tcp_call_loop: 
tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
[2017/12/27 08:20:55.740440,  3] 
../source4/smbd/process_single.c:114(single_terminate)
   single_terminate: reason[kdc_tcp_call_loop: 
tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
[2017/12/27 08:20:55.770764,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.771034,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.771283,  3] 
../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
   Kerberos: TGS-REQ DCDO1$@AD.kdu.COM from ipv4:192.168.172.14:48488 
for krbtgt/AD.kdu.COM at AD.kdu.COM [forwarded, forwardable]
[2017/12/27 08:20:55.771576,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.771786,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.772103,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.772257,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.773194,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
[2017/12/27 08:20:55.773691,  3] 
../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
   Kerberos: TGS-REQ authtime: 2017-12-27T08:20:54 starttime: 
2017-12-27T08:20:55 endtime: 2017-12-27T18:20:54 renew till: unset
[2017/12/27 08:20:55.804565,  3] 
../source4/smbd/service_stream.c:65(stream_terminate_connection)
   Terminating connection - 'kdc_tcp_call_loop: 
tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
[2017/12/27 08:20:55.804774,  3] 
../source4/smbd/process_single.c:114(single_terminate)
   single_terminate: reason[kdc_tcp_call_loop: 
tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
[2017/12/27 08:20:55.806137,  5] 
../auth/gensec/gensec_start.c:739(gensec_start_mech)
   Starting GENSEC mechanism spnego
[2017/12/27 08:20:55.806296,  5] 
../auth/gensec/gensec_start.c:739(gensec_start_mech)
   Starting GENSEC submechanism gssapi_krb5
[2017/12/27 08:20:55.807170,  5] 
../source4/auth/gensec/gensec_gssapi.c:668(gensec_gssapi_update_internal)
   gensec_gssapi: credentials were delegated
[2017/12/27 08:20:55.807242,  5] 
../source4/auth/gensec/gensec_gssapi.c:687(gensec_gssapi_update_internal)
   GSSAPI Connection will be cryptographically signed
[2017/12/27 08:20:55.810168,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_T\04\00\00
-> 0
[2017/12/27 08:20:55.810265,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_\04\02\00\00
-> 0
[2017/12/27 08:20:55.810353,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_<\02\00\00
-> 0
[2017/12/27 08:20:55.810428,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\09\00\00\00 -> 0
[2017/12/27 08:20:55.810507,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\01\00\00\00\00 -> 0
[2017/12/27 08:20:55.810582,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\02\00\00\00 -> 0
[2017/12/27 08:20:55.810674,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\0B\00\00\00 -> 0
[2017/12/27 08:20:55.810745,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\02\00\00\00\00\00\05\20\00\00\000\02\00\00 -> 0
[2017/12/27 08:20:55.810826,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\2A\02\00\00 -> 1
[2017/12/27 08:20:55.810901,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
   gendb_search_v: NULL 
objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\21\02\00\00 -> 0
[2017/12/27 08:20:55.811125,  4] 
../auth/auth_log.c:860(log_successful_authz_event_human_readable)
   Successful AuthZ: [LDAP,krb5] user [AD]\[DCDO1$] 
[S-1-5-21-454945863-777199239-1595221609-1108] at [Wed, 27 Dec 2017 
08:20:55.811108 CET] Remote host [ipv4:192.168.172.14:56798] local host 
[ipv4:192.168.152.15:389]
[2017/12/27 08:20:55.811301,  4] ../auth/auth_log.c:220(log_json)
   JSON Authorization: {"timestamp":
"2017-12-27T08:20:55.811228+0100",
"type": "Authorization", "Authorization":
{"version": {"major": 1,
"minor": 0}, "localAddress":
"ipv4:192.168.152.15:389", "remoteAddress":
"ipv4:192.168.172.14:56798", "serviceDescription":
"LDAP", "authType":
"krb5", "domain": "AD", "account":
"DCDO1$", "sid":
"S-1-5-21-454945863-777199239-1595221609-1108",
"logonServer": "DCDO1",
"transportProtection": "SIGN", "accountFlags":
"0x00002100"}}
[2017/12/27 08:20:55.811385,  3] 
../auth/auth_log.c:139(get_auth_event_server)
   get_auth_event_server: Failed to find 'auth_event' registered on the 
message bus to send JSON authentication events to: 
NT_STATUS_OBJECT_NAME_NOT_FOUND
[2017/12/27 08:20:55.841539,  5] 
../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
   ldb_request BASE dn= filter=(objectClass=*)
[2017/12/27 08:20:55.871177,  5] 
../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
   ldb_request SUB dn=CN=Configuration,DC=ad,DC=kdu,DC=com 
filter=(&(objectCategory=server)(|(name=dcdo1.ad.kdu.com)(dNSHostName=dcdo1.ad.kdu.com)))
[2017/12/27 08:20:55.902579,  5] 
../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
   ldb_request ONE 
dn=CN=DCDO1,CN=Servers,CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=ad,DC=kdu,DC=com
filter=(|(objectCategory=nTDSDSA)(objectCategory=nTDSDSARO))
[2017/12/27 08:20:55.932550,  5] 
default/librpc/gen_ndr/ndr_drsuapi_s.c:93(drsuapi__op_dispatch)
   function drsuapi_DsReplicaSync will reply async
[2017/12/27 08:20:55.932676,  3] 
../source4/dsdb/repl/drepl_service.c:206(_drepl_schedule_replication)
   _drepl_schedule_replication: forcing sync of partition 
(141bbe37-5eda-42b8-b904-0b75e26b1e2d, dc=ad,dc=kdu,dc=com, 
1d535613-81fa-435f-ba17-631d5742c775._msdcs.ad.kdu.com)
[2017/12/27 08:20:55.932697,  4] 
../source4/dsdb/repl/drepl_periodic.c:187(dreplsrv_pendingops_schedule)
   dreplsrv_pending_schedule(1) scheduled for: Wed Dec 27 08:20:57 2017 CET
[2017/12/27 08:20:56.971645,  4] 
../source4/dsdb/samdb/ldb_modules/repl_meta_data.c:6725(replmd_extended_replicated_objects)
   linked_attributes_count=0
[2017/12/27 08:20:56.971966,  4] 
../source4/dsdb/samdb/ldb_modules/repl_meta_data.c:6561(replmd_replicated_uptodate_modify)
   DRS replication uptodate modify message:
   dn: DC=ad,DC=kdu,DC=com
   changetype: modify
   replace: replUpToDateVector
   replUpToDateVector:: 
AgAAAAAAAAADAAAAAAAAABblFEZH4CNPh3GL0LFEOVz6FAAAAAAAAACAP
tXesZ0BhJrYYEE7/kOJnoKr3dq/vN0PAAAAAAAAAIA+1d6xnQHgHbdwEVrzS7KYP2wnvCZRbBYAAA
    AAAAAAgD7V3rGdAQ=   -
   replace: repsFrom
   repsFrom:: 
AQAAAAAAAAAOAQAAAAAAAMHaUxADAAAAwdpTEAMAAAAAAAAA0AAAAD4AAAB0AAAAERE
RERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERER
ERERERERERERERERERERERERERERERERAAAAAGsWAAAAAAAAAAAAAAAAAABrFgAAAAAAAKQMPrx0t
UlIhMh6s36sM6XgHbdwEVrzS7KYP2wnvCZRAAAAAAAAAAAAAAAAAAAAADoAAABiYzNlMGNhNC1iNT
c0LTQ4NDktODRjOC03YWIzN2VhYzMzYTUuX21zZGNzLmFkLmthbmRvdS5jb20A
   repsFrom:: 
AQAAAAAAAAAOAQAAuQIAANjaUxADAAAA2NpTEAMAAAAAAAAA0AAAAD4AAABkAAAAERE
RERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERER
ERERERERERERERERERERERERERERERERAAAAAPgUAAAAAAAAAAAAAAAAAAD4FAAAAAAAABNWUx36g
V9DuhdjHVdCx3UW5RRGR+AjT4dxi9CxRDlcAAAAAAAAAAAAAAAAAAAAADoAAAAxZDUzNTYxMy04MW
ZhLTQzNWYtYmExNy02MzFkNTc0MmM3NzUuX21zZGNzLmFkLmthbmRvdS5jb20A
   -


[2017/12/27 08:20:56.974912,  2] 
../source4/dsdb/repl/replicated_objects.c:1020(dsdb_replicated_objects_commit)
   Replicated 0 objects (0 linked attributes) for DC=ad,DC=kdu,DC=com
[2017/12/27 08:20:57.004974,  0] 
../source4/dsdb/repl/drepl_out_helpers.c:1087(dreplsrv_update_refs_done)
   UpdateRefs failed with WERR_DS_DRA_ACCESS_DENIED/NT code 0xc0002105 
for 0acce4bc-1193-4609-8e4d-a0771bb6fb76._msdcs.ad.kdu.com 
DC=ad,DC=kdu,DC=com
[2017/12/27 08:20:57.005468,  4] 
../source4/dsdb/repl/drepl_out_pull.c:181(dreplsrv_pending_op_callback)
   dreplsrv_op_pull_source(WERR_DS_DRA_ACCESS_DENIED) for 
DC=ad,DC=kdu,DC=com
[2017/12/27 08:20:57.009507,  5] 
default/librpc/gen_ndr/ndr_drsuapi_s.c:389(drsuapi__op_reply)
   function drsuapi_DsReplicaSync replied async
[2017/12/27 08:20:57.053246,  3] 
../source4/smbd/service_stream.c:65(stream_terminate_connection)
   Terminating connection - 'dcesrv: NT_STATUS_CONNECTION_DISCONNECTED'
[2017/12/27 08:20:57.053478,  3] 
../source4/smbd/process_single.c:114(single_terminate)
   single_terminate: reason[dcesrv: NT_STATUS_CONNECTION_DISCONNECTED]
[2017/12/27 08:20:57.053528,  3] 
../source4/smbd/service_stream.c:65(stream_terminate_connection)
   Terminating connection - 'ldapsrv_call_loop: 
tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
[2017/12/27 08:20:57.053760,  2] 
../source4/smbd/process_standard.c:473(standard_terminate)
   standard_terminate: reason[ldapsrv_call_loop: 
tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
[2017/12/27 08:20:57.057842,  2] 
../source4/smbd/process_standard.c:157(standard_child_pipe_handler)
   Child 900 () exited with status 0

Any hints/ideas very much appreciated ...

Thanks,

Uli

Dr. Johannes-Ulrich Menzebach

2017-Dec-27 12:00 UTC

head link

[Samba] AD replication problem "WERR_DS_DRA_ACCESS_DENIED" - need help debugging

There is additional info in the logs of the source DC (dcdo1, log level 
2, manually triggered another replication):
===================[2017/12/27 12:31:29.695121,  2] 
../source4/rpc_server/drsuapi/getncchanges.c:1731(getncchanges_collect_objects)
   ../source4/rpc_server/drsuapi/getncchanges.c:1731: getncchanges on 
DC=ad,DC=kdu,DC=com using filter (uSNChanged>=5415)
[2017/12/27 12:31:29.698828,  2] 
../source4/rpc_server/drsuapi/getncchanges.c:3006(dcesrv_drsuapi_DsGetNCChanges)
   DsGetNCChanges with uSNChanged >= 5415 flags 0x80000064 on 
<GUID=141bbe37-5eda-42b8-b904-0b75e26b1e2d>;<SID=S-1-5-21-454945863-777199239-1595221609>;DC=ad,DC=kdu,DC=com
gave 0 objects (done 0/0) 0 links (done 0/0 (as 
S-1-5-21-454945863-777199239-1595221609-1112))
[2017/12/27 12:31:29.733157,  1] 
../source4/dsdb/common/util.c:4807(dsdb_validate_dsa_guid)
   ../source4/dsdb/common/util.c:4807: Failed to find account dn 
(serverReference) for 
CN=DCNH1,CN=Servers,CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=ad,DC=kdu,DC=com,
parent of DSA with objectGUID 0acce4bc-1193-4609-8e4d-a0771bb6fb76, sid 
S-1-5-21-454945863-777199239-1595221609-1112
[2017/12/27 12:31:29.733198,  0] 
../source4/rpc_server/drsuapi/updaterefs.c:374(dcesrv_drsuapi_DsReplicaUpdateRefs)
   ../source4/rpc_server/drsuapi/updaterefs.c:374: Refusing 
DsReplicaUpdateRefs for sid S-1-5-21-454945863-777199239-1595221609-1112 
with GUID 0acce4bc-1193-4609-8e4d-a0771bb6fb76

According to what I see in the "Sites and Services" RSAT console the
DN
for 
CN=DCNH1,CN=Servers,CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=ad,DC=kdu,DC=com
seems to exist.

Any ideas?

Thanks,

     Uli



On 12/27/2017 09:59 AM, Dr. Johannes-Ulrich Menzebach via samba
wrote:> We have 3 ADCs based on Samba-4.7.4 (compiled from source,internal 
> DNS)/ CentOS7: dcdo1,dcnh1 and dcge1. dcge1 holds all FSMO roles. The 
> 3 ADCs are on different locations connected via IPSec based VPN. No 
> traffic is filtered out.
>
> All 3 ADCs replicate fine except dcdo1 -->dcnh1. Symptom:
>
> [root at dcdo1 ~]# samba-tool drs replicate dcnh1.ad.kdu.com 
> dcdo1.ad.kdu.com dc=ad,dc=kdu,dc=com
> ERROR(<class 'samba.drs_utils.drsException'>): DsReplicaSync
failed -
> drsException: DsReplicaSync failed (8453,
'WERR_DS_DRA_ACCESS_DENIED')
>   File "/usr/lib64/python2.7/site-packages/samba/netcmd/drs.py",
line
> 386, in run
>     drs_utils.sendDsReplicaSync(server_bind, server_bind_handle, 
> source_dsa_guid, NC, req_options)
>   File "/usr/lib64/python2.7/site-packages/samba/drs_utils.py",
line
> 85, in sendDsReplicaSync
>     raise drsException("DsReplicaSync failed %s" % estr)
>
> Log on dcdo1:
> =============> [2017/12/27 08:20:56.335895,  0] 
>
../source4/rpc_server/drsuapi/updaterefs.c:374(dcesrv_drsuapi_DsReplicaUpdateRefs)
>   ../source4/rpc_server/drsuapi/updaterefs.c:374: Refusing 
> DsReplicaUpdateRefs for sid 
> S-1-5-21-454945863-777199239-1595221609-1112 with GUID 
> 0acce4bc-1193-4609-8e4d-a0771bb6fb76
>
> Log on target DC dcnh1:
> =============> [2017/12/27 08:20:55.278559,  5] 
> ../auth/auth_log.c:860(log_successful_authz_event_human_readable)
>   Successful AuthZ: [DCE/RPC,ncacn_ip_tcp] user [NT 
> AUTHORITY]\[ANONYMOUS LOGON] [S-1-5-7] at [Wed, 27 Dec 2017 
> 08:20:55.278538 CET] Remote host [ipv4:192.168.172.14:36196] local 
> host [ipv4:192.168.152.15:135]
> [2017/12/27 08:20:55.278641,  5] ../auth/auth_log.c:220(log_json)
>   JSON Authorization: {"timestamp":
"2017-12-27T08:20:55.278587+0100",
> "type": "Authorization", "Authorization":
{"version": {"major": 1,
> "minor": 0}, "localAddress":
"ipv4:192.168.152.15:135",
> "remoteAddress": "ipv4:192.168.172.14:36196",
"serviceDescription":
> "DCE/RPC", "authType": "ncacn_ip_tcp",
"domain": "NT AUTHORITY",
> "account": "ANONYMOUS LOGON", "sid":
"S-1-5-7", "logonServer":
> "DCNH1", "transportProtection": "NONE",
"accountFlags": "0x00000010"}}
> [2017/12/27 08:20:55.278660,  3] 
> ../auth/auth_log.c:139(get_auth_event_server)
>   get_auth_event_server: Failed to find 'auth_event' registered on
the
> message bus to send JSON authentication events to: 
> NT_STATUS_OBJECT_NAME_NOT_FOUND
> [2017/12/27 08:20:55.337740,  3] 
> ../source4/smbd/service_stream.c:65(stream_terminate_connection)
>   Terminating connection - 'dcesrv:
NT_STATUS_CONNECTION_DISCONNECTED'
> [2017/12/27 08:20:55.337873,  3] 
> ../source4/smbd/process_single.c:114(single_terminate)
>   single_terminate: reason[dcesrv: NT_STATUS_CONNECTION_DISCONNECTED]
> [2017/12/27 08:20:55.506117,  3] 
> ../lib/ldb-samba/ldb_wrap.c:326(ldb_wrap_connect)
>   ldb_wrap open of secrets.ldb
> [2017/12/27 08:20:55.506420,  5] 
> ../auth/gensec/gensec_start.c:739(gensec_start_mech)
>   Starting GENSEC mechanism spnego
> [2017/12/27 08:20:55.506501,  5] 
> ../auth/gensec/gensec_start.c:739(gensec_start_mech)
>   Starting GENSEC submechanism gssapi_krb5
> [2017/12/27 08:20:55.536259,  5] 
> ../source4/auth/gensec/gensec_gssapi.c:668(gensec_gssapi_update_internal)
>   gensec_gssapi: credentials were delegated
> [2017/12/27 08:20:55.536320,  5] 
> ../source4/auth/gensec/gensec_gssapi.c:685(gensec_gssapi_update_internal)
>   GSSAPI Connection will be cryptographically sealed
> [2017/12/27 08:20:55.538591,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
>
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_T\04\00\00
> -> 0
> [2017/12/27 08:20:55.538644,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
>
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_\04\02\00\00
> -> 0
> [2017/12/27 08:20:55.538712,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
>
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_<\02\00\00
> -> 0
> [2017/12/27 08:20:55.538762,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\09\00\00\00 
> -> 0
> [2017/12/27 08:20:55.538819,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\01\00\00\00\00 
> -> 0
> [2017/12/27 08:20:55.538864,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\02\00\00\00 
> -> 0
> [2017/12/27 08:20:55.538909,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\0B\00\00\00 
> -> 0
> [2017/12/27 08:20:55.538967,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
> objectSid=\01\02\00\00\00\00\00\05\20\00\00\000\02\00\00 -> 0
> [2017/12/27 08:20:55.539029,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
> objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\2A\02\00\00 -> 1
> [2017/12/27 08:20:55.539087,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
> objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\21\02\00\00 -> 0
> [2017/12/27 08:20:55.539289,  4] 
> ../auth/auth_log.c:860(log_successful_authz_event_human_readable)
>   Successful AuthZ: [DCE/RPC,krb5] user [AD]\[DCDO1$] 
> [S-1-5-21-454945863-777199239-1595221609-1108] at [Wed, 27 Dec 2017 
> 08:20:55.539277 CET] Remote host [ipv4:192.168.172.14:57364] local 
> host [ipv4:192.168.152.15:49152]
> [2017/12/27 08:20:55.539359,  4] ../auth/auth_log.c:220(log_json)
>   JSON Authorization: {"timestamp":
"2017-12-27T08:20:55.539334+0100",
> "type": "Authorization", "Authorization":
{"version": {"major": 1,
> "minor": 0}, "localAddress":
"ipv4:192.168.152.15:49152",
> "remoteAddress": "ipv4:192.168.172.14:57364",
"serviceDescription":
> "DCE/RPC", "authType": "krb5",
"domain": "AD", "account": "DCDO1$",
> "sid": "S-1-5-21-454945863-777199239-1595221609-1108",
"logonServer":
> "DCDO1", "transportProtection": "SEAL",
"accountFlags": "0x00002100"}}
> [2017/12/27 08:20:55.539398,  3] 
> ../auth/auth_log.c:139(get_auth_event_server)
>   get_auth_event_server: Failed to find 'auth_event' registered on
the
> message bus to send JSON authentication events to: 
> NT_STATUS_OBJECT_NAME_NOT_FOUND
> [2017/12/27 08:20:55.568937,  3] 
> ../source4/rpc_server/drsuapi/dcesrv_drsuapi.c:89(dcesrv_drsuapi_DsBind)
>   ../source4/rpc_server/drsuapi/dcesrv_drsuapi.c:89: doing DsBind with 
> system_session
> [2017/12/27 08:20:55.641297,  3] 
> ../lib/ldb-samba/ldb_wrap.c:326(ldb_wrap_connect)
>   ldb_wrap open of secrets.ldb
> [2017/12/27 08:20:55.644257,  5] 
> ../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
>   ldb_request BASE dn= filter=(|(objectClass=*)(distinguishedName=*))
> [2017/12/27 08:20:55.706421,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.706573,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.706777,  3] 
> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
>   Kerberos: TGS-REQ DCDO1$@AD.kdu.COM from ipv4:192.168.172.14:48486 
> for ldap/dcnh1.ad.kdu.com at AD.kdu.COM [canonicalize]
> [2017/12/27 08:20:55.708186,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.708670,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.708795,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.709594,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.710027,  3] 
> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
>   Kerberos: TGS-REQ authtime: 2017-12-27T08:20:54 starttime: 
> 2017-12-27T08:20:55 endtime: 2017-12-27T18:20:54 renew till: unset
> [2017/12/27 08:20:55.740222,  3] 
> ../source4/smbd/service_stream.c:65(stream_terminate_connection)
>   Terminating connection - 'kdc_tcp_call_loop: 
> tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
> [2017/12/27 08:20:55.740440,  3] 
> ../source4/smbd/process_single.c:114(single_terminate)
>   single_terminate: reason[kdc_tcp_call_loop: 
> tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
> [2017/12/27 08:20:55.770764,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.771034,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.771283,  3] 
> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
>   Kerberos: TGS-REQ DCDO1$@AD.kdu.COM from ipv4:192.168.172.14:48488 
> for krbtgt/AD.kdu.COM at AD.kdu.COM [forwarded, forwardable]
> [2017/12/27 08:20:55.771576,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.771786,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.772103,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.772257,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.773194,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> [2017/12/27 08:20:55.773691,  3] 
> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
>   Kerberos: TGS-REQ authtime: 2017-12-27T08:20:54 starttime: 
> 2017-12-27T08:20:55 endtime: 2017-12-27T18:20:54 renew till: unset
> [2017/12/27 08:20:55.804565,  3] 
> ../source4/smbd/service_stream.c:65(stream_terminate_connection)
>   Terminating connection - 'kdc_tcp_call_loop: 
> tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
> [2017/12/27 08:20:55.804774,  3] 
> ../source4/smbd/process_single.c:114(single_terminate)
>   single_terminate: reason[kdc_tcp_call_loop: 
> tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
> [2017/12/27 08:20:55.806137,  5] 
> ../auth/gensec/gensec_start.c:739(gensec_start_mech)
>   Starting GENSEC mechanism spnego
> [2017/12/27 08:20:55.806296,  5] 
> ../auth/gensec/gensec_start.c:739(gensec_start_mech)
>   Starting GENSEC submechanism gssapi_krb5
> [2017/12/27 08:20:55.807170,  5] 
> ../source4/auth/gensec/gensec_gssapi.c:668(gensec_gssapi_update_internal)
>   gensec_gssapi: credentials were delegated
> [2017/12/27 08:20:55.807242,  5] 
> ../source4/auth/gensec/gensec_gssapi.c:687(gensec_gssapi_update_internal)
>   GSSAPI Connection will be cryptographically signed
> [2017/12/27 08:20:55.810168,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
>
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_T\04\00\00
> -> 0
> [2017/12/27 08:20:55.810265,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
>
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_\04\02\00\00
> -> 0
> [2017/12/27 08:20:55.810353,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
>
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_<\02\00\00
> -> 0
> [2017/12/27 08:20:55.810428,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\09\00\00\00 
> -> 0
> [2017/12/27 08:20:55.810507,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\01\00\00\00\00 
> -> 0
> [2017/12/27 08:20:55.810582,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\02\00\00\00 
> -> 0
> [2017/12/27 08:20:55.810674,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL objectSid=\01\01\00\00\00\00\00\05\0B\00\00\00 
> -> 0
> [2017/12/27 08:20:55.810745,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
> objectSid=\01\02\00\00\00\00\00\05\20\00\00\000\02\00\00 -> 0
> [2017/12/27 08:20:55.810826,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
> objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\2A\02\00\00 -> 1
> [2017/12/27 08:20:55.810901,  6] 
> ../lib/util/util_ldb.c:60(gendb_search_v)
>   gendb_search_v: NULL 
> objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\21\02\00\00 -> 0
> [2017/12/27 08:20:55.811125,  4] 
> ../auth/auth_log.c:860(log_successful_authz_event_human_readable)
>   Successful AuthZ: [LDAP,krb5] user [AD]\[DCDO1$] 
> [S-1-5-21-454945863-777199239-1595221609-1108] at [Wed, 27 Dec 2017 
> 08:20:55.811108 CET] Remote host [ipv4:192.168.172.14:56798] local 
> host [ipv4:192.168.152.15:389]
> [2017/12/27 08:20:55.811301,  4] ../auth/auth_log.c:220(log_json)
>   JSON Authorization: {"timestamp":
"2017-12-27T08:20:55.811228+0100",
> "type": "Authorization", "Authorization":
{"version": {"major": 1,
> "minor": 0}, "localAddress":
"ipv4:192.168.152.15:389",
> "remoteAddress": "ipv4:192.168.172.14:56798",
"serviceDescription":
> "LDAP", "authType": "krb5",
"domain": "AD", "account": "DCDO1$",
> "sid": "S-1-5-21-454945863-777199239-1595221609-1108",
"logonServer":
> "DCDO1", "transportProtection": "SIGN",
"accountFlags": "0x00002100"}}
> [2017/12/27 08:20:55.811385,  3] 
> ../auth/auth_log.c:139(get_auth_event_server)
>   get_auth_event_server: Failed to find 'auth_event' registered on
the
> message bus to send JSON authentication events to: 
> NT_STATUS_OBJECT_NAME_NOT_FOUND
> [2017/12/27 08:20:55.841539,  5] 
> ../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
>   ldb_request BASE dn= filter=(objectClass=*)
> [2017/12/27 08:20:55.871177,  5] 
> ../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
>   ldb_request SUB dn=CN=Configuration,DC=ad,DC=kdu,DC=com 
>
filter=(&(objectCategory=server)(|(name=dcdo1.ad.kdu.com)(dNSHostName=dcdo1.ad.kdu.com)))
> [2017/12/27 08:20:55.902579,  5] 
> ../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
>   ldb_request ONE 
>
dn=CN=DCDO1,CN=Servers,CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=ad,DC=kdu,DC=com
> filter=(|(objectCategory=nTDSDSA)(objectCategory=nTDSDSARO))
> [2017/12/27 08:20:55.932550,  5] 
> default/librpc/gen_ndr/ndr_drsuapi_s.c:93(drsuapi__op_dispatch)
>   function drsuapi_DsReplicaSync will reply async
> [2017/12/27 08:20:55.932676,  3] 
> ../source4/dsdb/repl/drepl_service.c:206(_drepl_schedule_replication)
>   _drepl_schedule_replication: forcing sync of partition 
> (141bbe37-5eda-42b8-b904-0b75e26b1e2d, dc=ad,dc=kdu,dc=com, 
> 1d535613-81fa-435f-ba17-631d5742c775._msdcs.ad.kdu.com)
> [2017/12/27 08:20:55.932697,  4] 
> ../source4/dsdb/repl/drepl_periodic.c:187(dreplsrv_pendingops_schedule)
>   dreplsrv_pending_schedule(1) scheduled for: Wed Dec 27 08:20:57 2017 
> CET
> [2017/12/27 08:20:56.971645,  4] 
>
../source4/dsdb/samdb/ldb_modules/repl_meta_data.c:6725(replmd_extended_replicated_objects)
>   linked_attributes_count=0
> [2017/12/27 08:20:56.971966,  4] 
>
../source4/dsdb/samdb/ldb_modules/repl_meta_data.c:6561(replmd_replicated_uptodate_modify)
>   DRS replication uptodate modify message:
>   dn: DC=ad,DC=kdu,DC=com
>   changetype: modify
>   replace: replUpToDateVector
>   replUpToDateVector:: 
> AgAAAAAAAAADAAAAAAAAABblFEZH4CNPh3GL0LFEOVz6FAAAAAAAAACAP
>
tXesZ0BhJrYYEE7/kOJnoKr3dq/vN0PAAAAAAAAAIA+1d6xnQHgHbdwEVrzS7KYP2wnvCZRbBYAAA
>
>    AAAAAAgD7V3rGdAQ=>   -
>   replace: repsFrom
>   repsFrom:: 
> AQAAAAAAAAAOAQAAAAAAAMHaUxADAAAAwdpTEAMAAAAAAAAA0AAAAD4AAAB0AAAAERE
>
RERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERER
>
>
ERERERERERERERERERERERERERERERERAAAAAGsWAAAAAAAAAAAAAAAAAABrFgAAAAAAAKQMPrx0t
>
>
UlIhMh6s36sM6XgHbdwEVrzS7KYP2wnvCZRAAAAAAAAAAAAAAAAAAAAADoAAABiYzNlMGNhNC1iNT
>
> c0LTQ4NDktODRjOC03YWIzN2VhYzMzYTUuX21zZGNzLmFkLmthbmRvdS5jb20A
>   repsFrom:: 
> AQAAAAAAAAAOAQAAuQIAANjaUxADAAAA2NpTEAMAAAAAAAAA0AAAAD4AAABkAAAAERE
>
RERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERER
>
>
ERERERERERERERERERERERERERERERERAAAAAPgUAAAAAAAAAAAAAAAAAAD4FAAAAAAAABNWUx36g
>
>
V9DuhdjHVdCx3UW5RRGR+AjT4dxi9CxRDlcAAAAAAAAAAAAAAAAAAAAADoAAAAxZDUzNTYxMy04MW
>
> ZhLTQzNWYtYmExNy02MzFkNTc0MmM3NzUuX21zZGNzLmFkLmthbmRvdS5jb20A
>   -
>
>
> [2017/12/27 08:20:56.974912,  2] 
>
../source4/dsdb/repl/replicated_objects.c:1020(dsdb_replicated_objects_commit)
>   Replicated 0 objects (0 linked attributes) for DC=ad,DC=kdu,DC=com
> [2017/12/27 08:20:57.004974,  0] 
> ../source4/dsdb/repl/drepl_out_helpers.c:1087(dreplsrv_update_refs_done)
>   UpdateRefs failed with WERR_DS_DRA_ACCESS_DENIED/NT code 0xc0002105 
> for 0acce4bc-1193-4609-8e4d-a0771bb6fb76._msdcs.ad.kdu.com 
> DC=ad,DC=kdu,DC=com
> [2017/12/27 08:20:57.005468,  4] 
> ../source4/dsdb/repl/drepl_out_pull.c:181(dreplsrv_pending_op_callback)
>   dreplsrv_op_pull_source(WERR_DS_DRA_ACCESS_DENIED) for 
> DC=ad,DC=kdu,DC=com
> [2017/12/27 08:20:57.009507,  5] 
> default/librpc/gen_ndr/ndr_drsuapi_s.c:389(drsuapi__op_reply)
>   function drsuapi_DsReplicaSync replied async
> [2017/12/27 08:20:57.053246,  3] 
> ../source4/smbd/service_stream.c:65(stream_terminate_connection)
>   Terminating connection - 'dcesrv:
NT_STATUS_CONNECTION_DISCONNECTED'
> [2017/12/27 08:20:57.053478,  3] 
> ../source4/smbd/process_single.c:114(single_terminate)
>   single_terminate: reason[dcesrv: NT_STATUS_CONNECTION_DISCONNECTED]
> [2017/12/27 08:20:57.053528,  3] 
> ../source4/smbd/service_stream.c:65(stream_terminate_connection)
>   Terminating connection - 'ldapsrv_call_loop: 
> tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
> [2017/12/27 08:20:57.053760,  2] 
> ../source4/smbd/process_standard.c:473(standard_terminate)
>   standard_terminate: reason[ldapsrv_call_loop: 
> tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
> [2017/12/27 08:20:57.057842,  2] 
> ../source4/smbd/process_standard.c:157(standard_child_pipe_handler)
>   Child 900 () exited with status 0
>
> Any hints/ideas very much appreciated ...
>
> Thanks,
>
> Uli
>
>

Rowland Penny

2017-Dec-27 12:29 UTC

head link

[Samba] AD replication problem "WERR_DS_DRA_ACCESS_DENIED" - need help debugging

On Wed, 27 Dec 2017 13:00:05 +0100
"Dr. Johannes-Ulrich Menzebach via samba" <samba at
lists.samba.org> wrote:
> There is additional info in the logs of the source DC (dcdo1, log
> level 2, manually triggered another replication):
> ===================> [2017/12/27 12:31:29.695121,  2] 
>
../source4/rpc_server/drsuapi/getncchanges.c:1731(getncchanges_collect_objects)
>    ../source4/rpc_server/drsuapi/getncchanges.c:1731: getncchanges on 
> DC=ad,DC=kdu,DC=com using filter (uSNChanged>=5415)
> [2017/12/27 12:31:29.698828,  2] 
>
../source4/rpc_server/drsuapi/getncchanges.c:3006(dcesrv_drsuapi_DsGetNCChanges)
>    DsGetNCChanges with uSNChanged >= 5415 flags 0x80000064 on 
>
<GUID=141bbe37-5eda-42b8-b904-0b75e26b1e2d>;<SID=S-1-5-21-454945863-777199239-1595221609>;DC=ad,DC=kdu,DC=com
> gave 0 objects (done 0/0) 0 links (done 0/0 (as 
> S-1-5-21-454945863-777199239-1595221609-1112))
> [2017/12/27 12:31:29.733157,  1] 
> ../source4/dsdb/common/util.c:4807(dsdb_validate_dsa_guid)
>    ../source4/dsdb/common/util.c:4807: Failed to find account dn 
> (serverReference) for 
>
CN=DCNH1,CN=Servers,CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=ad,DC=kdu,DC=com,
> parent of DSA with objectGUID 0acce4bc-1193-4609-8e4d-a0771bb6fb76,
> sid S-1-5-21-454945863-777199239-1595221609-1112
> [2017/12/27 12:31:29.733198,  0] 
>
../source4/rpc_server/drsuapi/updaterefs.c:374(dcesrv_drsuapi_DsReplicaUpdateRefs)
>    ../source4/rpc_server/drsuapi/updaterefs.c:374: Refusing 
> DsReplicaUpdateRefs for sid
> S-1-5-21-454945863-777199239-1595221609-1112 with GUID
> 0acce4bc-1193-4609-8e4d-a0771bb6fb76
> 
> According to what I see in the "Sites and Services" RSAT console
the
> DN for 
>
CN=DCNH1,CN=Servers,CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=ad,DC=kdu,DC=com
> seems to exist.
> 
> Any ideas?
> 
> Thanks,
> 
>      Uli
> 
> 
> 
> On 12/27/2017 09:59 AM, Dr. Johannes-Ulrich Menzebach via samba wrote:
> > We have 3 ADCs based on Samba-4.7.4 (compiled from source,internal 
> > DNS)/ CentOS7: dcdo1,dcnh1 and dcge1. dcge1 holds all FSMO roles.
> > The 3 ADCs are on different locations connected via IPSec based
> > VPN. No traffic is filtered out.
> >
> > All 3 ADCs replicate fine except dcdo1 -->dcnh1. Symptom:
> >
> > [root at dcdo1 ~]# samba-tool drs replicate dcnh1.ad.kdu.com 
> > dcdo1.ad.kdu.com dc=ad,dc=kdu,dc=com
> > ERROR(<class 'samba.drs_utils.drsException'>):
DsReplicaSync failed
> > - drsException: DsReplicaSync failed (8453,
> > 'WERR_DS_DRA_ACCESS_DENIED') File
> > "/usr/lib64/python2.7/site-packages/samba/netcmd/drs.py",
line 386,
> > in run drs_utils.sendDsReplicaSync(server_bind, server_bind_handle, 
> > source_dsa_guid, NC, req_options)
> >   File
"/usr/lib64/python2.7/site-packages/samba/drs_utils.py",
> > line 85, in sendDsReplicaSync
> >     raise drsException("DsReplicaSync failed %s" % estr)
> >
> > Log on dcdo1:
> > =============> > [2017/12/27 08:20:56.335895,  0] 
> >
../source4/rpc_server/drsuapi/updaterefs.c:374(dcesrv_drsuapi_DsReplicaUpdateRefs)
> >   ../source4/rpc_server/drsuapi/updaterefs.c:374: Refusing 
> > DsReplicaUpdateRefs for sid 
> > S-1-5-21-454945863-777199239-1595221609-1112 with GUID 
> > 0acce4bc-1193-4609-8e4d-a0771bb6fb76
> >
> > Log on target DC dcnh1:
> > =============> > [2017/12/27 08:20:55.278559,  5] 
> > ../auth/auth_log.c:860(log_successful_authz_event_human_readable)
> >   Successful AuthZ: [DCE/RPC,ncacn_ip_tcp] user [NT 
> > AUTHORITY]\[ANONYMOUS LOGON] [S-1-5-7] at [Wed, 27 Dec 2017 
> > 08:20:55.278538 CET] Remote host [ipv4:192.168.172.14:36196] local 
> > host [ipv4:192.168.152.15:135]
> > [2017/12/27 08:20:55.278641,  5] ../auth/auth_log.c:220(log_json)
> >   JSON Authorization: {"timestamp":
> > "2017-12-27T08:20:55.278587+0100", "type":
"Authorization",
> > "Authorization": {"version": {"major":
1, "minor": 0},
> > "localAddress": "ipv4:192.168.152.15:135",
"remoteAddress":
> > "ipv4:192.168.172.14:36196", "serviceDescription":
"DCE/RPC",
> > "authType": "ncacn_ip_tcp", "domain":
"NT AUTHORITY", "account":
> > "ANONYMOUS LOGON", "sid": "S-1-5-7",
"logonServer": "DCNH1",
> > "transportProtection": "NONE",
"accountFlags": "0x00000010"}}
> > [2017/12/27 08:20:55.278660,
> > 3] ../auth/auth_log.c:139(get_auth_event_server)
> > get_auth_event_server: Failed to find 'auth_event' registered
on
> > the message bus to send JSON authentication events to:
> > NT_STATUS_OBJECT_NAME_NOT_FOUND [2017/12/27 08:20:55.337740,  3] 
> > ../source4/smbd/service_stream.c:65(stream_terminate_connection)
> >   Terminating connection - 'dcesrv:
> > NT_STATUS_CONNECTION_DISCONNECTED' [2017/12/27 08:20:55.337873, 
3]
> > ../source4/smbd/process_single.c:114(single_terminate)
> >   single_terminate: reason[dcesrv:
> > NT_STATUS_CONNECTION_DISCONNECTED] [2017/12/27 08:20:55.506117,  3] 
> > ../lib/ldb-samba/ldb_wrap.c:326(ldb_wrap_connect)
> >   ldb_wrap open of secrets.ldb
> > [2017/12/27 08:20:55.506420,  5] 
> > ../auth/gensec/gensec_start.c:739(gensec_start_mech)
> >   Starting GENSEC mechanism spnego
> > [2017/12/27 08:20:55.506501,  5] 
> > ../auth/gensec/gensec_start.c:739(gensec_start_mech)
> >   Starting GENSEC submechanism gssapi_krb5
> > [2017/12/27 08:20:55.536259,  5] 
> >
../source4/auth/gensec/gensec_gssapi.c:668(gensec_gssapi_update_internal)
> >   gensec_gssapi: credentials were delegated
> > [2017/12/27 08:20:55.536320,  5] 
> >
../source4/auth/gensec/gensec_gssapi.c:685(gensec_gssapi_update_internal)
> >   GSSAPI Connection will be cryptographically sealed
> > [2017/12/27 08:20:55.538591,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> >
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_T\04\00\00
> > -> 0
> > [2017/12/27 08:20:55.538644,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> >
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_\04\02\00\00
> > -> 0
> > [2017/12/27 08:20:55.538712,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> >
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_<\02\00\00
> > -> 0
> > [2017/12/27 08:20:55.538762,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL
> > objectSid=\01\01\00\00\00\00\00\05\09\00\00\00 -> 0
> > [2017/12/27 08:20:55.538819,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL
> > objectSid=\01\01\00\00\00\00\00\01\00\00\00\00 -> 0
> > [2017/12/27 08:20:55.538864,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL
> > objectSid=\01\01\00\00\00\00\00\05\02\00\00\00 -> 0
> > [2017/12/27 08:20:55.538909,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL
> > objectSid=\01\01\00\00\00\00\00\05\0B\00\00\00 -> 0
> > [2017/12/27 08:20:55.538967,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> > objectSid=\01\02\00\00\00\00\00\05\20\00\00\000\02\00\00 -> 0
> > [2017/12/27 08:20:55.539029,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> > objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\2A\02\00\00 -> 1
> > [2017/12/27 08:20:55.539087,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> > objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\21\02\00\00 -> 0
> > [2017/12/27 08:20:55.539289,  4] 
> > ../auth/auth_log.c:860(log_successful_authz_event_human_readable)
> >   Successful AuthZ: [DCE/RPC,krb5] user [AD]\[DCDO1$] 
> > [S-1-5-21-454945863-777199239-1595221609-1108] at [Wed, 27 Dec 2017 
> > 08:20:55.539277 CET] Remote host [ipv4:192.168.172.14:57364] local 
> > host [ipv4:192.168.152.15:49152]
> > [2017/12/27 08:20:55.539359,  4] ../auth/auth_log.c:220(log_json)
> >   JSON Authorization: {"timestamp":
> > "2017-12-27T08:20:55.539334+0100", "type":
"Authorization",
> > "Authorization": {"version": {"major":
1, "minor": 0},
> > "localAddress": "ipv4:192.168.152.15:49152",
"remoteAddress":
> > "ipv4:192.168.172.14:57364", "serviceDescription":
"DCE/RPC",
> > "authType": "krb5", "domain":
"AD", "account": "DCDO1$", "sid":
> > "S-1-5-21-454945863-777199239-1595221609-1108",
"logonServer":
> > "DCDO1", "transportProtection": "SEAL",
"accountFlags":
> > "0x00002100"}} [2017/12/27 08:20:55.539398,
> > 3] ../auth/auth_log.c:139(get_auth_event_server)
> > get_auth_event_server: Failed to find 'auth_event' registered
on
> > the message bus to send JSON authentication events to:
> > NT_STATUS_OBJECT_NAME_NOT_FOUND [2017/12/27 08:20:55.568937,  3] 
> >
../source4/rpc_server/drsuapi/dcesrv_drsuapi.c:89(dcesrv_drsuapi_DsBind)
> >   ../source4/rpc_server/drsuapi/dcesrv_drsuapi.c:89: doing DsBind
> > with system_session
> > [2017/12/27 08:20:55.641297,  3] 
> > ../lib/ldb-samba/ldb_wrap.c:326(ldb_wrap_connect)
> >   ldb_wrap open of secrets.ldb
> > [2017/12/27 08:20:55.644257,  5] 
> > ../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
> >   ldb_request BASE dn> >
filter=(|(objectClass=*)(distinguishedName=*)) [2017/12/27
> > 08:20:55.706421,  6] ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.706573,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.706777,  3] 
> >
../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
> >   Kerberos: TGS-REQ DCDO1$@AD.kdu.COM from
> > ipv4:192.168.172.14:48486 for ldap/dcnh1.ad.kdu.com at AD.kdu.COM
> > [canonicalize] [2017/12/27 08:20:55.708186,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.708670,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.708795,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.709594,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.710027,  3] 
> >
../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
> >   Kerberos: TGS-REQ authtime: 2017-12-27T08:20:54 starttime: 
> > 2017-12-27T08:20:55 endtime: 2017-12-27T18:20:54 renew till: unset
> > [2017/12/27 08:20:55.740222,  3] 
> > ../source4/smbd/service_stream.c:65(stream_terminate_connection)
> >   Terminating connection - 'kdc_tcp_call_loop: 
> > tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
> > [2017/12/27 08:20:55.740440,  3] 
> > ../source4/smbd/process_single.c:114(single_terminate)
> >   single_terminate: reason[kdc_tcp_call_loop: 
> > tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
> > [2017/12/27 08:20:55.770764,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.771034,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.771283,  3] 
> >
../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
> >   Kerberos: TGS-REQ DCDO1$@AD.kdu.COM from
> > ipv4:192.168.172.14:48488 for krbtgt/AD.kdu.COM at AD.kdu.COM
> > [forwarded, forwardable] [2017/12/27 08:20:55.771576,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.771786,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.772103,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.772257,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.773194,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: DC=ad,DC=kdu,DC=com NULL -> 1
> > [2017/12/27 08:20:55.773691,  3] 
> >
../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper)
> >   Kerberos: TGS-REQ authtime: 2017-12-27T08:20:54 starttime: 
> > 2017-12-27T08:20:55 endtime: 2017-12-27T18:20:54 renew till: unset
> > [2017/12/27 08:20:55.804565,  3] 
> > ../source4/smbd/service_stream.c:65(stream_terminate_connection)
> >   Terminating connection - 'kdc_tcp_call_loop: 
> > tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
> > [2017/12/27 08:20:55.804774,  3] 
> > ../source4/smbd/process_single.c:114(single_terminate)
> >   single_terminate: reason[kdc_tcp_call_loop: 
> > tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
> > [2017/12/27 08:20:55.806137,  5] 
> > ../auth/gensec/gensec_start.c:739(gensec_start_mech)
> >   Starting GENSEC mechanism spnego
> > [2017/12/27 08:20:55.806296,  5] 
> > ../auth/gensec/gensec_start.c:739(gensec_start_mech)
> >   Starting GENSEC submechanism gssapi_krb5
> > [2017/12/27 08:20:55.807170,  5] 
> >
../source4/auth/gensec/gensec_gssapi.c:668(gensec_gssapi_update_internal)
> >   gensec_gssapi: credentials were delegated
> > [2017/12/27 08:20:55.807242,  5] 
> >
../source4/auth/gensec/gensec_gssapi.c:687(gensec_gssapi_update_internal)
> >   GSSAPI Connection will be cryptographically signed
> > [2017/12/27 08:20:55.810168,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> >
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_T\04\00\00
> > -> 0
> > [2017/12/27 08:20:55.810265,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> >
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_\04\02\00\00
> > -> 0
> > [2017/12/27 08:20:55.810353,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> >
objectSid=\01\05\00\00\00\00\00\05\15\00\00\00G\EC\1D\1B\87\1ES.i\26\15_<\02\00\00
> > -> 0
> > [2017/12/27 08:20:55.810428,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL
> > objectSid=\01\01\00\00\00\00\00\05\09\00\00\00 -> 0
> > [2017/12/27 08:20:55.810507,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL
> > objectSid=\01\01\00\00\00\00\00\01\00\00\00\00 -> 0
> > [2017/12/27 08:20:55.810582,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL
> > objectSid=\01\01\00\00\00\00\00\05\02\00\00\00 -> 0
> > [2017/12/27 08:20:55.810674,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL
> > objectSid=\01\01\00\00\00\00\00\05\0B\00\00\00 -> 0
> > [2017/12/27 08:20:55.810745,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> > objectSid=\01\02\00\00\00\00\00\05\20\00\00\000\02\00\00 -> 0
> > [2017/12/27 08:20:55.810826,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> > objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\2A\02\00\00 -> 1
> > [2017/12/27 08:20:55.810901,  6] 
> > ../lib/util/util_ldb.c:60(gendb_search_v)
> >   gendb_search_v: NULL 
> > objectSid=\01\02\00\00\00\00\00\05\20\00\00\00\21\02\00\00 -> 0
> > [2017/12/27 08:20:55.811125,  4] 
> > ../auth/auth_log.c:860(log_successful_authz_event_human_readable)
> >   Successful AuthZ: [LDAP,krb5] user [AD]\[DCDO1$] 
> > [S-1-5-21-454945863-777199239-1595221609-1108] at [Wed, 27 Dec 2017 
> > 08:20:55.811108 CET] Remote host [ipv4:192.168.172.14:56798] local 
> > host [ipv4:192.168.152.15:389]
> > [2017/12/27 08:20:55.811301,  4] ../auth/auth_log.c:220(log_json)
> >   JSON Authorization: {"timestamp":
> > "2017-12-27T08:20:55.811228+0100", "type":
"Authorization",
> > "Authorization": {"version": {"major":
1, "minor": 0},
> > "localAddress": "ipv4:192.168.152.15:389",
"remoteAddress":
> > "ipv4:192.168.172.14:56798", "serviceDescription":
"LDAP",
> > "authType": "krb5", "domain":
"AD", "account": "DCDO1$", "sid":
> > "S-1-5-21-454945863-777199239-1595221609-1108",
"logonServer":
> > "DCDO1", "transportProtection": "SIGN",
"accountFlags":
> > "0x00002100"}} [2017/12/27 08:20:55.811385,
> > 3] ../auth/auth_log.c:139(get_auth_event_server)
> > get_auth_event_server: Failed to find 'auth_event' registered
on
> > the message bus to send JSON authentication events to:
> > NT_STATUS_OBJECT_NAME_NOT_FOUND [2017/12/27 08:20:55.841539,  5] 
> > ../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
> >   ldb_request BASE dn= filter=(objectClass=*)
> > [2017/12/27 08:20:55.871177,  5] 
> > ../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
> >   ldb_request SUB dn=CN=Configuration,DC=ad,DC=kdu,DC=com 
> >
filter=(&(objectCategory=server)(|(name=dcdo1.ad.kdu.com)(dNSHostName=dcdo1.ad.kdu.com)))
> > [2017/12/27 08:20:55.902579,  5] 
> > ../source4/ldap_server/ldap_backend.c:578(ldapsrv_SearchRequest)
> >   ldb_request ONE 
> >
dn=CN=DCDO1,CN=Servers,CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=ad,DC=kdu,DC=com
> > filter=(|(objectCategory=nTDSDSA)(objectCategory=nTDSDSARO))
> > [2017/12/27 08:20:55.932550,  5] 
> > default/librpc/gen_ndr/ndr_drsuapi_s.c:93(drsuapi__op_dispatch)
> >   function drsuapi_DsReplicaSync will reply async
> > [2017/12/27 08:20:55.932676,  3] 
> > ../source4/dsdb/repl/drepl_service.c:206(_drepl_schedule_replication)
> >   _drepl_schedule_replication: forcing sync of partition 
> > (141bbe37-5eda-42b8-b904-0b75e26b1e2d, dc=ad,dc=kdu,dc=com, 
> > 1d535613-81fa-435f-ba17-631d5742c775._msdcs.ad.kdu.com)
> > [2017/12/27 08:20:55.932697,  4] 
> >
../source4/dsdb/repl/drepl_periodic.c:187(dreplsrv_pendingops_schedule)
> >   dreplsrv_pending_schedule(1) scheduled for: Wed Dec 27 08:20:57
> > 2017 CET
> > [2017/12/27 08:20:56.971645,  4] 
> >
../source4/dsdb/samdb/ldb_modules/repl_meta_data.c:6725(replmd_extended_replicated_objects)
> >   linked_attributes_count=0
> > [2017/12/27 08:20:56.971966,  4] 
> >
../source4/dsdb/samdb/ldb_modules/repl_meta_data.c:6561(replmd_replicated_uptodate_modify)
> >   DRS replication uptodate modify message:
> >   dn: DC=ad,DC=kdu,DC=com
> >   changetype: modify
> >   replace: replUpToDateVector
> >   replUpToDateVector:: 
> > AgAAAAAAAAADAAAAAAAAABblFEZH4CNPh3GL0LFEOVz6FAAAAAAAAACAP
> >
tXesZ0BhJrYYEE7/kOJnoKr3dq/vN0PAAAAAAAAAIA+1d6xnQHgHbdwEVrzS7KYP2wnvCZRbBYAAA
> >
> >    AAAAAAgD7V3rGdAQ=> >   -
> >   replace: repsFrom
> >   repsFrom:: 
> > AQAAAAAAAAAOAQAAAAAAAMHaUxADAAAAwdpTEAMAAAAAAAAA0AAAAD4AAAB0AAAAERE
> >
RERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERER
> >
> >
ERERERERERERERERERERERERERERERERAAAAAGsWAAAAAAAAAAAAAAAAAABrFgAAAAAAAKQMPrx0t
> >
> >
UlIhMh6s36sM6XgHbdwEVrzS7KYP2wnvCZRAAAAAAAAAAAAAAAAAAAAADoAAABiYzNlMGNhNC1iNT
> >
> > c0LTQ4NDktODRjOC03YWIzN2VhYzMzYTUuX21zZGNzLmFkLmthbmRvdS5jb20A
> >   repsFrom:: 
> > AQAAAAAAAAAOAQAAuQIAANjaUxADAAAA2NpTEAMAAAAAAAAA0AAAAD4AAABkAAAAERE
> >
RERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERERER
> >
> >
ERERERERERERERERERERERERERERERERAAAAAPgUAAAAAAAAAAAAAAAAAAD4FAAAAAAAABNWUx36g
> >
> >
V9DuhdjHVdCx3UW5RRGR+AjT4dxi9CxRDlcAAAAAAAAAAAAAAAAAAAAADoAAAAxZDUzNTYxMy04MW
> >
> > ZhLTQzNWYtYmExNy02MzFkNTc0MmM3NzUuX21zZGNzLmFkLmthbmRvdS5jb20A
> >   -
> >
> >
> > [2017/12/27 08:20:56.974912,  2] 
> >
../source4/dsdb/repl/replicated_objects.c:1020(dsdb_replicated_objects_commit)
> >   Replicated 0 objects (0 linked attributes) for DC=ad,DC=kdu,DC=com
> > [2017/12/27 08:20:57.004974,  0] 
> >
../source4/dsdb/repl/drepl_out_helpers.c:1087(dreplsrv_update_refs_done)
> >   UpdateRefs failed with WERR_DS_DRA_ACCESS_DENIED/NT code
> > 0xc0002105 for
> > 0acce4bc-1193-4609-8e4d-a0771bb6fb76._msdcs.ad.kdu.com
> > DC=ad,DC=kdu,DC=com [2017/12/27 08:20:57.005468,  4] 
> >
../source4/dsdb/repl/drepl_out_pull.c:181(dreplsrv_pending_op_callback)
> >   dreplsrv_op_pull_source(WERR_DS_DRA_ACCESS_DENIED) for 
> > DC=ad,DC=kdu,DC=com
> > [2017/12/27 08:20:57.009507,  5] 
> > default/librpc/gen_ndr/ndr_drsuapi_s.c:389(drsuapi__op_reply)
> >   function drsuapi_DsReplicaSync replied async
> > [2017/12/27 08:20:57.053246,  3] 
> > ../source4/smbd/service_stream.c:65(stream_terminate_connection)
> >   Terminating connection - 'dcesrv:
> > NT_STATUS_CONNECTION_DISCONNECTED' [2017/12/27 08:20:57.053478, 
3]
> > ../source4/smbd/process_single.c:114(single_terminate)
> >   single_terminate: reason[dcesrv:
> > NT_STATUS_CONNECTION_DISCONNECTED] [2017/12/27 08:20:57.053528,  3] 
> > ../source4/smbd/service_stream.c:65(stream_terminate_connection)
> >   Terminating connection - 'ldapsrv_call_loop: 
> > tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED'
> > [2017/12/27 08:20:57.053760,  2] 
> > ../source4/smbd/process_standard.c:473(standard_terminate)
> >   standard_terminate: reason[ldapsrv_call_loop: 
> > tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED]
> > [2017/12/27 08:20:57.057842,  2] 
> > ../source4/smbd/process_standard.c:157(standard_child_pipe_handler)
> >   Child 900 () exited with status 0
> >
> > Any hints/ideas very much appreciated ...
> >
> > Thanks,
> >
> > Uli
> >
> >
> 
> 
Couple of thoughts, try reading this:

https://wiki.samba.org/index.php/Verifying_and_Creating_a_DC_DNS_Record

and this:

https://wiki.samba.org/index.php/Manually_Replicating_Directory_Partitions

Does the missing 'CN' exist on the other two DCs ?

Rowland

Possibly Parallel Threads

Search for more seemingly similar threads

samba - Dec 2017 - AD replication problem "WERR_DS_DRA_ACCESS_DENIED" - need help debugging

[Samba] AD replication problem "WERR_DS_DRA_ACCESS_DENIED" - need help debugging

[Samba] AD replication problem "WERR_DS_DRA_ACCESS_DENIED" - need help debugging

[Samba] AD replication problem "WERR_DS_DRA_ACCESS_DENIED" - need help debugging

Possibly Parallel Threads