Bug 1477367 - ipa-server-upgrade timeouts on wait_for_open ports expecting IPA services listening on IPv6 ports
ipa-server-upgrade timeouts on wait_for_open ports expecting IPA services lis...
Status: VERIFIED
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: ipa (Show other bugs)
7.4
All Linux
urgent Severity urgent
: rc
: ---
Assigned To: IPA Maintainers
ipa-qe
: Regression, ZStream
: 1493116 (view as bug list)
Depends On:
Blocks: 1493410
  Show dependency treegraph
 
Reported: 2017-08-01 18:11 EDT by Marc Sauton
Modified: 2017-11-22 08:32 EST (History)
18 users (show)

See Also:
Fixed In Version: ipa-4.5.0-21.el7.2.2
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1493410 (view as bug list)
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Marc Sauton 2017-08-01 18:11:51 EDT
Description of problem:

failed "yum ipa-*" from RHEL-7.3 to new 7.4

I was about to complete an upgrade test when I lost access to my test environment, at this point I need to log in a bz those customer logs for review and references.
there are 2 customer cases at this moment, it seem like there is some difficulties around the dogtag services, the start from
/bin/systemctl start pki-tomcatd@pki-tomcat.service
may not have happened correctly:

2017-08-01T15:33:23Z DEBUG wait_for_open_ports: localhost [8080, 8443] timeout 300
2017-08-01T15:38:23Z ERROR IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
2017-08-01T15:38:23Z DEBUG   File "/usr/lib/python2.7/site-packages/ipapython/admintool.py", line 172, in execute
    return_value = self.run()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/ipa_server_upgrade.py", line 46, in run
    server.upgrade()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/upgrade.py", line 1913, in upgrade
    upgrade_configuration()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/upgrade.py", line 1646, in upgrade_configuration
    upgrade_pki(ca, fstore)
  File "/usr/lib64/python2.7/contextlib.py", line 24, in __exit__
    self.gen.next()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/installutils.py", line 1134, in stopped_service
    service_obj.start(instance_name)
  File "/usr/lib/python2.7/site-packages/ipaplatform/redhat/services.py", line 211, in start
    instance_name, capture_output=capture_output, wait=wait)
  File "/usr/lib/python2.7/site-packages/ipaplatform/base/services.py", line 300, in start
    self.wait_for_open_ports(self.service_instance(instance_name))
  File "/usr/lib/python2.7/site-packages/ipaplatform/base/services.py", line 270, in wait_for_open_ports
    self.api.env.startup_timeout)
  File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 1227, in wait_for_open_ports
    raise socket.timeout("Timeout exceeded")

2017-08-01T15:38:23Z DEBUG The ipa-server-upgrade command failed, exception: timeout: Timeout exceeded
2017-08-01T15:38:23Z ERROR Timeout exceeded



case 01901713 has a sosreport

but the dogtag debug log is empty, at
https://fubar.gsslab.rdu2.redhat.com/01901713/10-sosreport-ipaserver1.dlcportal.de-20170801082748.tar.xz/sosreport-ipaserver1.dlcportal.de-20170801082748/var/log/pki/pki-tomcat/ca/

so it is not clear what happened.
then, there are quite some errors, and also from custodia, at
https://fubar.gsslab.rdu2.redhat.com/01901713/10-sosreport-ipaserver1.dlcportal.de-20170801082748.tar.xz/sosreport-ipaserver1.dlcportal.de-20170801082748/var/log/messages

Aug  1 08:25:28 ipaserver1 systemd: Starting The Apache HTTP Server...
Aug  1 08:25:28 ipaserver1 ipa-httpd-kdcproxy: ipa         : INFO     KDC proxy enabled
Aug  1 08:25:29 ipaserver1 systemd: Started The Apache HTTP Server.
Aug  1 08:26:02 ipaserver1 systemd: Starting IPA Custodia Service...
Aug  1 08:26:02 ipaserver1 ipa-custodia: Traceback (most recent call last):
Aug  1 08:26:02 ipaserver1 ipa-custodia: File "/usr/libexec/ipa/ipa-custodia", line 6, in <module>
Aug  1 08:26:02 ipaserver1 ipa-custodia: main()
Aug  1 08:26:02 ipaserver1 ipa-custodia: File "/usr/lib/python2.7/site-packages/ipaserver/secrets/service.py", line 26, in main
Aug  1 08:26:02 ipaserver1 ipa-custodia: return custodia.server.main(argparser)
Aug  1 08:26:02 ipaserver1 ipa-custodia: File "/usr/lib/python2.7/site-packages/custodia/server/__init__.py", line 211, in main
Aug  1 08:26:02 ipaserver1 ipa-custodia: _load_plugins(config, cfgparser)
Aug  1 08:26:02 ipaserver1 ipa-custodia: File "/usr/lib/python2.7/site-packages/custodia/server/__init__.py", line 191, in _load_plugins
Aug  1 08:26:02 ipaserver1 ipa-custodia: raise RuntimeError(menu, name, e)
Aug  1 08:26:02 ipaserver1 ipa-custodia: RuntimeError: ('authorizers', 'kemkeys', ValueError(u'Invalid format for "handler" option [ImportError(\'No module named secrets.kem\',)]: ipapython.secrets.kem.IPAKEMKeys',))
Aug  1 08:26:02 ipaserver1 systemd: ipa-custodia.service: main process exited, code=exited, status=1/FAILURE
Aug  1 08:26:02 ipaserver1 systemd: Failed to start IPA Custodia Service.


Version-Release number of selected component (if applicable):
custodia-0.3.1-4.el7.noarch                                 Tue Aug  1 05:36:02 2017
ipa-server-4.5.0-20.el7.x86_64                              Tue Aug  1 05:36:39 2017
redhat-release-server-7.4-18.el7.x86_64                     Tue Aug  1 05:34:46 2017


How reproducible:
N/A (unreachable test enviroment in remote lab)

Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:
Comment 14 Petr Vobornik 2017-08-02 12:08:46 EDT
Upstream ticket:
https://pagure.io/freeipa/issue/7083
Comment 15 Petr Vobornik 2017-08-02 12:41:36 EDT
If theory behind incorrect changes in host_port_open function is correct then this PR might fix the issue: https://github.com/freeipa/freeipa/pull/955/files
Comment 35 Tomas Krizek 2017-09-20 06:57:39 EDT
Fixed upstream
ipa-4-6:
https://pagure.io/freeipa/c/f05afa4813f425e9fc9960f63100431a78310638
Comment 36 Rob Crittenden 2017-09-25 10:09:36 EDT
*** Bug 1493116 has been marked as a duplicate of this bug. ***
Comment 38 Nikhil Dehadrai 2017-11-22 08:32:31 EST
IPA-server version: ipa-server-4.5.4-4.el7.x86_64

Verified the bug on the basis of following steps:
1) Disable IPV6 in /etc/sysctl.conf and run 'sysctl -p'. Use 'ifconfig | grep inet6' to confirm IPv6 is disabled.

2) When IPA server having IPAv6 disabled and is upgraded to latest version ( in my case RHEL 7.5), the upgrade fails with following message:

ERROR IPv6 stack is enabled in the kernel but there is no interface that has ::1 address assigned. Add ::1 address resolution to 'lo' interface. You might need to enable IPv6 on the interface 'lo' in sysctl.conf.

Console:
----------
[root@cloud-qe-17 ~]# rpm -q ipa-server selinux-policy
ipa-server-4.5.4-4.el7.x86_64
selinux-policy-3.13.1-180.el7.noarch

[root@cloud-qe-17 ~]# tail -1 /var/log/ipaupgrade.log 
2017-11-22T13:20:27Z ERROR The ipa-server-upgrade command failed. See /var/log/ipaupgrade.log for more information

[root@cloud-qe-17 ~]# cat /var/log/ipaupgrade.log | grep IPv6
2017-11-22T13:20:27Z ERROR IPv6 stack is enabled in the kernel but there is no interface that has ::1 address assigned. Add ::1 address resolution to 'lo' interface. You might need to enable IPv6 on the interface 'lo' in sysctl.conf.

Thus on the basis of above observations, marking status of bug to "VERIFIED".

Note You need to log in before you can comment on or make changes to this bug.