#9658 Nightly test failure in test_ipa_ipa_migration.py
Closed: fixed by frenaud. Opened by frenaud.

The nightly test test_ipa_ipa_migration.py is failing since commit 7808fc8 ipa-migrate - fix migration issues with entries using ipaUniqueId in the RDN

Example of run in PR #3960 with the following logs and report:

self = <ipatests.test_integration.test_ipa_ipa_migration.TestIPAMigrateScenario1 object at 0x7f9aa6bc9910>
empty_log_file = None
    def test_ipa_migrate_prod_mode_dry_run(self, empty_log_file):
        """
        Test ipa-migrate prod mode with dry run option
        """
        tasks.kinit_admin(self.master)
        tasks.kinit_admin(self.replicas[0])
        IPA_MIGRATE_PROD_DRY_RUN_LOG = "--dryrun=True\n"
        IPA_SERVER_UPRGADE_LOG = (
            "Skipping ipa-server-upgrade in dryrun mode.\n"
        )
        IPA_SIDGEN_LOG = "Skipping SIDGEN task in dryrun mode.\n"
        result = run_migrate(
            self.replicas[0],
            "prod-mode",
            self.master.hostname,
            "cn=Directory Manager",
            self.master.config.admin_password,
            extra_args=['-x'],
        )
        install_msg = self.replicas[0].get_file_contents(
            paths.IPA_MIGRATE_LOG, encoding="utf-8"
        )
>       assert result.returncode == 0
E       assert 1 == 0
E        +  where 1 = <pytest_multihost.transport.SSHCommand object at 0x7f9aa67f5b50>.returncode
test_integration/test_ipa_ipa_migration.py:506: AssertionError
------------------------------ Captured log setup ------------------------------
INFO     ipatests.pytest_ipa.integration.host.Host.replica0.IPAOpenSSHTransport:transport.py:391 RUN ['truncate', '-s', '0', '/var/log/ipa-migrate.log']
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd123:transport.py:513 RUN ['truncate', '-s', '0', '/var/log/ipa-migrate.log']
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd123:transport.py:217 Exit code: 0
------------------------------ Captured log call -------------------------------
INFO     ipatests.pytest_ipa.integration.host.Host.master.IPAOpenSSHTransport:transport.py:391 RUN ['kinit', 'admin']
DEBUG    ipatests.pytest_ipa.integration.host.Host.master.cmd154:transport.py:513 RUN ['kinit', 'admin']
DEBUG    ipatests.pytest_ipa.integration.host.Host.master.cmd154:transport.py:557 Password for admin@IPA.TEST: 
DEBUG    ipatests.pytest_ipa.integration.host.Host.master.cmd154:transport.py:217 Exit code: 0
INFO     ipatests.pytest_ipa.integration.host.Host.replica0.IPAOpenSSHTransport:transport.py:391 RUN ['kinit', 'admin']
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd124:transport.py:513 RUN ['kinit', 'admin']
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd124:transport.py:557 Password for admin@IPA.TEST: 
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd124:transport.py:217 Exit code: 0
INFO     ipatests.pytest_ipa.integration.host.Host.replica0.IPAOpenSSHTransport:transport.py:391 RUN ['ipa-migrate', 'prod-mode', 'master.ipa.test', '-D', 'cn=Directory Manager', '-w', 'Secret.123', '-x']
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:513 RUN ['ipa-migrate', 'prod-mode', 'master.ipa.test', '-D', 'cn=Directory Manager', '-w', 'Secret.123', '-x']
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 IPA to IPA migration starting ...
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 Migrating schema ...
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 Migrating configuration ...
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 Migrating database ... (this may take a while)
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 Initializing ...
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 Connecting to local server ...
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 Traceback (most recent call last):
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipapython/ipaldap.py", line 1096, in error_handler
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     yield
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipapython/ipaldap.py", line 1608, in find_entries
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     raise e
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipapython/ipaldap.py", line 1562, in find_entries
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     id = self.conn.search_ext(
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557          ^^^^^^^^^^^^^^^^^^^^^
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib64/python3.12/site-packages/ldap/ldapobject.py", line 614, in search_ext
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     return self._ldap_call(
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557            ^^^^^^^^^^^^^^^^
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib64/python3.12/site-packages/ldap/ldapobject.py", line 128, in _ldap_call
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     result = func(*args,**kwargs)
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557              ^^^^^^^^^^^^^^^^^^^^
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 ldap.FILTER_ERROR: {'result': -7, 'desc': 'Bad search filter', 'ctrls': [], 'matched': 'cn=views,cn=accounts,dc=ipa,dc=test'}
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 During handling of the above exception, another exception occurred:
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 Traceback (most recent call last):
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/sbin/ipa-migrate", line 10, in <module>
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     ipa_migrate.run()
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipaserver/install/ipa_migrate.py", line 2147, in run
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     self.do_migration()
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipaserver/install/ipa_migrate.py", line 2034, in do_migration
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     self.migrateDB()
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipaserver/install/ipa_migrate.py", line 1672, in migrateDB
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     self.processDBOnline()
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipaserver/install/ipa_migrate.py", line 1639, in processDBOnline
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     self.process_db_entry(entry_dn, entry_attrs)
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipaserver/install/ipa_migrate.py", line 1499, in process_db_entry
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     entries = self.local_conn.get_entries(DN(srch_base),
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipapython/ipaldap.py", line 1474, in get_entries
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     entries, truncated = self.find_entries(
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557                          ^^^^^^^^^^^^^^^^^^
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipapython/ipaldap.py", line 1548, in find_entries
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     with self.error_handler():
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib64/python3.12/contextlib.py", line 158, in __exit__
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     self.gen.throw(value)
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557   File "/usr/lib/python3.12/site-packages/ipapython/ipaldap.py", line 1145, in error_handler
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557     raise errors.BadSearchFilter(info=info)
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:557 ipalib.errors.BadSearchFilter: Bad search filter 
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd125:transport.py:217 Exit code: 1
INFO     ipatests.pytest_ipa.integration.host.Host.replica0.IPAOpenSSHTransport:transport.py:436 GET /var/log/ipa-migrate.log
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd126:transport.py:513 RUN ['cat', '/var/log/ipa-migrate.log']
DEBUG    ipatests.pytest_ipa.integration.host.Host.replica0.cmd126:transport.py:217 Exit code: 0

The migration is failing on the following entry:

(Pdb) entry_dn
'ipauniqueid=4156520c-3013-4886-aad9-abe8c3f4f1b0,cn=subids,cn=accounts,dc=ipa,dc=test'
(Pdb) entry_attrs
{'ipaOwner': ['uid=testuser1,cn=users,cn=accounts,dc=ipa,dc=test'], 'ipaUniqueID': ['4156520c-3013-4886-aad9-abe8c3f4f1b0'], 'description': ['auto-assigned subid'], 'ipaSubUidCount': ['65536'], 'ipaSubGidCount': ['65536'], 'ipaSubUidNumber': ['2147483648'], 'ipaSubGidNumber': ['2147483648'], 'objectClass': ['ipasubordinateidentry', 'ipasubordinateid', 'ipasubordinategid', 'ipasubordinateuid', 'top']}

The initial value for srch_filter:

'ipaOwner=uid=testuser1,cn=users,cn=accounts,dc=ipa,dc=test'

After a call to srch_filter = self.replace_suffix(srch_filter):

'ipaOwner=uid\\=testuser1,cn=users,cn=accounts,dc=ipa,dc=test'

Metadata Update from @frenaud:
- Issue assigned to mreynolds

I could not reproduce this issue.

Before:

ipaOwner=uid=mreynolds,cn=users,cn=accounts,dc=bkr,dc=lab,dc=eng,dc=rdu2,dc=dc,dc=redhat,dc=com

after:

ipaOwner=uid=mreynolds,cn=users,cn=accounts,dc=bkr,dc=lab,dc=eng,dc=rdu2,dc=dc,dc=redhat,dc=com

But I wrote a fix that should prevent any kind of "normalization" from happening:

https://github.com/freeipa/freeipa/pull/7525

master:

  • b98b4a886ee0a75c7cf2c1650e4a0c8a699ac808 ipa-migrate - fix alternate entry search filter

ipa-4-12:

  • 3b5a980f5b65b03b9fd7ad0cfbb6c87874d3ff24 ipa-migrate - fix alternate entry search filter

Metadata Update from @frenaud:
- Issue close_status updated to: fixed
- Issue status updated to: Closed (was: Open)

Metadata