The nightly test test_winsyncmigrate.py::TestWinsyncMigrate is failing while establishing a winsync replication agreement, when the updates-testing repository is enabled. See PR #1389 with the following logs and report:
test_winsyncmigrate.py::TestWinsyncMigrate
cls = <class 'ipatests.test_integration.test_winsyncmigrate.TestWinsyncMigrate'> mh = <pytest_multihost.plugin.MultihostFixture object at 0x7ff434c6d180> @classmethod def install(cls, mh): super(TestWinsyncMigrate, cls).install(mh) cls.ad = cls.ads[0] cls.trust_test_user = '%s@%s' % (cls.ad_user, cls.ad.domain.name) tasks.configure_dns_for_trust(cls.master, cls.ad) tasks.install_adtrust(cls.master) cls.create_test_objects() > establish_winsync_agreement(cls.master, cls.ad) test_integration/test_winsyncmigrate.py:82: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ test_integration/test_winsyncmigrate.py:38: in establish_winsync_agreement master.run_command([ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = <ipatests.pytest_ipa.integration.host.Host master.ipa.test (master)> argv = ['ipa-replica-manage', 'connect', '--winsync', '--binddn', 'cn=Administrator,cn=users,dc=ad,dc=test', '--bindpw', ...] set_env = True, stdin_text = None, log_stdout = True, raiseonerr = True cwd = None, bg = False, encoding = 'utf-8', ok_returncode = 0 def run_command(self, argv, set_env=True, stdin_text=None, log_stdout=True, raiseonerr=True, cwd=None, bg=False, encoding='utf-8', ok_returncode=0): """Wrapper around run_command to log stderr on raiseonerr=True :param ok_returncode: return code considered to be correct, you can pass an integer or sequence of integers """ result = super().run_command( argv, set_env=set_env, stdin_text=stdin_text, log_stdout=log_stdout, raiseonerr=False, cwd=cwd, bg=bg, encoding=encoding ) # in FIPS mode SSH may print noise to stderr, remove the string # "FIPS mode initialized" + optional newline. result.stderr_bytes = FIPS_NOISE_RE.sub(b'', result.stderr_bytes) try: result_ok = result.returncode in ok_returncode except TypeError: result_ok = result.returncode == ok_returncode if not result_ok and raiseonerr: result.log.error('stderr: %s', result.stderr_text) > raise subprocess.CalledProcessError( result.returncode, argv, result.stdout_text, result.stderr_text ) E subprocess.CalledProcessError: Command '['ipa-replica-manage', 'connect', '--winsync', '--binddn', 'cn=Administrator,cn=users,dc=ad,dc=test', '--bindpw', 'Secret123', '--password', 'Secret.123', '--cacert', '/tmp/tmp.TpQiL0PavA', '--passsync', 'dummy', 'ad-root.ad.test', '-v']' returned non-zero exit status 1.
Output of the command:
DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:513 RUN ['ipa-replica-manage', 'connect', '--winsync', '--binddn', 'cn=Administrator,cn=users,dc=ad,dc=test', '--bindpw', 'Secret123', '--password', 'Secret.123', '--cacert', '/tmp/tmp.TpQiL0PavA', '--passsync', 'dummy', 'ad-root.ad.test', '-v'] DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 ipa: INFO: AD Suffix is: DC=ad,DC=test DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 Added CA certificate /tmp/tmp.TpQiL0PavA to certificate database for master.ipa.test DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 The user for the Windows PassSync service is uid=passsync,cn=sysaccounts,cn=etc,dc=ipa,dc=test DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 Adding Windows PassSync system account DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 Traceback (most recent call last): DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib/python3.10/site-packages/ipapython/ipaldap.py", line 1090, in error_handler DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 yield DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib/python3.10/site-packages/ipapython/ipaldap.py", line 1662, in add_entry DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 self.conn.add_s(str(entry.dn), list(attrs.items())) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib64/python3.10/site-packages/ldap/ldapobject.py", line 439, in add_s DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 return self.add_ext_s(dn,modlist,None,None) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib64/python3.10/site-packages/ldap/ldapobject.py", line 425, in add_ext_s DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 resp_type, resp_data, resp_msgid, resp_ctrls = self.result3(msgid,all=1,timeout=self.timeout) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib64/python3.10/site-packages/ldap/ldapobject.py", line 764, in result3 DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 resp_type, resp_data, resp_msgid, decoded_resp_ctrls, retoid, retval = self.result4( DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib64/python3.10/site-packages/ldap/ldapobject.py", line 774, in result4 DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib64/python3.10/site-packages/ldap/ldapobject.py", line 340, in _ldap_call DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 reraise(exc_type, exc_value, exc_traceback) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib64/python3.10/site-packages/ldap/compat.py", line 46, in reraise DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 raise exc_value DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib64/python3.10/site-packages/ldap/ldapobject.py", line 324, in _ldap_call DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 result = func(*args,**kwargs) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 ldap.UNWILLING_TO_PERFORM: {'msgtype': 105, 'msgid': 18, 'result': 53, 'desc': 'Server is unwilling to perform', 'ctrls': []} DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 During handling of the above exception, another exception occurred: DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 Traceback (most recent call last): DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/sbin/ipa-replica-manage", line 1613, in <module> DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 main(options, args) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/sbin/ipa-replica-manage", line 1570, in main DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 add_link(realm, replica1, replica2, dirman_passwd, options) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/sbin/ipa-replica-manage", line 1143, in add_link DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 repl1.setup_winsync_replication(replica2, DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib/python3.10/site-packages/ipaserver/install/replication.py", line 1349, in setup_winsync_replication DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 self.setup_agreement(self.conn, ad_dc_name, DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib/python3.10/site-packages/ipaserver/install/replication.py", line 888, in setup_agreement DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 a_conn.add_entry(entry) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib/python3.10/site-packages/ipapython/ipaldap.py", line 1660, in add_entry DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 with self.error_handler(): DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib64/python3.10/contextlib.py", line 153, in __exit__ DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 self.gen.throw(typ, value, traceback) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 File "/usr/lib/python3.10/site-packages/ipapython/ipaldap.py", line 1152, in error_handler DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 raise errors.DatabaseError(desc=desc, info=info) DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 ipalib.errors.DatabaseError: Server is unwilling to perform: DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:557 Unexpected error: Server is unwilling to perform: DEBUG ipatests.pytest_ipa.integration.host.Host.master.cmd90:transport.py:217 Exit code: 1 ERROR ipatests.pytest_ipa.integration.host.Host.master.cmd90:host.py:201 stderr: ipa: INFO: AD Suffix is: DC=ad,DC=test
The directory server returns error=53 (unwilling to perform) on the operation adding the windows replication agreement:
[22/Dec/2021:14:54:50.313481432 +0000] conn=4 op=17 ADD dn="cn=meToad-root.ad.test,cn=replica,cn=dc\3Dipa\2Cdc\3Dtest,cn=mapping tree,cn=config" [22/Dec/2021:14:54:50.321542434 +0000] conn=4 op=17 RESULT err=53 tag=105 nentries=0 wtime=0.000367177 optime=0.008066724 etime=0.008430591
Dirsrv error log contains the following:
[22/Dec/2021:14:54:50.316125333 +0000] - ERR - NSMMReplicationPlugin - agmt_new_from_entry: failed to initialise windows replicationagreement "agmt="cn=meToad-root.ad.test" (ad-root:389)" - replica is not a supplier (may be hub or consumer). [22/Dec/2021:14:54:50.317510539 +0000] - ERR - NSMMReplicationPlugin - To proceed, you MUST promote this server to a supplier with: dsconf INSTANCENAME replication promote --suffix "dc=ipa,dc=test" --newrole supplier --replica-id=NEW_REPLICA_ID [22/Dec/2021:14:54:50.318917730 +0000] - ERR - NSMMReplicationPlugin - agmt_new_from_entry - Failed to parse agreement, skipping. [22/Dec/2021:14:54:50.319904477 +0000] - ERR - NSMMReplicationPlugin - agmtlist_add_callback - Can't start agreement "cn=meToad-root.ad.test,cn=replica,cn=dc\3Dipa\2Cdc\3Dtest,cn=mapping tree,cn=config" [22/Dec/2021:14:54:50.324904645 +0000] - ERR - ipa_sidgen_add_post_op - [file ipa_sidgen.c, line 128]: Missing target entry.
The regression seems to be introduced with 389-ds-base-2.0.12-1.fc35.
Companion issue on 389-ds-base side: https://github.com/389ds/389-ds-base/issues/5079
The issue has been fixed in 389-ds master branch, 389-ds 2.0 branch and 389-ds 1.4.4 branch. PRCI will run the test next week-end using the copr repo @389ds/389-ds-base-nightly and we'll be able to confirm whether the issue is fixed.
test failure seen in testing_master_latest PR 1440 report
testing_master_latest
Also present in [testing_master_previous] Nightly PR #1438 report
test failure seen in testing_master_testing_selinux PR 1452 report
test faliure seen in testing_master_latest PR 1456 Report
test faliure seen in testing_master_latest_selinux PR 1463 Report
test failure seen in testing_master_latest_selinux PR report
test failure seen in testing_master_latest PR 1471 Report
test failure seen in testing_master_latest PR 1479 Report
test failure seen in testing_master_latest PR 1487 Report
test failure seen in testing_master_latest PR 1495 Report
master:
ipa-4-9:
Metadata Update from @frenaud: - Issue close_status updated to: fixed - Issue status updated to: Closed (was: Open)