Hello, I've encountered several issues while installing freeipa replica.
I have freeipa 4.6.8 master and the replica I tried installing is 4.9.12.
During the replica install it seems that the replica is unable to get a CA cert from my master:
DEBUG Configuring Kerberos KDC (krb5kdc) DEBUG [1/1]: installing X509 Certificate for PKINIT DEBUG flushing ldapi://%2Frun%2Fslapd-[REDACTED].socket from SchemaCache DEBUG retrieving schema for SchemaCache url=ldapi://%2Frun%2Fslapd-[REDACTED].socket conn=<ldap.ldapobject.SimpleLDAPObject object at 0x7f6ac1b7d6d8> DEBUG certmonger request is in state 'NEWLY_ADDED_READING_KEYINFO' DEBUG certmonger request is in state 'SUBMITTING' DEBUG certmonger request is in state 'CA_UNREACHABLE' DEBUG Cert request 20240312144851 failed: CA_UNREACHABLE (Server at https://%5BREDACTED%5D/ipa/json failed request, will retry: 903 (an internal error has occurred).) DEBUG Giving up on cert request 20240312144851 WARNING PKINIT certificate request failed: Certificate issuance failed (CA_UNREACHABLE: Server at https://%5BREDACTED%5D/ipa/json failed request, will retry: 903 (an internal error has occurred).) WARNING Failed to configure PKINIT DEBUG Full PKINIT configuration did not succeed DEBUG The setup will only install bits essential to the server functionality DEBUG You can enable PKINIT after the setup completed using 'ipa-pkinit-manage' DEBUG certmonger request is in state 'GENERATING_CSR' DEBUG certmonger request is in state 'MONITORING' DEBUG Cert request 20240312144853 was successful DEBUG step duration: krb5kdc setup_pkinit 2.72 sec DEBUG Done configuring Kerberos KDC (krb5kdc).
(However the the installation succeeds with INFO The ipa-replica-install command was successful)
On master in /var/log/httpd/error_log:
ipa: ERROR: non-public: AttributeError: 'ldap2' object has no attribute 'Object' Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 369, in wsgi_execute result = command(*args, **options) File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 450, in __call__ return self.__do_call(*args, **options) File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 478, in __do_call ret = self.run(*args, **options) File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 800, in run return self.execute(*args, **options) File "/usr/lib/python2.7/site-packages/ipaserver/plugins/cert.py", line 863, in execute ca_kdc_check(ldap, alt_principal.hostname) File "/usr/lib/python2.7/site-packages/ipaserver/plugins/cert.py", line 301, in ca_kdc_check master_dn = api_instance.Object.server.get_dn(unicode(hostname)) AttributeError: 'ldap2' object has no attribute 'Object' ipa: INFO: [jsonserver_kerb] host/ipa-replica01.[REDACTED]@[REDACTED]: cert_request(u'MIID3DCCAsQCAQAwQjEZMBcGA1UECgwQRkxPUkEuTFRGUy5UT09MUzElMCMGA1UEAxMcaXBhLXNsYXZlMDEuZmxvcmEubHRmcy50b29sczCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBANhiTu7x/3sRCBq0spuBM1M2dkAzfMFEtJRx/BUcDi7PrRhJBa+w2o+XfOjtP9YFYpnOYbqV6eNlslGuYbHYIZX5D4lawvcT+IfqBaeWAz3ZRyK+nFVotMm+BRHNeUFse3OUL2kGPLRgXZQ1wdzE+V17rTRtPHDV9cs0ERjTjMyntM24zYxWicrdsoFfwF/BJQRXVO+GZDdhJcmNvCcxywaUD8C/y9TYYLwhFdIRYFmOHvTHJwabPt5/QM8EkrAfkpCHypwf6oz7xvyiqnRFyx5okWexHqE1xXHbvMS+pjd2eNBl4n38H+hbdb83wJFS64M9zerlhU/u5h4cbY0WdIJtOz2dP7A3NvQL0X5oF10ivWYw5+Rbar8h6nCr07ApVku6m5kXePp6rK3c0f+IORxflJFEdRGBG7zBbE1Dt4Kf5Q+uTwiEjN2wEre1s6CFg8oTipncOwHkyettAplFisitfdxs4HlEZpsN3kxh6NQDFAhx4JE1WNGMPVZNKuBz6tHhMwgpDDXS16UjIXZqYllUDnBaf5GdawCgWr2wbXEaUflgOWje/QyvZkYVsHZzUFw9Bqh8B7jxw7h/4KAM43XBDWN9P6J2+gqp2M3SQ=', profile_id=u'KDCs_PKINIT_Certs', principal=u'krbtgt/[REDACTED]@[REDACTED]', add=True): InternalError
That's the issue number one. Number two is that I can't login into web UI of my replica - it gives me "Login failed due to an unknown reason" error. From /var/log/httpd/error_log:
[auth_gssapi:error] GSS ERROR gss_acquire_cred[_from]() failed to get server creds: [Unspecified GSS failure. Minor code may provide more information ( SPNEGO cannot find mechanisms to negotiate)] [wsgi:error] ipa: INFO: 401 Unauthorized: No session cookie found
Finally, my third issue is that I can't remove replica from my master. ipa-replica-manage del --force --cleanup fails with:
Traceback (most recent call last): File "/usr/sbin/ipa-replica-manage", line 1624, in <module> main(options, args) File "/usr/sbin/ipa-replica-manage", line 1524, in main api.finalize() File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 740, in finalize self.__do_if_not_done('load_plugins') File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 431, in __do_if_not_done getattr(self, name)() File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 620, in load_plugins self.add_package(package) File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 658, in add_package self.add_module(module) File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 675, in add_module self.add_plugin(**kwargs) File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 711, in add_plugin plugin=plugin, PluginOverrideError: unexpected override of BaseCertObject.certreq with <class 'ipaserver.plugins.cert.certreq'> Unexpected error: unexpected override of BaseCertObject.certreq with <class 'ipaserver.plugins.cert.certreq'>
D S via FreeIPA-users wrote:
Hello, I've encountered several issues while installing freeipa replica.
I have freeipa 4.6.8 master and the replica I tried installing is 4.9.12.
Rather than focusing on the versions, what OS release are you using? There are known crypto incompatibilities between RHEL 7 and RHEL 9, for example, such that you can't go directly between them.
During the replica install it seems that the replica is unable to get a CA cert from my master:
DEBUG Configuring Kerberos KDC (krb5kdc) DEBUG [1/1]: installing X509 Certificate for PKINIT DEBUG flushing ldapi://%2Frun%2Fslapd-[REDACTED].socket from SchemaCache DEBUG retrieving schema for SchemaCache url=ldapi://%2Frun%2Fslapd-[REDACTED].socket conn=<ldap.ldapobject.SimpleLDAPObject object at 0x7f6ac1b7d6d8> DEBUG certmonger request is in state 'NEWLY_ADDED_READING_KEYINFO' DEBUG certmonger request is in state 'SUBMITTING' DEBUG certmonger request is in state 'CA_UNREACHABLE' DEBUG Cert request 20240312144851 failed: CA_UNREACHABLE (Server at https://%5BREDACTED%5D/ipa/json failed request, will retry: 903 (an internal error has occurred).) DEBUG Giving up on cert request 20240312144851 WARNING PKINIT certificate request failed: Certificate issuance failed (CA_UNREACHABLE: Server at https://%5BREDACTED%5D/ipa/json failed request, will retry: 903 (an internal error has occurred).) WARNING Failed to configure PKINIT DEBUG Full PKINIT configuration did not succeed DEBUG The setup will only install bits essential to the server functionality DEBUG You can enable PKINIT after the setup completed using 'ipa-pkinit-manage' DEBUG certmonger request is in state 'GENERATING_CSR' DEBUG certmonger request is in state 'MONITORING' DEBUG Cert request 20240312144853 was successful DEBUG step duration: krb5kdc setup_pkinit 2.72 sec DEBUG Done configuring Kerberos KDC (krb5kdc).
(However the the installation succeeds with INFO The ipa-replica-install command was successful)
A failed PKINIT cert request is not considered fatal because a self-signed one is issued in this case. I'd also look in the journal for certmonger to see if it logged additional info about the request.
On master in /var/log/httpd/error_log:
ipa: ERROR: non-public: AttributeError: 'ldap2' object has no attribute 'Object' Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 369, in wsgi_execute result = command(*args, **options) File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 450, in __call__ return self.__do_call(*args, **options) File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 478, in __do_call ret = self.run(*args, **options) File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 800, in run return self.execute(*args, **options) File "/usr/lib/python2.7/site-packages/ipaserver/plugins/cert.py", line 863, in execute ca_kdc_check(ldap, alt_principal.hostname) File "/usr/lib/python2.7/site-packages/ipaserver/plugins/cert.py", line 301, in ca_kdc_check master_dn = api_instance.Object.server.get_dn(unicode(hostname)) AttributeError: 'ldap2' object has no attribute 'Object' ipa: INFO: [jsonserver_kerb] host/ipa-replica01.[REDACTED]@[REDACTED]: cert_request(u'MIID3DCCAsQCAQAwQjEZMBcGA1UECgwQRkxPUkEuTFRGUy5UT09MUzElMCMGA1UEAxMcaXBhLXNsYXZlMDEuZmxvcmEubHRmcy50b29sczCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBANhiTu7x/3sRCBq0spuBM1M2dkAzfMFEtJRx/BUcDi7PrRhJBa+w2o+XfOjtP9YFYpnOYbqV6eNlslGuYbHYIZX5D4lawvcT+IfqBaeWAz3ZRyK+nFVotMm+BRHNeUFse3OUL2kGPLRgXZQ1wdzE+V17rTRtPHDV9cs0ERjTjMyntM24zYxWicrdsoFfwF/BJQRXVO+GZDdhJcmNvCcxywaUD8C/y9TYYLwhFdIRYFmOHvTHJwabPt5/QM8EkrAfkpCHypwf6oz7xvyiqnRFyx5okWexHqE1xXHbvMS+pjd2eNBl4n38H+hbdb83wJFS64M9zerlhU/u5h4cbY0WdIJtOz2dP7A3NvQL0X5oF10ivWYw5+Rbar8h6nCr07ApVku6m5kXePp6rK3c0f+IORxflJFEdRGBG7zBbE1Dt4Kf5Q+uTwiEjN2wEre1s6CFg8oTipncOwHkyettAplFisitfdxs4HlEZpsN3kxh6NQDFAhx4JE1WNGMPVZNKuBz6tHhMwgpDDXS16UjIXZqYllUDnBaf5GdawCgWr2wbXEaUflgOWje/QyvZkYVsHZzUFw9Bqh8B7jxw7h/4KAM43XBDWN9P6J2+gqp2M3SQ=', profile_id=u'KDCs_PKINIT_Certs', principal=u'krbtgt/[REDACTED]@[REDACTED]', add=True): InternalError
That's the issue number one. Number two is that I can't login into web UI of my replica - it gives me "Login failed due to an unknown reason" error. From /var/log/httpd/error_log:
[auth_gssapi:error] GSS ERROR gss_acquire_cred[_from]() failed to get server creds: [Unspecified GSS failure. Minor code may provide more information ( SPNEGO cannot find mechanisms to negotiate)] [wsgi:error] ipa: INFO: 401 Unauthorized: No session cookie found
Newer IPA requires that every user have a SID. I'm guessing this is related.
Finally, my third issue is that I can't remove replica from my master. ipa-replica-manage del --force --cleanup fails with:
Traceback (most recent call last): File "/usr/sbin/ipa-replica-manage", line 1624, in <module> main(options, args) File "/usr/sbin/ipa-replica-manage", line 1524, in main api.finalize() File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 740, in finalize self.__do_if_not_done('load_plugins') File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 431, in __do_if_not_done getattr(self, name)() File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 620, in load_plugins self.add_package(package) File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 658, in add_package self.add_module(module) File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 675, in add_module self.add_plugin(**kwargs) File "/usr/lib/python2.7/site-packages/ipalib/plugable.py", line 711, in add_plugin plugin=plugin, PluginOverrideError: unexpected override of BaseCertObject.certreq with <class 'ipaserver.plugins.cert.certreq'> Unexpected error: unexpected override of BaseCertObject.certreq with <class 'ipaserver.plugins.cert.certreq'>
This and the previous ldap2.Object error point to a coding issue. Did you make any plugin changes?
rob
Hi Rob, Thanks for your reply.
what OS release are you using?
My master is running in docker container with freeipa-server:centos-7-4.6.8 and replica is freeipa-server:almalinux-8-4.9.12.
I'd also look in the journal for certmonger to see if it logged additional info about the request.
Here is all I can find in journalctl about that particular request
Mar 12 14:48:50 replica.example.com systemd[1]: Started The Apache HTTP Server. Mar 12 14:48:50 replica.example.com httpd[3413]: Server configured, listening on: port 443, port 80 Mar 12 14:48:50 replica.example.com platform-python[299]: GSSAPI client step 1 Mar 12 14:48:50 replica.example.com platform-python[299]: GSSAPI client step 1 Mar 12 14:48:50 replica.example.com platform-python[299]: GSSAPI client step 1 Mar 12 14:48:50 replica.example.com platform-python[299]: GSSAPI client step 2 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[3685]: 2024-03-12 14:48:51 [3685] error:0D06407A:asn1 encoding routines:a2d_ASN1_OBJECT:first num too large Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_REQ_SUBJECT" to "O=EXAMPLE.COM,cn=replica.example.com" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_REQ_HOSTNAME" to "replica.example.com" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_REQ_PRINCIPAL" to "krbtgt/EXAMPLE.COM@EXAMPLE.COM" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_OPERATION" to "SUBMIT" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_CSR" to "-----BEGIN CERTIFICATE REQUEST----- Mar 12 14:48:51 replica.example.com certmonger[3686]: MIID3DCCAsQCAQAwQjEZMBcGA1UECgwQRkxPUkEuTFRGUy5UT09MUzElMCMGA1UE Mar 12 14:48:51 replica.example.com certmonger[3686]: AxMcaXBhLXNsYXZlMDEuZmxvcmEubHRmcy50b29sczCCASIwDQYJKoZIhvcNAQEB Mar 12 14:48:51 replica.example.com certmonger[3686]: BQADggEPADCCAQoCggEBAPRUIp5MLhpT5+vBdM3Gxt5IdVBJHlfu6uIfSK3HJcsb Mar 12 14:48:51 replica.example.com certmonger[3686]: rjRdh6jPmo/WTPsnEKVQtBpy6UQVK6CGmjUX3gc+TeZ/XWYFk08Nl+C2QCPYzyp7 Mar 12 14:48:51 replica.example.com certmonger[3686]: 0/RorK2sx0wcUN4LVQTtXalGPpUn+TZgO7w40VqwYRAa/cJt5jGOljE2V7tVpJXF Mar 12 14:48:51 replica.example.com certmonger[3686]: qsE2AaTc+vGl2xwUlgFj0/lAYsJZvv3prnkHk2ZHtuUEhNyc7HfXCjnzkCToj1gm Mar 12 14:48:51 replica.example.com certmonger[3686]: FlQdgGxfmbyAMSWjiz6mRDJq0XJgoAoqSs7u+IOny0v+27jJu2eobPTNPMav2hlo Mar 12 14:48:51 replica.example.com certmonger[3686]: a9bywDusRukfurqNC00i/TH2iuJon1QoOUvPJdrdK70CAwEAAaCCAVMwKwYJKoZI Mar 12 14:48:51 replica.example.com certmonger[3686]: hvcNAQkUMR4eHAAyADAAMgA0ADAAMwAxADIAMQA0ADQAOAA1ADEwggEiBgkqhkiG Mar 12 14:48:51 replica.example.com certmonger[3686]: 9w0BCQ4xggETMIIBDzCBrAYDVR0RBIGkMIGhghxpcGEtc2xhdmUwMS5mbG9yYS5s Mar 12 14:48:51 replica.example.com certmonger[3686]: dGZzLnRvb2xzoDgGCisGAQQBgjcUAgOgKgwoa3JidGd0L0ZMT1JBLkxURlMuVE9P Mar 12 14:48:51 replica.example.com certmonger[3686]: TFNARkxPUkEuTFRGUy5UT09MU6BHBgYrBgEFAgKgPTA7oBIbEEZMT1JBLkxURlMu Mar 12 14:48:51 replica.example.com certmonger[3686]: VE9PTFOhJTAjoAMCAQGhHDAaGwZrcmJ0Z3QbEEZMT1JBLkxURlMuVE9PTFMwDAYD Mar 12 14:48:51 replica.example.com certmonger[3686]: VR0TAQH/BAIwADAdBgNVHQ4EFgQUqt/MlzFeUhqoXqWF/wPkFEQlAQQwMQYJKwYB Mar 12 14:48:51 replica.example.com certmonger[3686]: BAGCNxQCBCQeIgBLAEQAQwBzAF8AUABLAEkATgBJAFQAXwBDAGUAcgB0AHMwDQYJ Mar 12 14:48:51 replica.example.com certmonger[3686]: KoZIhvcNAQELBQADggEBAKjvYfc4LD4+R0ZblIg6COt29K26fNzhC1cj/Nnj76hK Mar 12 14:48:51 replica.example.com certmonger[3686]: ly5i2ITjUnBI1SjvqlV1DqGqAd0TcWaP8DzxTsTbZG47MNg3Mtjx5HjB5uX3XydP Mar 12 14:48:51 replica.example.com certmonger[3686]: 2JEKtWIFTgqB3ZXBBKSAGGwQMYsuMHgfmjb2s3WV4yXooLuv0fTBLMwWnIlT/Pf+ Mar 12 14:48:51 replica.example.com certmonger[3686]: xRuvbREv5t65TEw23/naasR/C0SzxG9LkInJE7WrX7MGqo8SgcUeC/J29jmlSCL/ Mar 12 14:48:51 replica.example.com certmonger[3686]: 9vKEUnIgZkMrqco2KdSgUxMLmqLdfK9t1LpLik8lh1W3WOH7epAz/jmkt7zQqkC8 Mar 12 14:48:51 replica.example.com certmonger[3686]: BHJHpO3WP+MFMJuK1FfW5sMeoEiKulEtGL1NYKnPIZA= Mar 12 14:48:51 replica.example.com certmonger[3686]: -----END CERTIFICATE REQUEST----- Mar 12 14:48:51 replica.example.com certmonger[3686]: " for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_SPKAC" to "MIICQDCCASgwggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQD0VCKeTC4aU+frwXTNxsbeSHVQSR5X7uriH0itxyXLG640XYeoz5qP1kz7JxClULQaculEFSughpo1F94HPk3mf11mBZNPDZfgtkAj2M8qe9P0aKytrMdMHFDeC1UE7V2pRj6VJ/k2YDu8ONFasGEQGv3CbeYxjpYxNle7VaSVxarBNgGk3PrxpdscFJYBY9P5QGLCWb796a55B5NmR7blBITcnOx31wo585Ak6I9YJhZUHYBsX5m8gDElo4s+pkQyatFyYKAKKkrO7viDp8tL/tu4ybtnqGz0zTzGr9oZaGvW8sA7rEbpH7q6jQtNIv0x9oriaJ9UKDlLzyXa3Su9AgMBAAEWADANBgkqhkiG9w0BAQsFAAOCAQEAUrMSI/CB/D2Jx8KIRJORQPt711QUWvURi8MJuQF2VpDxGugKl0Jqbqpl+vgDcrVi8PegIdecCrkXV+Ws0UocMv7ld8zpUAQhLmyqt5QXdoa0UzVqDQQm/TsnspSLK3QKWwscgRsg+8Z737VJp6zh5QrQ+mFbSPPYVOt1LQN6DvTTJ6yqb/Zbk37k1nBm2io1XOD+t9gbHiv/iE9yZXLd44Iscg+gSz9+d4E3gT2wRcfXskiaYd4MOnZDA64OgPNYXgVP99nVsAwjhxtCoe774qHi4920mdzC6XnjrxafPpvBU0o7czyXwAR2biLy9ofgQjn+JAj3Dyg2HvH0LxBo2w==" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_SPKI" to "MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEA9FQinkwuGlPn68F0zcbG3kh1UEkeV+7q4h9IrcclyxuuNF2HqM+aj9ZM+ycQpVC0GnLpRBUroIaaNRfeBz5N5n9dZgWTTw2X4LZAI9jPKnvT9GisrazHTBxQ3gtVBO1dqUY+lSf5NmA7vDjRWrBhEBr9wm3mMY6WMTZXu1WklcWqwTYBpNz68aXbHBSWAWPT+UBiwlm+/emueQeTZke25QSE3Jzsd9cKOfOQJOiPWCYWVB2AbF+ZvIAxJaOLPqZEMmrRcmCgCipKzu74g6fLS/7buMm7Z6hs9M08xq/aGWhr1vLAO6xG6R+6uo0LTSL9MfaK4mifVCg5S88l2t0rvQIDAQAB" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_LOCAL_CA_DIR" to "/var/lib/certmonger/local" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_KEY_TYPE" to "RSA" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_CA_NICKNAME" to "IPA" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Setting "CERTMONGER_CA_PROFILE" to "KDCs_PKINIT_Certs" for child. Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Redirecting stdin to /dev/null, leaving stdout and stderr open for child "/usr/libexec/certmonger/ipa-server-guard". Mar 12 14:48:51 replica.example.com certmonger[3686]: 2024-03-12 14:48:51 [3686] Running enrollment helper "/usr/libexec/certmonger/ipa-server-guard". Mar 12 14:48:51 replica.example.com certmonger[478]: 2024-03-12 14:48:51 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:51 replica.example.com ipa-submit[3687]: JSON-RPC call failed with HTTP status code: 401 Mar 12 14:48:51 replica.example.com ipa-submit[3687]: code = 0, code_text = "No error" Mar 12 14:48:51 replica.example.com ipa-submit[3687]: GSSAPI client step 1 Mar 12 14:48:51 replica.example.com ipa-submit[3687]: GSSAPI client step 1 Mar 12 14:48:51 replica.example.com ipa-submit[3687]: GSSAPI client step 1 Mar 12 14:48:51 replica.example.com ipa-submit[3687]: GSSAPI client step 1 Mar 12 14:48:51 replica.example.com ipa-submit[3687]: GSSAPI client step 2 Mar 12 14:48:52 replica.example.com ipa-submit[3687]: JSON-RPC error: 903: an internal error has occurred Mar 12 14:48:52 replica.example.com certmonger[3686]: Submitting request to "https://replica.example.com/ipa/json". Mar 12 14:48:52 replica.example.com certmonger[3686]: Submitting request to "https://ipamaster01.EXAMPLE.COM/ipa/json". Mar 12 14:48:52 replica.example.com certmonger[478]: 2024-03-12 14:48:52 [478] Certificate submission still ongoing. Mar 12 14:48:52 replica.example.com certmonger[478]: 2024-03-12 14:48:52 [478] Certificate submission attempt complete. Mar 12 14:48:52 replica.example.com certmonger[478]: 2024-03-12 14:48:52 [478] Child status = 3. Mar 12 14:48:52 replica.example.com certmonger[478]: 2024-03-12 14:48:52 [478] Child output: Mar 12 14:48:52 replica.example.com certmonger[478]: "Server at https://ipamaster01.EXAMPLE.COM/ipa/json failed request, will retry: 903 (an internal error has occurred). Mar 12 14:48:52 replica.example.com certmonger[478]: " Mar 12 14:48:52 replica.example.com certmonger[478]: 2024-03-12 14:48:52 [478] Server at https://ipamaster01.EXAMPLE.COM/ipa/json failed request, will retry: 903 (an internal error has occurred). Mar 12 14:48:52 replica.example.com certmonger[478]: 2024-03-12 14:48:52 [478] Certificate not (yet?) issued. Mar 12 14:48:52 replica.example.com certmonger[478]: 2024-03-12 14:48:52 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144851 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[3706]: 2024-03-12 14:48:53 [3706] error:0D06407A:asn1 encoding routines:a2d_ASN1_OBJECT:first num too large Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] No hooks set for pre-save command. Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com /renew_kdc_cert[3711]: restarting krb5kdc Mar 12 14:48:53 replica.example.com systemd[1]: Stopping Kerberos 5 KDC... Mar 12 14:48:53 replica.example.com systemd[1]: krb5kdc.service: Succeeded. Mar 12 14:48:53 replica.example.com systemd[1]: Stopped Kerberos 5 KDC. Mar 12 14:48:53 replica.example.com systemd[1]: Starting Kerberos 5 KDC... Mar 12 14:48:53 replica.example.com systemd[1]: Started Kerberos 5 KDC. Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com certmonger[3721]: Certificate in file "/var/kerberos/krb5kdc/kdc.crt" issued by CA and saved. Mar 12 14:48:53 replica.example.com certmonger[478]: 2024-03-12 14:48:53 [478] Wrote to /var/lib/certmonger/requests/20240312144853 Mar 12 14:48:53 replica.example.com systemd[1]: Stopping Kerberos 5 KDC... Mar 12 14:48:53 replica.example.com systemd[1]: krb5kdc.service: Succeeded. Mar 12 14:48:53 replica.example.com systemd[1]: Stopped Kerberos 5 KDC. Mar 12 14:48:53 replica.example.com systemd[1]: Starting Kerberos 5 KDC... Mar 12 14:48:53 replica.example.com systemd[1]: Started Kerberos 5 KDC. Mar 12 14:48:53 replica.example.com systemd[1]: Stopping 389 Directory Server EXAMPLE-COM.... Mar 12 14:48:53 replica.example.com ns-slapd[3158]: [12/Mar/2024:14:48:53.972895559 +0000] - INFO - op_thread_cleanup - slapd shutting down - signaling operation threads - op stack size 5 max work q size 3 max work q stack size 3 Mar 12 14:48:53 replica.example.com ns-slapd[3158]: [12/Mar/2024:14:48:53.975341242 +0000] - INFO - slapd_daemon - slapd shutting down - closing down internal subsystems and plugins Mar 12 14:48:54 replica.example.com ns-slapd[3158]: [12/Mar/2024:14:48:54.300961794 +0000] - INFO - bdb_pre_close - Waiting for 5 database threads to stop Mar 12 14:48:55 replica.example.com ns-slapd[3158]: [12/Mar/2024:14:48:55.631075995 +0000] - INFO - bdb_pre_close - All database threads now stopped Mar 12 14:48:55 replica.example.com ns-slapd[3158]: [12/Mar/2024:14:48:55.641120041 +0000] - INFO - ldbm_back_instance_set_destructor - Set of instances destroyed Mar 12 14:48:55 replica.example.com ns-slapd[3158]: [12/Mar/2024:14:48:55.643485203 +0000] - INFO - connection_post_shutdown_cleanup - slapd shutting down - freed 3 work q stack objects - freed 7 op stack objects Mar 12 14:48:55 replica.example.com ns-slapd[3158]: [12/Mar/2024:14:48:55.644291920 +0000] - INFO - main - slapd stopped. Mar 12 14:48:55 replica.example.com systemd[1]: dirsrv@EXAMPLE-COM.service: Succeeded. Mar 12 14:48:55 replica.example.com systemd[1]: Stopped 389 Directory Server EXAMPLE-COM.. Mar 12 14:48:55 replica.example.com systemd[1]: Starting 389 Directory Server EXAMPLE-COM.... Mar 12 14:48:55 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:55.998014766 +0000] - NOTICE - config_set_port - Non-Secure Port Disabled Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.042865581 +0000] - INFO - main - 389-Directory/1.4.3.37 B2024.015.1049 starting up Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.043363575 +0000] - INFO - main - Setting the maximum file descriptor limit to: 1024 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.188563525 +0000] - INFO - PBKDF2_SHA256 - Based on CPU performance, chose 2048 rounds Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.190611179 +0000] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.194886774 +0000] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.197854298 +0000] - NOTICE - ldbm_back_start - found 8147288k physical memory Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.198141008 +0000] - NOTICE - ldbm_back_start - found 6240412k available Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.198374407 +0000] - NOTICE - ldbm_back_start - cache autosizing: db cache: 509205k Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.198594412 +0000] - NOTICE - ldbm_back_start - cache autosizing: userRoot entry cache (2 total): 720896k Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.199322666 +0000] - NOTICE - ldbm_back_start - cache autosizing: userRoot dn cache (2 total): 131072k Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.199598164 +0000] - NOTICE - ldbm_back_start - cache autosizing: ipaca entry cache (2 total): 720896k Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.199833184 +0000] - NOTICE - ldbm_back_start - cache autosizing: ipaca dn cache (2 total): 131072k Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.200104091 +0000] - NOTICE - ldbm_back_start - total cache size: 2161971609 B; Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.213824215 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=dns,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.214232545 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=dns,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.214609076 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=keys,cn=sec,cn=dns,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.214857069 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=dns,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.215175624 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=dns,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.215489664 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=groups,cn=compat,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.215840203 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=computers,cn=compat,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.216098774 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=ng,cn=compat,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.216439062 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target ou=sudoers,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.216692141 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=users,cn=compat,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.216966987 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.217209064 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.217479985 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.217745656 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.218009822 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.218272664 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.218522586 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.218787101 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.219061832 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.219345409 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.219622472 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.220541390 +0000] - WARN - NSACLPlugin - acl_parse - The ACL target cn=ad,cn=etc,dc=example,dc=com does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.285040894 +0000] - INFO - slapi_vattrspi_regattr - Because krbPwdPolicyReference is a new registered virtual attribute , nsslapd-ignore-virtual-attrs was set to 'off' Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.288001867 +0000] - ERR - dna-plugin - dna_parse_config_entry - Unable to locate shared configuration entry (cn=subordinate-ids,cn=dna,cn=ipa,cn=etc,dc=example,dc=com) Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.288295481 +0000] - ERR - dna-plugin - dna_parse_config_entry - Invalid config entry [cn=subordinate ids,cn=distributed numeric assignment plugin,cn=plugins,cn=config] skipped Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.311790536 +0000] - INFO - validate_num_config_reservedescriptors - reserve descriptors changed from 64 to 192 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.312109874 +0000] - INFO - connection_table_new - conntablesize:832 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.315247289 +0000] - INFO - slapd_daemon - slapd started. Listening on /run/slapd-EXAMPLE-COM.socket for LDAPI requests Mar 12 14:48:56 replica.example.com systemd[1]: Started 389 Directory Server EXAMPLE-COM.. Mar 12 14:48:56 replica.example.com ns-slapd[3748]: GSSAPI client step 1 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: GSSAPI client step 1 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: GSSAPI client step 1 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: GSSAPI client step 1 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: GSSAPI client step 2 Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.983846414 +0000] - ERR - ipa-topology-plugin - ipa_topo_post_mod - segment to be modified does not exist Mar 12 14:48:56 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:56.988840906 +0000] - ERR - ipa-topology-plugin - ipa_topo_post_mod - segment to be modified does not exist Mar 12 14:48:58 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:58.577334269 +0000] - INFO - bdb_db2index - userRoot: Indexing attribute: ipaidpconfiglink Mar 12 14:48:58 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:58.700532113 +0000] - INFO - bdb_db2index - userRoot: Indexed 1000 entries (24%). Mar 12 14:48:58 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:58.764762073 +0000] - INFO - bdb_db2index - userRoot: Indexed 2000 entries (48%). Mar 12 14:48:58 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:58.803142534 +0000] - INFO - bdb_db2index - userRoot: Indexed 3000 entries (73%). Mar 12 14:48:58 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:58.843639293 +0000] - INFO - bdb_db2index - userRoot: Finished indexing. Mar 12 14:48:59 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:59.617329048 +0000] - ERR - dna-plugin - dna_parse_config_entry - Unable to locate shared configuration entry (cn=subordinate-ids,cn=dna,cn=ipa,cn=etc,dc=example,dc=com) Mar 12 14:48:59 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:59.617781616 +0000] - ERR - dna-plugin - dna_parse_config_entry - Invalid config entry [cn=subordinate ids,cn=distributed numeric assignment plugin,cn=plugins,cn=config] skipped Mar 12 14:48:59 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:59.728526972 +0000] - INFO - memberof-plugin - memberof_fixup_task_thread - Memberof task starts (filter: "(objectclass=*)") ... Mar 12 14:48:59 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:59.862227190 +0000] - INFO - memberof-plugin - memberof_fixup_task_thread - Memberof task starts (filter: "(objectclass=*)") ... Mar 12 14:48:59 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:59.862621703 +0000] - INFO - memberof-plugin - memberof_fixup_task_thread - Memberof task finished (processed 0 entries in 0 seconds) Mar 12 14:48:59 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:48:59.937766136 +0000] - INFO - memberof-plugin - memberof_fixup_task_thread - Memberof task finished (processed 9 entries in 0 seconds) Mar 12 14:49:10 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:49:10.532865828 +0000] - WARN - NSMMReplicationPlugin - repl5_inc_update_from_op_result - agmt="cn=meToipamaster01.EXAMPLE.COM" (ipamaster01:389): Consumer failed to replay change (uniqueid a6dc7cde-e07f11ee-ba71cdae-2496bee9, CSN 65f06b5f003700200000): Operations error (1). Will retry later. Mar 12 14:49:10 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:49:10.533754246 +0000] - WARN - NSMMReplicationPlugin - repl5_inc_update_from_op_result - agmt="cn=meToipamaster01.EXAMPLE.COM" (ipamaster01:389): Consumer failed to replay change (uniqueid a6dc7cdf-e07f11ee-ba71cdae-2496bee9, CSN 65f06b5f003a00200000): Operations error(1). Will retry later. Mar 12 14:49:10 replica.example.com ns-slapd[3748]: [12/Mar/2024:14:49:10.552875462 +0000] - ERR - NSMMReplicationPlugin - release_replica - agmt="cn=meToipamaster01.EXAMPLE.COM" (ipamaster01:389): Unable to send endReplication extended operation (Operations error)
Newer IPA requires that every user have a SID. I'm guessing this is related.
I answered no when replica install prompted me to generate SIDs, but I had to use ldapmodify to add RID base numbers to ID ranges on my master. Otherwise the install wouldn't go through.
Did you make any plugin changes?
No, I tried to apply a few patches manually (I am reluctant to upgrade master, as it is a single point of failure for our company), but I reverted all changes.
Did you make any plugin changes?
Ok, you were right. I managed to fix ipa-replica-manage del command. Apparently, after I restored original .py files I needed to delete .pyc files as well. That fixed the error here.
As for AttributeError: 'ldap2' object has no attribute 'Object' - I applied this https://pagure.io/freeipa/issue/8686 patch since it is supposed to fix the
PKINIT certificate request failed: Certificate issuance failed (CA_UNREACHABLE: Server at >https:///ipa/json failed request, will retry: 903 (an internal error has >occurred).)
error.
And another update. Tried patching the file - still the same issue. Note: line 863 now has ca_kdc_check(self.api instead of ca_kdc_check(ldap [Wed Mar 13 19:07:28.353046 2024] [:error] [pid 13823] File "/usr/lib/python2.7/site-packages/ipaserver/plugins/cert.py", line 863, in execute [Wed Mar 13 19:07:28.353048 2024] [:error] [pid 13823] ca_kdc_check(self.api, alt_principal.hostname) [Wed Mar 13 19:07:28.353051 2024] [:error] [pid 13823] File "/usr/lib/python2.7/site-packages/ipaserver/plugins/cert.py", line 301, in ca_kdc_check [Wed Mar 13 19:07:28.353053 2024] [:error] [pid 13823] master_dn = api_instance.Object.server.get_dn(unicode(hostname)) [Wed Mar 13 19:07:28.353055 2024] [:error] [pid 13823] AttributeError: 'ldap2' object has no attribute 'Object'
D S via FreeIPA-users wrote:
And another update. Tried patching the file - still the same issue. Note: line 863 now has ca_kdc_check(self.api instead of ca_kdc_check(ldap [Wed Mar 13 19:07:28.353046 2024] [:error] [pid 13823] File "/usr/lib/python2.7/site-packages/ipaserver/plugins/cert.py", line 863, in execute [Wed Mar 13 19:07:28.353048 2024] [:error] [pid 13823] ca_kdc_check(self.api, alt_principal.hostname) [Wed Mar 13 19:07:28.353051 2024] [:error] [pid 13823] File "/usr/lib/python2.7/site-packages/ipaserver/plugins/cert.py", line 301, in ca_kdc_check [Wed Mar 13 19:07:28.353053 2024] [:error] [pid 13823] master_dn = api_instance.Object.server.get_dn(unicode(hostname)) [Wed Mar 13 19:07:28.353055 2024] [:error] [pid 13823] AttributeError: 'ldap2' object has no attribute 'Object'
Did you restart httpd after applying the change?
rob
Good call, thank you. Got rid of failed request, will retry: 903 (an internal error has occurred).) However, got this instead:
[28/30]: importing IPA certificate profiles Lookup failed: Preferred host ipa-slave01.flora.ltfs.tools does not provide CA. Lookup failed: Preferred host ipa-slave01.flora.ltfs.tools does not provide CA. Failed to import profile 'acmeIPAServerCert': Request failed with status 500: Non-2xx >response from CA REST API: 500. . Running ipa-server-upgrade when installation is >completed may resolve this issue.
And still unable to login via web UI with the same Login failed due to an unknown reason error. I will dig into the logs for more details.
Here are some kerberos logs:
Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3895](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 172.17.0.2: NEEDED_PREAUTH: WELLKNOWN/ANONYMOUS@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM, Additional pre-authentication required Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3895](info): closing down fd 11 Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3895](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 172.17.0.2: ISSUE: authtime 1710401149, etypes {rep=aes256-cts-hmac-sha384-192(20), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, WELLKNOWN/ANONYMOUS@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3895](info): closing down fd 11 Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3896](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 172.17.0.2: NEEDED_PREAUTH: my.user@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM, Additional pre-authentication required Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3896](info): closing down fd 4 Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3894](info): AS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 172.17.0.2: ISSUE: authtime 1710401149, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, my.user@EXAMPLE.COM for krbtgt/EXAMPLE.COM@EXAMPLE.COM Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3894](info): closing down fd 11 Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3895](info): TGS_REQ (6 etypes {aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), camellia256-cts-cmac(26), camellia128-cts-cmac(25)}) 172.17.0.2: ISSUE: authtime 1710401149, etypes {rep=aes256-cts-hmac-sha1-96(18), tkt=aes256-cts-hmac-sha1-96(18), ses=aes256-cts-hmac-sha1-96(18)}, my.user@EXAMPLE.COM for HTTP/ipa-replica01.example.com@EXAMPLE.COM Mar 14 07:25:49 ipa-replica01.example.com krb5kdc[3895](info): closing down fd 11
All points to the problem being similar to this https://lists.fedoraproject.org/archives/list/freeipa-users@lists.fedorahost.... Namely lack of SIDs due to migration from old freeipa.
I also applied this solution: https://access.redhat.com/solutions/7052703 Since ipa config-mod --enable-sid --add-sids gave me ipa: ERROR: No valid Negotiate header in server response I did python3 /usr/libexec/ipa/oddjob/org.freeipa.server.config-enable-sid --add-sids It was successful as indicated in /var/log/dirsrv/slapd-EXAMPLE-COM/errors
[14/Mar/2024:09:12:39.543473504 +0000] - ERR - sidgen_task_thread - [file ipa_sidgen_task.c, line 194]: Sidgen task starts ... [14/Mar/2024:09:12:41.706166332 +0000] - ERR - sidgen_task_thread - [file ipa_sidgen_task.c, line 199]: Sidgen task finished [0].
However, ipa -d user-find my.user --all | grep -i ipantsecurityidentifier ipa: DEBUG: Loading Index file from '/var/lib/ipa-client/sysrestore/sysrestore.index' ipa: DEBUG: Loading StateFile from '/var/lib/ipa-client/sysrestore/sysrestore.state' ipa: DEBUG: Loading StateFile from '/var/lib/ipa-client/sysrestore/sysrestore.state' ipa: DEBUG: failed to find session_cookie in persistent storage for principal 'my.user@EXAMPLE.COM' ipa: DEBUG: trying https://ipa-replica01.example.com/ipa/json ipa: DEBUG: Created connection context.rpcclient_140556515458128 ipa: DEBUG: [try 1]: Forwarding 'schema' to json server 'https://ipa-replica01.example.com/ipa/json' ipa: DEBUG: New HTTP connection (ipa-replica01.example.com) ipa: DEBUG: HTTP connection destroyed (ipa-replica01.example.com) Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ipaclient/remote_plugins/__init__.py", line 120, in get_package plugins = api._remote_plugins AttributeError: 'API' object has no attribute '_remote_plugins'
During handling of the above exception, another exception occurred:
Traceback (most recent call last): File "/usr/lib/python3.6/site-packages/ipalib/rpc.py", line 724, in single_request if not self._auth_complete(response): File "/usr/lib/python3.6/site-packages/ipalib/rpc.py", line 674, in _auth_complete message=u"No valid Negotiate header in server response") ipalib.errors.KerberosError: No valid Negotiate header in server response ipa: DEBUG: Destroyed connection context.rpcclient_140556515458128 ipa: ERROR: No valid Negotiate header in server response
I added more log info below and also applied this solution to generate SIDs https://access.redhat.com/solutions/7052703 Still unable to login via web UI and every ipa command fails.
Hi,
On Thu, Mar 14, 2024 at 9:50 PM D S via FreeIPA-users < freeipa-users@lists.fedorahosted.org> wrote:
I added more log info below and also applied this solution to generate SIDs https://access.redhat.com/solutions/7052703 Still unable to login via web UI and every ipa command fails.
Did I get it right that the login and commands fail on the replica but everything is working on the master? If that's the case, check on the master if the users contain an ipantsecurityidentifier. The users are replicated and should have the same content on master and replica. You can also check directly in LDAP (either on the master or the replica), for instance for the admin user: ldapsearch -D "cn=directory manager" -W -b uid=admin,cn=users,cn=accounts,dc=example,dc=com ipantsecurityidentifier
flo
--
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to freeipa-users-leave@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahoste... Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
Hi Flo,
Did I get it right that the login and commands fail on the replica but everything is working on the master?
Yes, that is correct.
If that's the case, check on the master if the users contain an ipantsecurityidentifier. The users are replicated and should have the same content on master and replica.
They do now, after I did https://access.redhat.com/solutions/7052703 Still no login.
freeipa-users@lists.fedorahosted.org
-
D S -
Florence Blanc-Renaud -
Rob Crittenden