Note: This is a beta release of Red Hat Bugzilla 5.0. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Also email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback here.
Bug 1367217 - rhel-osp-director: Introspection fails on VM environment: the VM doesn't get an IP.
Summary: rhel-osp-director: Introspection fails on VM environment: the VM doesn't get...
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: rhosp-director
Version: 10.0 (Newton)
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ga
: 10.0 (Newton)
Assignee: Angus Thomas
QA Contact: Omri Hochman
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-08-15 21:50 UTC by Alexander Chuzhoy
Modified: 2016-09-14 15:33 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-09-14 15:33:08 UTC


Attachments (Terms of Use)
ironic logs. (deleted)
2016-08-15 21:51 UTC, Alexander Chuzhoy
no flags Details

Description Alexander Chuzhoy 2016-08-15 21:50:16 UTC
rhel-osp-director:   Introspection fails on VM environment: StdErr: u"/bin/dd: error writing '/dev/disk/by-path/ip-192.0.2.9:3260-iscsi-iqn.2008-10.org.openstack:39835c8d-9718-4546-a68b-6533ecd371ce-lun-1-part2': Input/output error


Environment:
python-ironic-lib-2.0.1-0.20160711231122.64dc8b6.el7ost.noarch
puppet-ironic-9.1.0-0.20160718195634.f7264d5.el7ost.noarch
openstack-ironic-api-6.0.1-0.20160726050352.636f26a.el7ost.noarch
python-ironicclient-1.5.1-0.20160721211401.65bdaea.el7ost.noarch
python-ironic-inspector-client-1.8.1-0.20160721140301.6951fb1.el7ost.noarch
python-ironic-tests-6.0.1-0.20160726050352.636f26a.el7ost.noarch
openstack-ironic-conductor-6.0.1-0.20160726050352.636f26a.el7ost.noarch
openstack-ironic-common-6.0.1-0.20160726050352.636f26a.el7ost.noarch
openstack-ironic-inspector-4.0.1-0.20160721111014.d970bf5.el7ost.noarch


Steps to reproduce:
Attempt to introspect the OC nodes on VM setup.

Result:
The introspection fails. I see an error on the console (Error 0x040ee119) followed by: No more network devices.

I see the following in the ironic-conductor.log:
2016-08-15 15:11:18.595 18007 ERROR ironic.drivers.modules.agent_base_vendor   File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/iscsi_deploy.py", line 267, in _fail_deploy
2016-08-15 15:11:18.595 18007 ERROR ironic.drivers.modules.agent_base_vendor     raise exception.InstanceDeployFailure(msg)
2016-08-15 15:11:18.595 18007 ERROR ironic.drivers.modules.agent_base_vendor InstanceDeployFailure: Deploy failed for instance 0d29f15c-2261-428e-abe0-599ece796219. Error: Unexpected error while running command.
2016-08-15 15:11:18.595 18007 ERROR ironic.drivers.modules.agent_base_vendor Command: sudo ironic-rootwrap /etc/ironic/rootwrap.conf dd if=/var/lib/ironic/images/d32c9721-21db-4fec-aa58-4545540e5768/disk of=/dev/d
isk/by-path/ip-192.0.2.8:3260-iscsi-iqn.2008-10.org.openstack:d32c9721-21db-4fec-aa58-4545540e5768-lun-1-part2 bs=1M oflag=direct
2016-08-15 15:11:18.595 18007 ERROR ironic.drivers.modules.agent_base_vendor Exit code: 1
2016-08-15 15:11:18.595 18007 ERROR ironic.drivers.modules.agent_base_vendor Stdout: u''
2016-08-15 15:11:18.595 18007 ERROR ironic.drivers.modules.agent_base_vendor Stderr: u"/bin/dd: error writing '/dev/disk/by-path/ip-192.0.2.8:3260-iscsi-iqn.2008-10.org.openstack:d32c9721-21db-4fec-aa58-4545540e57
68-lun-1-part2': Input/output error\n526+0 records in\n525+0 records out\n550502400 bytes (551 MB) copied, 170.504 s, 3.2 MB/s\n"
2016-08-15 15:11:18.595 18007 ERROR ironic.drivers.modules.agent_base_vendor
2016-08-15 15:11:18.609 18007 DEBUG ironic.conductor.task_manager [req-742beb6b-6839-4ff3-a28f-2dfa292b53ab - - - - -] Successfully released exclusive lock for calling vendor passthru on node d32c9721-21db-4fec-aa
58-4545540e5768 (lock was held 186.09 sec) release_resources /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:326
2016-08-15 15:11:18.672 18007 DEBUG oslo_concurrency.processutils [req-b50520a3-11d8-41c8-a7d6-28911097f449 - - - - -] Result was 0 ssh_execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:508
2016-08-15 15:11:18.814 18007 INFO ironic.conductor.utils [req-b50520a3-11d8-41c8-a7d6-28911097f449 - - - - -] Successfully set node 420751f0-d86c-4c6b-b365-d19bcbebdae8 power state to power off.
2016-08-15 15:11:18.845 18007 DEBUG ironic.conductor.manager [req-0a97c074-7fcc-4b33-a69b-fb888dd26cc4 - - - - -] RPC do_node_tear_down called for node 420751f0-d86c-4c6b-b365-d19bcbebdae8. do_node_tear_down /usr/
lib/python2.7/site-packages/ironic/conductor/manager.py:508
2016-08-15 15:11:18.847 18007 DEBUG ironic.conductor.task_manager [req-0a97c074-7fcc-4b33-a69b-fb888dd26cc4 - - - - -] Attempting to get exclusive lock on node 420751f0-d86c-4c6b-b365-d19bcbebdae8 (for node tear d
own) __init__ /usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py:209
2016-08-15 15:11:18.918 18007 DEBUG oslo_concurrency.lockutils [req-b50520a3-11d8-41c8-a7d6-28911097f449 - - - - -] Lock "master_image" acquired by "ironic.drivers.modules.image_cache.clean_up" :: waited 0.000s in
ner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:270
2016-08-15 15:11:18.918 18007 DEBUG ironic.drivers.modules.image_cache [req-b50520a3-11d8-41c8-a7d6-28911097f449 - - - - -] Starting clean up for master image cache /var/lib/ironic/master_images clean_up /usr/lib/
python2.7/site-packages/ironic/drivers/modules/image_cache.py:185
2016-08-15 15:11:18.919 18007 DEBUG oslo_concurrency.lockutils [req-b50520a3-11d8-41c8-a7d6-28911097f449 - - - - -] Lock "master_image" released by "ironic.drivers.modules.image_cache.clean_up" :: held 0.001s inne
r /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor [req-b50520a3-11d8-41c8-a7d6-28911097f449 - - - - -] Asynchronous exception for node 420751f0-d86c-4c6b-b365-d19bcbebdae8: Node failed t
o get image for deploy. Exception: Deploy failed for instance 54fc8c01-7a10-4b04-8871-08ccebc4ce26. Error: Unexpected error while running command.
Command: sudo ironic-rootwrap /etc/ironic/rootwrap.conf dd if=/var/lib/ironic/images/420751f0-d86c-4c6b-b365-d19bcbebdae8/disk of=/dev/disk/by-path/ip-192.0.2.16:3260-iscsi-iqn.2008-10.org.openstack:420751f0-d86c-
4c6b-b365-d19bcbebdae8-lun-1-part2 bs=1M oflag=direct
Exit code: 1
Stdout: u''
Stderr: u"/bin/dd: error writing '/dev/disk/by-path/ip-192.0.2.16:3260-iscsi-iqn.2008-10.org.openstack:420751f0-d86c-4c6b-b365-d19bcbebdae8-lun-1-part2': Input/output error\n524+0 records in\n523+0 records out\n54
8405248 bytes (548 MB) copied, 171.102 s, 3.2 MB/s\n"
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor Traceback (most recent call last):
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor   File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/agent_base_vendor.py", line 487, in heartbeat
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor     self.continue_deploy(task, **kwargs)
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor   File "/usr/lib/python2.7/site-packages/ironic/conductor/task_manager.py", line 140, in wrapper
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor     return f(*args, **kwargs)
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor   File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/iscsi_deploy.py", line 586, in continue_deploy
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor     uuid_dict_returned = do_agent_iscsi_deploy(task, self._client)
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor   File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/iscsi_deploy.py", line 352, in do_agent_iscsi_deploy
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor     uuid_dict_returned = continue_deploy(task, iqn=iqn, address=address)
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor   File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/iscsi_deploy.py", line 290, in continue_deploy
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor     _fail_deploy(task, msg)
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor   File "/usr/lib/python2.7/site-packages/ironic/drivers/modules/iscsi_deploy.py", line 267, in _fail_deploy
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor     raise exception.InstanceDeployFailure(msg)
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor InstanceDeployFailure: Deploy failed for instance 54fc8c01-7a10-4b04-8871-08ccebc4ce26. Error: Unexpected error while running command.
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor Command: sudo ironic-rootwrap /etc/ironic/rootwrap.conf dd if=/var/lib/ironic/images/420751f0-d86c-4c6b-b365-d19bcbebdae8/disk of=/dev/d
isk/by-path/ip-192.0.2.16:3260-iscsi-iqn.2008-10.org.openstack:420751f0-d86c-4c6b-b365-d19bcbebdae8-lun-1-part2 bs=1M oflag=direct
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor Exit code: 1
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor Stdout: u''
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor Stderr: u"/bin/dd: error writing '/dev/disk/by-path/ip-192.0.2.16:3260-iscsi-iqn.2008-10.org.openstack:420751f0-d86c-4c6b-b365-d19bcbebd
ae8-lun-1-part2': Input/output error\n524+0 records in\n523+0 records out\n548405248 bytes (548 MB) copied, 171.102 s, 3.2 MB/s\n"
2016-08-15 15:11:18.920 18007 ERROR ironic.drivers.modules.agent_base_vendor
2016-08-15 15:11:18.939 18007 DEBUG ironic.conductor.manager [req-f738bc4b-6676-4


Expected result:
Successful introspection.
Note: I'm able to introspect on BM setup, but it constantly fails on VM.

Comment 2 Alexander Chuzhoy 2016-08-15 21:51:05 UTC
Created attachment 1191019 [details]
ironic logs.

Comment 3 Dmitry Tantsur 2016-08-17 15:49:27 UTC
The title contradicts itself: it says introspection, but the error is from deployment. Could you please clarify?

Comment 4 Alexander Chuzhoy 2016-08-17 15:50:49 UTC
I guess we'll need to change the title then once enough info is collected.
Once the introspection ended, a deployment was attempted (script).
I assumed the message is related to introspection.
Thanks.

Comment 5 Alexander Chuzhoy 2016-08-17 17:17:17 UTC
The VM doesn't get an IP upon boot:

[stack@instack ~]$ sudo tcpdump -i any port 67 or port 68 or port 69
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on any, link-type LINUX_SLL (Linux cooked), capture size 65535 bytes
^[[24~13:15:12.855875 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:1a:04:9d:07:be (oui Unknown), length 396
13:15:20.765602 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request from 00:1a:04:9d:07:be (oui Unknown), length 396
13:15:36.584220 IP 0.0.0.0.bootpc > 255.255.255.255.bootps: BOOTP/DHCP, Request 
from 00:1a:04:9d:07:be (oui Unknown), length 396

I tried to clear the iptables - same result.

Comment 6 James Slagle 2016-09-13 20:08:17 UTC
this is an error encounted by Ironic during deployment. moving to DFG:HardProv

Comment 7 Dmitry Tantsur 2016-09-14 07:23:19 UTC
Please paste logs from openstack-ironic-inspector and openstack-ironic-inspector-dnsmasq.

Also, is there anything special about your virtual environment? How was it created?

Comment 8 Alexander Chuzhoy 2016-09-14 15:32:13 UTC
I don't reproduce this issue now.

Comment 9 Dmitry Tantsur 2016-09-14 15:33:08 UTC
Thanks! Please reopen if you see it again.


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