Bug 1549367

Summary:	Ironic instances in Under Cloud do not get IP address from DHCP, due to invalid name resolution from 192.168.24.1 NS in the new docker package(1.13.1-55.rhel75.git774336d.el7)
Product:	Red Hat OpenStack	Reporter:	Shashank Katlaparthi <skatlapa>
Component:	puppet-ironic	Assignee:	RHOS Maint <rhos-maint>
Status:	CLOSED DUPLICATE	QA Contact:	nlevinki <nlevinki>
Severity:	urgent	Docs Contact:
Priority:	unspecified
Version:	13.0 (Queens)	CC:	bfournie, jjoyce, jschluet, psedlak, slinaber, tvignaud
Target Milestone:	---
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2018-02-27 13:47:00 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:

Description Shashank Katlaparthi 2018-02-27 01:47:52 UTC

Description of problem:

After the Undercloud Deployment, the ironic instances aren't getting IP address due to faulty DHCP server from an invalid Nameserver(192.168.24.1).
(docker.x86_64    2:1.13.1-55.rhel75.git774336d.el7).


1) nova-conductor.log

c97ed789-8e4f-4592-8d2b-1b699793fcfd] Error from last host: undercloud-0.redhat.local (node 66891d78-515d-4d16-b0d7-23dbbf1f1bdb): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1840, in _do_build_and_run_instance\n    filter_properties, request_spec)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2108, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c97ed789-8e4f-4592-8d2b-1b699793fcfd was re-scheduled: Failed to provision instance c97ed789-8e4f-4592-8d2b-1b699793fcfd: Failed to prepare to deploy: Unable to set binding:host_id for neutron port 7f495ac7-1ef2-4b92-905a-342c6758a5ea. Error: Host 66891d78-515d-4d16-b0d7-23dbbf1f1bdb is not connected to any segments on routed provider network '464855f9-e35e-472a-a7e2-5e19e954f2b1'.  It should be connected to one.\nNeutron server returns request_ids: ['req-3a3fe0bf-c438-41af-ba21-b4d3efa6ca4a']\n"]
2018-02-26 13:55:1


2) Ironic conductor snippet:

18-02-26 13:37:43.912 1378 DEBUG ironic_inspector.pxe_filter.iptables [-] DHCP is already disabled, not updating _disable_dhcp /usr/lib/python2.7/site-packages/ironic_inspector/pxe_filter/iptables.py:178
2018-02-26 13:37:43.913 1378 DEBUG ironic_inspector.pxe_filter.base [-] The PXE filter driver IptablesFilter, state=initialized left the fsm_reset_on_error context fsm_reset_on_error /usr/lib/python2.7/site-packages/ironic_inspector/pxe_filter/base.py:153

2018-02-26 13:55:05.669 1386 ERROR ironic.drivers.modules.network.flat [req-5689c777-3575-4081-beed-35f4e6baf31b aa1c6d98e9ba4c3bbd665bd73b135a73 d2ced46113564e9cba9e435b84705e9d - default default] Unable to set binding:host_id for neutron port 7f495ac7-1ef2-4b92-905a-342c6758a5ea. Error: Host 66891d78-515d-4d16-b0d7-23dbbf1f1bdb is not connected to any segments on routed provider network '464855f9-e35e-472a-a7e2-5e19e954f2b1'.  It should be connected to one.

3) ironic-inspector.log

2018-02-26 13:43:04.897 1378 INFO werkzeug [req-492dced8-8b4c-458f-ab39-01d90f0c1d63 - - - - -] 192.168.24.1 - - [26/Feb/2018 13:43:04] "GET / HTTP/1.1" 200 -
2018-02-26 13:43:05.075 1378 INFO werkzeug [req-b4f1e26e-4304-47e2-aafa-d7ec49a0259c 694fbdfdb054454ba2015337186a9316 6dfa73a84b0e49639709cc25ae752d21 - default default] 192.168.24.1 - - [26/Feb/2018 13:43:05] "GET /v1/introspection/0c25a48b-cae1-4166-b704-cb6c7069d36f/data HTTP/1.1" 200 -
2018-02-26 13:43:13.932 1378 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic_inspector.pxe_filter.base.periodic_sync_task' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639
2018-02-26 13:43:13.932 1378 DEBUG ironic_inspector.pxe_filter.base [-] The PXE filter driver IptablesFilter, state=initialized enters the fsm_reset_on_error context fsm_reset_on_error /usr/lib/python2.7/site-packages/ironic_inspector/pxe_filter/base.py:137
2018-02-26 13:43:13.937 1378 DEBUG ironic_inspect

"GET /v1/introspection HTTP/1.1" 200 -
2018-02-26 13:42:58.907 1378 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic_inspector.wsgi_service.periodic_clean_up' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639
2018-02-26 13:42:58.931 1378 DEBUG futurist.periodics [-] Submitting periodic callback 'ironic_inspector.pxe_filter.base.periodic_sync_task' _process_scheduled /usr/lib/python2.7/site-packages/futurist/periodics.py:639
2018-02-26 13:42:58.931 1378 DEBUG ironic_inspector.pxe_filter.base [-] The PXE filter driver IptablesFilter, state=initialized enters the fsm_reset_on_error context fsm_reset_on_error /usr/lib/python2.7/site-packages/ironic_inspector/pxe_filter/base.py:137
2018-02-26 13:42:58.935 1378 DEBUG ironic_inspector.pxe_filter.iptables [-] DHCP is already disabled, not updating _disable_dhcp /usr/lib/python2.7/site-packages/ironic_inspector/pxe_filter/iptables.py:178
2018-02-26 13:42:58.936 1378 DEBUG ironic_inspector.pxe_filter.base [-] The PXE filter driver IptablesFilter, state=initialized left the fsm_reset_on_error context fsm_reset_on_error /usr/lib/python2.7/site-packages/ironic_inspector/pxe_filter/base.py:153
2018-02-26 13:42:59.622 1378 INFO werkzeug [req-f48b20af-bf7a-4f01-9e7e-28e94d39bf37 - - - - -] 192.168.24.1 - - [26/Feb/2018 13:42:59] "GET / HTTP/1.1" 200 -
2018-02-26 13:42:59.806 1378 INFO werkzeug [req-81a2a328-365e-4e5c-8374-206bff2640aa 694fbdfdb054454ba2015337186a9316 6dfa73a84b0e49639709cc25ae752d21 - default default] 192.168.24.1 - - [26/Feb/2018 13:42:59] "GET /v1/introspection/66891d78-515d-4d16-b0d7-23dbbf1f1bdb/data HTTP/1.1" 200 -
2018-02-26 13:43:01.377 1378 INFO werkzeug [req-84310ac3-6c44-4f6b-ada4-cd9bbb0b1a30 - - - - -] 192.168.24.1 - - [26/Feb/2018 13:43:01] "GET / HTTP/1.1" 200 -
2018-02-26 13:43:01.560 1378 INFO werkzeug [req-53c15e66-d224-4c23-9b0e-e1a110cbf6c7 694fbdfdb054454ba2015337186a9316 6dfa73a84b0e49639709cc25ae752d21 - default default] 192.168.24.1 - - [26/Feb/2018 13:43:01] "GET /v1/introspection/f36a3e49-b9ea-4199-ba01-d6f4c98aae12/data HTTP/1.1" 200 -
2018-02-26 13:43:03.162 1378 INFO werkzeug [req-f69846b6-bb91-4348-8f4e-f3f1e8183567 - - - - -] 192.168.24.1 - - [26/Feb/2018 13:43:03] "GET / HTTP/1.1" 200 -
2018-02-26 13:43:03.340 1378 INFO werkzeug [req-a39d9f1f-269e-455d-b8f7-4fe24a3499a5 694fbdfdb054454ba2015337186a9316 6dfa73a84b0e49639709cc25ae752d21 - default default] 192.168.24.1 - - [26/Feb/2018 13:43:03] "GET /v1/introspection/0c25a48b-cae1-4166-b704-cb6c7069d36f/data HTTP/1.1" 200 -
2018-02-26 13:43:04.897 1378 INFO werkzeug [req-492dced8-8b4c-458f-ab39-01d90f0c1d63 - - - - -] 192.168.24.1 - - [26/Feb/2018 13:43:04] "GET / HTTP/1.1" 200 -
2018-02-26 13:43:05.075 1378 INFO werkzeug [req-b4f1e26e-4304-47e2-aafa-d7ec49a0259c 694fbdfdb054454ba2015337186a9316 6dfa73a84b0e49639709cc25ae752d21 - default default] 192.168.24.1 - - [26/Feb/2018 13:43:05] "GET /v1/introspection/0c25a48b-cae1-4166-b704-cb6c7069d36f/data HTTP/1.1" 200 -


From the nova-conductor.log we see that the instance fails to get an IP address from the DHCP server, also from the ironic-conductor snippet(2), we see that the name server here is 192.168.24.1 which is invalid and deployment steps timeout trying to get an IP from the incorrect name resolution.

Comment 1 Bob Fournier 2018-02-27 13:47:00 UTC

Shashank - based on the logs this appears to be a duplicate of https://bugzilla.redhat.com/show_bug.cgi?id=1549170.

You'll need to pick up the latest puddle which has a fix.

*** This bug has been marked as a duplicate of bug 1549170 ***