#8645 upgrade fail with PKI service trying to start before the LDAP service is ready
Closed: invalid 3 years ago by fcami. Opened 3 years ago by fcami.

Ticket was cloned from Red Hat Bugzilla (product Red Hat Enterprise Linux 8): Bug 1911849

Description of problem:

RHEL IPA upgrade failing in

2020-12-29T12:57:17Z INFO [Migrating certificate profiles to LDAP]

in
/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py

this happened when the PKI service was starting before the LDAP service was
ready.
( does not happen a boot time when systemd is used)


possible workaround to test (originally suggested by Francois C.):

duplicate and edit the file
/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py

from the package python3-ipaserver

locate the line
    logger.info('[Migrating certificate profiles to LDAP]')

it is probably around line 413
add
    time.sleep(10)

so the file is changed from
    logger.info('[Migrating certificate profiles to LDAP]')
    cainstance.migrate_profiles_to_ldap()

to
    logger.info('[Migrating certificate profiles to LDAP]')
    time.sleep(10)
    cainstance.migrate_profiles_to_ldap()

and try again.


Version-Release number of selected component (if applicable):
RHEL-8.3

ugrade from RHEL-8.2
ipa-server-4.8.4-7.module+el8.2.0+6046+aaa49f96

to RHEL-8.3.1
389-ds-base-1.4.3.8-6.module+el8.3.0+8995+c08169ba.x86_64   Wed Dec 16 03:31:30
2020
ipa-server-4.8.7-13.module+el8.3.0+8376+0bba7131.x86_64     Thu Nov  5 03:30:55
2020
redhat-release-8.3-1.0.el8.x86_64                           Wed Nov  4 03:36:12
2020



How reproducible:
N/A

Steps to Reproduce:
1. N/A
2.
3.


Actual results:

var/log/ipaupgrade.log
...
2020-12-29T12:57:17Z INFO [Migrating certificate profiles to LDAP]
...
2020-12-29T12:57:17Z DEBUG request GET
https://edited:8443/ca/rest/account/login
2020-12-29T12:57:17Z DEBUG request body ''
2020-12-29T12:57:17Z DEBUG response status 500
...
2020-12-29T12:57:17Z DEBUG   File
"/usr/lib/python3.6/site-packages/ipapython/admintool.py", line 179, in execute
    return_value = self.run()
  File
"/usr/lib/python3.6/site-packages/ipaserver/install/ipa_server_upgrade.py",
line 54, in run
    server.upgrade()
  File "/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py",
line 1805, in upgrade
    upgrade_configuration()
  File "/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py",
line 1670, in upgrade_configuration
    ca_enable_ldap_profile_subsystem(ca)
  File "/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py",
line 414, in ca_enable_ldap_profile_subsystem
    cainstance.migrate_profiles_to_ldap()
  File "/usr/lib/python3.6/site-packages/ipaserver/install/cainstance.py", line
1954, in migrate_profiles_to_ldap
    _create_dogtag_profile(profile_id, profile_data, overwrite=False)
  File "/usr/lib/python3.6/site-packages/ipaserver/install/cainstance.py", line
1960, in _create_dogtag_profile
    with api.Backend.ra_certprofile as profile_api:
  File "/usr/lib/python3.6/site-packages/ipaserver/plugins/dogtag.py", line
1315, in __enter__
    raise errors.RemoteRetrieveError(reason=_('Failed to authenticate to CA
REST API'))


Expected results:
yes


Additional info:


from a different attachment and test with different time stamps, but this shows
the problem, the LDAP service was not ready while the PKI service was starting:

var/log/pki/pki-tomcat/ca/debug.2020-12-30.log
...
2020-12-30 15:23:00 [main] SEVERE: Unable to create socket:
java.net.ConnectException: Connexion refusée (Connection refused)
java.net.ConnectException: Connexion refusée (Connection refused)


var/log/dirsrv/slapd-edited/errors
...
[30/Dec/2020:15:23:00.947237533 +0100] - INFO - main - slapd stopped.
[30/Dec/2020:15:23:01.422101109 +0100] - INFO - slapd_extract_cert - CA CERT
NAME: edited IPA CA
...
[30/Dec/2020:15:23:02.865548903 +0100] - ERR - schema-compat-plugin -
schema-compat-plugin tree scan will start in about 5 seconds!
[30/Dec/2020:15:23:08.067018376 +0100] - ERR - schema-compat-plugin - warning:
no entries set up under cn=computers, cn=compat,dc=idm,dc=edited
[30/Dec/2020:15:23:08.089413336 +0100] - ERR - schema-compat-plugin - Finished
plugin initialization.
(END)

Metadata Update from @fcami:
- Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1911849

3 years ago

Closing as invalid.

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

3 years ago

I'd like to see this issue reopened as we are currently experiencing this when trying to upgrade from ipa-server 4.8 to 4.9.
pki-tomcatd starts a few seconds before the dirsrv is up, resulting in in the /ca context failing to start.
The upgrade script then is unable to reach /ca/rest/account/login and aborts the upgrade.
We tried to add "Requires=dirsrv" to the pki unit but the script then fails to restart pki-tomcatd because it was still starting.

Hi @paktosan
you may be hitting issue https://pagure.io/freeipa/issue/9381, for which a fix is available upstream (86c1426 Upgrade: add PKI drop-in file if missing).

The workaround is to create a drop-in file on your server:

# cat /etc/systemd/system/pki-tomcatd@pki-tomcat.service.d/ipa.conf
[Service]
Environment=LC_ALL=C.UTF-8
ExecStartPost=/usr/libexec/ipa/ipa-pki-wait-running

Login to comment on this ticket.

Metadata