Bug 1547641

Summary: ipa: Please log something after restarting the KDC
Product: Red Hat Enterprise Linux 7 Reporter: Robbie Harwood <rharwood>
Component: ipaAssignee: IPA Maintainers <ipa-maint>
Status: CLOSED ERRATA QA Contact: ipa-qe <ipa-qe>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.4CC: mkosek, ndehadra, pasik, ppicka, pvoborni, rcritten, tscherf
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: ipa-4.6.4-1.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-10-30 10:57:12 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
tarball of /var/log none

Description Robbie Harwood 2018-02-21 16:31:56 UTC
Created attachment 1398903 [details]
tarball of /var/log

During an `ipa-server-install -N`, the installer appears to hang on "Restarting the KDC" for about a full minute.

However, per ipaserver-install.log, it has already finished this:

2018-02-21T16:16:40Z DEBUG Restarting the KDC
2018-02-21T16:16:40Z DEBUG Starting external process
2018-02-21T16:16:40Z DEBUG args=/bin/systemctl restart krb5kdc.service
2018-02-21T16:16:40Z DEBUG Process finished, return code=0
2018-02-21T16:16:40Z DEBUG stdout=
2018-02-21T16:16:40Z DEBUG stderr=
2018-02-21T16:16:40Z DEBUG Starting external process
2018-02-21T16:16:40Z DEBUG args=/bin/systemctl is-active krb5kdc.service
2018-02-21T16:16:40Z DEBUG Process finished, return code=0
2018-02-21T16:16:40Z DEBUG stdout=active

And is instead doing... something else?

2018-02-21T16:16:40Z DEBUG stderr=
2018-02-21T16:16:40Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2018-02-21T16:16:40Z DEBUG raw: server_find(None, version=u'2.228', no_members=False)
2018-02-21T16:16:40Z DEBUG server_find(None, all=False, raw=False, version=u'2.228', no_members=False, pkey_only=False)
2018-02-21T16:16:40Z DEBUG flushing ldapi://%2fvar%2frun%2fslapd-TESTIUM-BIZ.socket from SchemaCache
2018-02-21T16:16:40Z DEBUG retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-TESTIUM-BIZ.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x827ea28>
2018-02-21T16:16:40Z DEBUG raw: topologysuffix_find(None, all=True, raw=True, version=u'2.228')
2018-02-21T16:16:40Z DEBUG topologysuffix_find(None, all=True, raw=True, version=u'2.228', pkey_only=False)
2018-02-21T16:16:40Z DEBUG raw: server_role_find(None, server_server=u'freeipa.testium.biz', status=u'enabled', version=u'2.228')
2018-02-21T16:16:40Z DEBUG server_role_find(None, server_server=u'freeipa.testium.biz', status=u'enabled', all=False, raw=False, version=u'2.228')
2018-02-21T16:16:40Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:16:45Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:16:50Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:16:55Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:00Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:05Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:10Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:15Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:20Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:25Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:30Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:35Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:40Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:45Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:50Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:17:55Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:18:00Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:18:05Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:18:10Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:18:15Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:18:20Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:18:25Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:18:30Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:18:35Z DEBUG The DNS query name does not exist: freeipa.testium.biz.
2018-02-21T16:18:40Z ERROR unable to resolve host name freeipa.testium.biz. to IP address, ipa-ca DNS record will be incomplete

After logging the ERROR, the CLI logs

ipa         : ERROR    unable to resolve host name freeipa.testium.biz. to IP address, ipa-ca DNS record will be incomplete

prints some information about the installation, and declares it complete.

Thanks!

[root@freeipa ~]# rpm -qa | egrep 'krb|ipa|cert|389|sssd' | sort
389-ds-base-1.3.6.1-16.el7.x86_64
389-ds-base-libs-1.3.6.1-16.el7.x86_64
ca-certificates-2017.2.14-71.el7.noarch
certmonger-0.78.4-3.el7.x86_64
ipa-client-4.5.0-20.el7.x86_64
ipa-client-common-4.5.0-20.el7.noarch
ipa-common-4.5.0-20.el7.noarch
ipa-server-4.5.0-20.el7.x86_64
ipa-server-common-4.5.0-20.el7.noarch
krb5-libs-1.15.1-8.el7.x86_64
krb5-pkinit-1.15.1-8.el7.x86_64
krb5-server-1.15.1-8.el7.x86_64
krb5-workstation-1.15.1-8.el7.x86_64
libipa_hbac-1.15.2-50.el7.x86_64
libsss_certmap-1.15.2-50.el7.x86_64
python2-ipaclient-4.5.0-20.el7.noarch
python2-ipalib-4.5.0-20.el7.noarch
python2-ipaserver-4.5.0-20.el7.noarch
python-iniparse-0.4-9.el7.noarch
python-ipaddress-1.0.16-2.el7.noarch
python-libipa_hbac-1.15.2-50.el7.x86_64
python-rhsm-certificates-1.19.9-1.el7.x86_64
python-sssdconfig-1.15.2-50.el7.noarch
sssd-1.15.2-50.el7.x86_64
sssd-ad-1.15.2-50.el7.x86_64
sssd-client-1.15.2-50.el7.x86_64
sssd-common-1.15.2-50.el7.x86_64
sssd-common-pac-1.15.2-50.el7.x86_64
sssd-dbus-1.15.2-50.el7.x86_64
sssd-ipa-1.15.2-50.el7.x86_64
sssd-krb5-1.15.2-50.el7.x86_64
sssd-krb5-common-1.15.2-50.el7.x86_64
sssd-ldap-1.15.2-50.el7.x86_64
sssd-proxy-1.15.2-50.el7.x86_64
[root@freeipa ~]#

Comment 2 fbarreto 2018-03-07 20:57:43 UTC
Upstream ticket:
https://pagure.io/freeipa/issue/7436

Comment 3 Rob Crittenden 2018-05-10 13:31:07 UTC
ipa-4-6:

    c500dbc Log service start/stop/restart message

Comment 5 Pavel Picka 2018-08-17 07:11:15 UTC
ipa-server-install -N -d
ipa-server-4.6.4-5.el7.x86_64

ipaserver.install.service: DEBUG    Restarting the KDC
Restarting the KDC
ipapython.ipautil: DEBUG    Starting external process
ipapython.ipautil: DEBUG    args=/bin/systemctl restart krb5kdc.service
ipapython.ipautil: DEBUG    Process finished, return code=0
ipapython.ipautil: DEBUG    stdout=
ipapython.ipautil: DEBUG    stderr=
ipapython.ipautil: DEBUG    Starting external process
ipapython.ipautil: DEBUG    args=/bin/systemctl is-active krb5kdc.service
ipapython.ipautil: DEBUG    Process finished, return code=0
ipapython.ipautil: DEBUG    stdout=active

ipapython.ipautil: DEBUG    stderr=
ipaplatform.base.services: DEBUG    Restart of krb5kdc.service complete

===============================================================================

ipaserver.install.service: DEBUG      [9/10]: starting the KDC
  [9/10]: starting the KDC
ipapython.ipautil: DEBUG    Starting external process
ipapython.ipautil: DEBUG    args=/bin/systemctl start krb5kdc.service
ipapython.ipautil: DEBUG    Process finished, return code=0
ipapython.ipautil: DEBUG    stdout=
ipapython.ipautil: DEBUG    stderr=
ipapython.ipautil: DEBUG    Starting external process
ipapython.ipautil: DEBUG    args=/bin/systemctl is-active krb5kdc.service
ipapython.ipautil: DEBUG    Process finished, return code=0
ipapython.ipautil: DEBUG    stdout=active

ipapython.ipautil: DEBUG    stderr=
ipaplatform.base.services: DEBUG    Start of krb5kdc.service complete
ipaserver.install.service: DEBUG      duration: 0 seconds

===============================================================================

ipapython.ipautil: DEBUG    Starting external process
ipapython.ipautil: DEBUG    args=/bin/systemctl stop krb5kdc.service
ipapython.ipautil: DEBUG    Process finished, return code=0
ipapython.ipautil: DEBUG    stdout=
ipapython.ipautil: DEBUG    stderr=
ipaplatform.base.services: DEBUG    Stop of krb5kdc.service complete
ipaserver.install.service: DEBUG    Configuring Kerberos KDC (krb5kdc)
Configuring Kerberos KDC (krb5kdc)

debug messages in place

Verified

Comment 7 errata-xmlrpc 2018-10-30 10:57:12 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2018:3187