Bug 9400 - dcerpc_fault WERR_EPT_S_CANT_PERFORM_OP in drsuapi_DsReplicaSync
Summary: dcerpc_fault WERR_EPT_S_CANT_PERFORM_OP in drsuapi_DsReplicaSync
Status: NEW
Alias: None
Product: Samba 4.0
Classification: Unclassified
Component: AD: LDB/DSDB/SAMDB (show other bugs)
Version: 4.0.0rc5
Hardware: x86 Linux
: P5 normal (vote)
Target Milestone: ---
Assignee: Andrew Bartlett
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-11-15 09:42 UTC by Sergey Urushkin
Modified: 2012-11-15 09:42 UTC (History)
0 users

See Also:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Sergey Urushkin 2012-11-15 09:42:11 UTC 
We have 2 running s4 DCs in production (migrated from s3), more than half thousand users.

From time to time (after some changes are made to the directory, e.g.
group policies) I see these messages in the logs (log level = 2):

[2012/11/12 09:23:00,  0]
../source4/rpc_server/common/forward.c:51(dcesrv_irpc_forward_callback)
  IRPC callback failed for DsReplicaSync - NT_STATUS_IO_TIMEOUT
[2012/11/12 09:23:00,  2]
default/librpc/gen_ndr/ndr_drsuapi_s.c:394(drsuapi__op_reply)
  dcerpc_fault WERR_EPT_S_CANT_PERFORM_OP in drsuapi_DsReplicaSync

The same time on the other DC I see repeating messages (as I understand it's trying to replicate, but fails): 

[2012/11/12 09:22:41,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on DC=domain,DC=ru using filter (uSNChanged>=13902)
[2012/11/12 09:22:41,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 13902 flags 0x00000074 on <GUID=81116378-3e99-4d1f-804d-8a8925f3dd55>;<SID=S-1-5-21-530720856-2058831417-1234567890>;DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:42,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on DC=ForestDnsZones,DC=domain,DC=ru using filter (uSNChanged>=5133)
[2012/11/12 09:22:42,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 5133 flags 0x00000074 on <GUID=8296a94f-d92b-4ee5-8687-deebc22b0f92>;DC=ForestDnsZones,DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:42,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on DC=DomainDnsZones,DC=domain,DC=ru using filter (uSNChanged>=5115)
[2012/11/12 09:22:42,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 5115 flags 0x00000074 on <GUID=76fd0afd-cc86-4d23-b7c6-3f9671c244ff>;DC=DomainDnsZones,DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:43,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on DC=domain,DC=ru using filter (uSNChanged>=13902)
[2012/11/12 09:22:43,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 13902 flags 0x00000074 on <GUID=81116378-3e99-4d1f-804d-8a8925f3dd55>;<SID=S-1-5-21-530720856-2058831417-1234567890>;DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:43,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on CN=Schema,CN=Configuration,DC=domain,DC=ru using filter (uSNChanged>=1558)
[2012/11/12 09:22:43,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 1558 flags 0x00000074 on <GUID=affe8535-a031-4a34-8356-7b94cfbe1291>;CN=Schema,CN=Configuration,DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:44,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on CN=Configuration,DC=domain,DC=ru using filter (uSNChanged>=12907)
[2012/11/12 09:22:44,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 12907 flags 0x00000074 on <GUID=76a7c9b6-0b25-48a4-b85f-a9e57c14b0ad>;CN=Configuration,DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:49,  2] ../source4/smbd/process_standard.c:197(standard_terminate)
  standard_terminate: reason[NT_STATUS_END_OF_FILE]
[2012/11/12 09:22:51,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on DC=domain,DC=ru using filter (uSNChanged>=13902)
[2012/11/12 09:22:51,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 13902 flags 0x00000074 on <GUID=81116378-3e99-4d1f-804d-8a8925f3dd55>;<SID=S-1-5-21-530720856-2058831417-1234567890>;DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:52,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on DC=ForestDnsZones,DC=domain,DC=ru using filter (uSNChanged>=5133)
[2012/11/12 09:22:52,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 5133 flags 0x00000074 on <GUID=8296a94f-d92b-4ee5-8687-deebc22b0f92>;DC=ForestDnsZones,DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:52,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on DC=DomainDnsZones,DC=domain,DC=ru using filter (uSNChanged>=5115)
[2012/11/12 09:22:52,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 5115 flags 0x00000074 on <GUID=76fd0afd-cc86-4d23-b7c6-3f9671c244ff>;DC=DomainDnsZones,DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:53,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on DC=domain,DC=ru using filter (uSNChanged>=13902)
[2012/11/12 09:22:53,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 13902 flags 0x00000074 on <GUID=81116378-3e99-4d1f-804d-8a8925f3dd55>;<SID=S-1-5-21-530720856-2058831417-1234567890>;DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:53,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on CN=Schema,CN=Configuration,DC=domain,DC=ru using filter (uSNChanged>=1558)
[2012/11/12 09:22:54,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 1558 flags 0x00000074 on <GUID=affe8535-a031-4a34-8356-7b94cfbe1291>;CN=Schema,CN=Configuration,DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:22:54,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on CN=Configuration,DC=domain,DC=ru using filter (uSNChanged>=12907)
[2012/11/12 09:22:54,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 12907 flags 0x00000074 on <GUID=76a7c9b6-0b25-48a4-b85f-a9e57c14b0ad>;CN=Configuration,DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:23:00,  2] ../source4/smbd/process_standard.c:197(standard_terminate)
  standard_terminate: reason[NT_STATUS_END_OF_FILE]
[2012/11/12 09:23:01,  2] ../source4/rpc_server/drsuapi/getncchanges.c:1395(getncchanges_collect_objects)
  ../source4/rpc_server/drsuapi/getncchanges.c:1395: getncchanges on DC=domain,DC=ru using filter (uSNChanged>=13902)
[2012/11/12 09:23:01,  2] ../source4/rpc_server/drsuapi/getncchanges.c:2007(dcesrv_drsuapi_DsGetNCChanges)
  DsGetNCChanges with uSNChanged >= 13902 flags 0x00000074 on <GUID=81116378-3e99-4d1f-804d-8a8925f3dd55>;<SID=S-1-5-21-530720856-2058831417-1234567890>;DC=domain,DC=ru gave 0 objects (done 0/0) 0 links (done 0/0 (as S-1-5-21-530720856-2058831417-1234567890-7087))
[2012/11/12 09:23:02,  2] ../source4/smbd/process_standard.c:197(standard_terminate)
  standard_terminate: reason[NT_STATUS_END_OF_FILE]


And it's repeating until I restart samba on the first DC (I have a cronjob for this on both
DCs as a dirty workaround). After restarting all is ok, until something
(don't know what exactly) is changed in the directory again.
samba-tool dbcheck doesn't find anything wrong.

What additional info could help here? Because of the restarting - this
issue is really critical for us, I'll be glad if you help me with this.

# samba --version
Version 4.1.0pre1-GIT-50d47fc

# uname -a
Linux dc0 3.2.0-32-generic #51-Ubuntu SMP Wed Sep 26 21:33:09 UTC 2012
x86_64 x86_64 x86_64 GNU/Linux