Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1670517

Summary: Error: Failed to create config drive on disk /dev/disk/by-path/ip-x.x.x.x deploying whole disk with UEFI bootmode
Product: Red Hat OpenStack Reporter: mlammon
Component: python-ironic-libAssignee: RHOS Maint <rhos-maint>
Status: CLOSED ERRATA QA Contact: mlammon
Severity: high Docs Contact:
Priority: high    
Version: 14.0 (Rocky)CC: apevec, bfournie, hjensas, jjoyce, jschluet, lhh, mburns, rhos-maint
Target Milestone: z2Keywords: Triaged, ZStream
Target Release: 14.0 (Rocky)   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: python-ironic-lib-2.14.1-0.20190204171927.95c6a2a.el7ost Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1670624 (view as bug list) Environment:
Last Closed: 2019-04-30 17:50:30 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:
Bug Depends On:    
Bug Blocks: 1670624    

Description mlammon 2019-01-29 17:59:28 UTC
Description of problem:
Error: Failed to create config drive on disk /dev/disk/by-path/ip-x.x.x.x deploying whole disk with UEFI bootmode

Version-Release number of selected component (if applicable):
Env
instack-undercloud-9.4.1-0.20180928005746.15cda5a.el7ost.noarch
openstack-ironic-api-11.1.1-0.20181012152843.el7ost.noarch.rpm 
openstack-ironic-common-11.1.1-0.20181012152843.el7ost.noarch.rpm
openstack-ironic-conductor-11.1.1-0.20181012152843.el7ost.noarch.rpm
openstack-ironic-inspector-8.0.1-0.20180924215820.e89450c.el7ost.noarch.rpm
openstack-ironic-python-agent-3.3.1-0.20180820213404.85a9cca.el7ost.noarch.rpm
openstack-ironic-staging-drivers-0.10.1-0.20180820161038.39c4e93.el7ost.noarch.rpm 

How reproducible:
100%

Steps to Reproduce:
1. Deploy OC (3 controller, 2 compute) using whole disk image built from rhel 7.6 with UEFI bootmode
2. Deployment failed to build a node ( I have seem the node that fails not always the same) but seems to be just one.
3.

Actual results:

/var/log/containers/nova

nova-conductor.log:2019-01-29 03:27:18.262 28 ERROR nova.scheduler.utils [req-535e3996-1eaa-481b-bf2b-a4a74532d02e 78611f01958e4bdfb3f2d4d722f8778c 190a907999874771b4bbe264b5f259aa - default default] [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867] Error from last host: undercloud-0.localdomain (node a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1929, 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 2218, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867 was re-scheduled: Failed to provision instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867: Deploy failed for instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867. Error: Failed to create config drive on disk /dev/disk/by-path/ip-192.168.24.16:3260-iscsi-iqn.2008-10.org.openstack:a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3-lun-1 for node a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3. Error: Unexpected error while running command.\nCommand: test -e /dev/disk/by-path/ip-192.168.24.16:3260-iscsi-iqn.2008-10.org.openstack:a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3-lun-1-part4\nExit code: 1\nStdout: u''\nStderr: u''\n"]
nova-compute.log.1:2019-01-29 02:32:07.760 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:33:08.447 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:34:08.454 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:35:10.453 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:36:12.448 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:37:13.464 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:38:15.446 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:39:15.483 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:40:17.448 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:41:18.458 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:42:18.448 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:43:20.468 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 02:44:22.447 1 ERROR nova.compute.manager [req-1353d92b-2725-4ca4-a7f0-bcce771eb289 - - - - -] No compute node record for host undercloud-0.localdomain: ComputeHostNotFound_Remote: Compute host undercloud-0.localdomain could not be found.
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [req-535e3996-1eaa-481b-bf2b-a4a74532d02e 78611f01958e4bdfb3f2d4d722f8778c 190a907999874771b4bbe264b5f259aa - default default] [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867] Instance failed to spawn: InstanceDeployFailure: Failed to provision instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867: Deploy failed for instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867. Error: Failed to create config drive on disk /dev/disk/by-path/ip-192.168.24.16:3260-iscsi-iqn.2008-10.org.openstack:a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3-lun-1 for node a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3. Error: Unexpected error while running command.
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867] Traceback (most recent call last):
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2357, in _build_resources
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     yield resources
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2121, in _build_and_run_instance
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     block_device_info=block_device_info)
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/nova/virt/ironic/driver.py", line 1153, in spawn
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     'node': node_uuid})
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     self.force_reraise()
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     six.reraise(self.type_, self.value, self.tb)
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/nova/virt/ironic/driver.py", line 1145, in spawn
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     timer.start(interval=CONF.ironic.api_retry_interval).wait()
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/eventlet/event.py", line 121, in wait
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     return hubs.get_hub().switch()
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 294, in switch
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     return self.greenlet.switch()
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/oslo_service/loopingcall.py", line 171, in _run_loop
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     result = func(*self.args, **self.kw)
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]   File "/usr/lib/python2.7/site-packages/nova/virt/ironic/driver.py", line 509, in _wait_for_active
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]     raise exception.InstanceDeployFailure(msg)
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867] InstanceDeployFailure: Failed to provision instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867: Deploy failed for instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867. Error: Failed to create config drive on disk /dev/disk/by-path/ip-192.168.24.16:3260-iscsi-iqn.2008-10.org.openstack:a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3-lun-1 for node a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3. Error: Unexpected error while running command.
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867] Command: test -e /dev/disk/by-path/ip-192.168.24.16:3260-iscsi-iqn.2008-10.org.openstack:a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3-lun-1-part4
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867] Exit code: 1
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867] Stdout: u''
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867] Stderr: u''
nova-compute.log.1:2019-01-29 03:26:35.953 1 ERROR nova.compute.manager [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867]
nova-compute.log.1:2019-01-29 03:27:14.411 1 DEBUG nova.compute.manager [req-535e3996-1eaa-481b-bf2b-a4a74532d02e 78611f01958e4bdfb3f2d4d722f8778c 190a907999874771b4bbe264b5f259aa - default default] [instance: 5c294b7d-2334-4fb3-8723-7d29d4b4f867] Build of instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867 was re-scheduled: Failed to provision instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867: Deploy failed for instance 5c294b7d-2334-4fb3-8723-7d29d4b4f867. Error: Failed to create config drive on disk /dev/disk/by-path/ip-192.168.24.16:3260-iscsi-iqn.2008-10.org.openstack:a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3-lun-1 for node a2a85eff-c0d9-4f68-9e41-fbbc931b8ad3. Error: Unexpected error while running command.

Comment 1 mlammon 2019-01-29 18:02:00 UTC
(undercloud) [stack@undercloud-0 ~]$ openstack stack failures list overcloud
overcloud.Controller.0:
  resource_type: OS::TripleO::Controller
  physical_resource_id: 6e57421c-9d70-410f-81fb-946c783acae5
  status: CREATE_FAILED
  status_reason: |
    resources[0]: Stack CREATE cancelled

Comment 3 Harald Jensås 2019-01-29 21:47:39 UTC
On failed deployments I see these messages.

First partprobe command have an Error:
 """ The backup GPT table is not at the end of the disk, as it should be.  This might mean that another operating system believes the disk is smaller.  Fix, by moving the backup to the end (and removing the old backup)? """

 (Questionmark makes me wonder if it's prompting for input?)

2019-01-29 13:55:37.161 1 DEBUG oslo_concurrency.processutils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] Running cmd (subprocess): sudo ironic-rootwrap /etc/ironic/rootwrap.conf partprobe /dev/disk/by-path/ip-192.168.24.10:3260-iscsi-iqn.2008-10.org.openstack:4f3e6f17-9cd0-4ade-9a63-49b17dd7a704-lun-1 execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372
2019-01-29 13:55:39.172 1 DEBUG oslo_concurrency.processutils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] CMD "sudo ironic-rootwrap /etc/ironic/rootwrap.conf partprobe /dev/disk/by-path/ip-192.168.24.10:3260-iscsi-iqn.2008-10.org.openstack:4f3e6f17-9cd0-4ade-9a63-49b17dd7a704-lun-1" returned: 0 in 2.011s execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409
2019-01-29 13:55:39.174 1 DEBUG ironic_lib.utils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] Execution completed, command line is "partprobe /dev/disk/by-path/ip-192.168.24.10:3260-iscsi-iqn.2008-10.org.openstack:4f3e6f17-9cd0-4ade-9a63-49b17dd7a704-lun-1" execute /usr/lib/python2.7/site-packages/ironic_lib/utils.py:101
2019-01-29 13:55:39.174 1 DEBUG ironic_lib.utils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] Command stdout is: "" execute /usr/lib/python2.7/site-packages/ironic_lib/utils.py:103
2019-01-29 13:55:39.174 1 DEBUG ironic_lib.utils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] Command stderr is: "Error: The backup GPT table is not at the end of the disk, as it should be.  This might mean that another operating system believes the disk is smaller.  Fix, by moving the backup to the end (and removing the old backup)?


Then when sgdisk run's to (according to code comment) """ # Also verify that the partitioning is correct now. """ it prints a warning that the kernel is still using the old partition table.

2019-01-29 13:55:39.175 1 DEBUG oslo_concurrency.processutils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] Running cmd (subprocess): sudo ironic-rootwrap /etc/ironic/rootwrap.conf sgdisk -e /dev/disk/by-path/ip-192.168.24.10:3260-iscsi-iqn.2008-10.org.openstack:4f3e6f17-9cd0-4ade-9a63-49b17dd7a704-lun-1 execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:372
2019-01-29 13:55:41.143 1 DEBUG oslo_concurrency.processutils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] CMD "sudo ironic-rootwrap /etc/ironic/rootwrap.conf sgdisk -e /dev/disk/by-path/ip-192.168.24.10:3260-iscsi-iqn.2008-10.org.openstack:4f3e6f17-9cd0-4ade-9a63-49b17dd7a704-lun-1" returned: 0 in 1.968s execute /usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py:409
2019-01-29 13:55:41.144 1 DEBUG ironic_lib.utils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] Execution completed, command line is "sgdisk -e /dev/disk/by-path/ip-192.168.24.10:3260-iscsi-iqn.2008-10.org.openstack:4f3e6f17-9cd0-4ade-9a63-49b17dd7a704-lun-1" execute /usr/lib/python2.7/site-packages/ironic_lib/utils.py:101
2019-01-29 13:55:41.145 1 DEBUG ironic_lib.utils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] Command stdout is: "Warning: The kernel is still using the old partition table.
2019-01-29 13:55:41.145 1 DEBUG ironic_lib.utils [req-0bab1ac7-5d4b-4229-b1f8-55694e8a9057 - - - - -] Command stderr is: "" execute /usr/lib/python2.7/site-packages/ironic_lib/utils.py:104


The code in question is in ironic-lib[1].
And the CI does not yet have this change: https://review.openstack.org/#/q/I9db48a3462422749290bbb887c14816734ab0478



[1] https://github.com/openstack/ironic-lib/blob/master/ironic_lib/disk_utils.py#L795

Comment 4 mlammon 2019-01-29 23:03:14 UTC
This overcloud deployment is success with above patch applied in comment#3
https://review.openstack.org/#/q/I9db48a3462422749290bbb887c14816734ab0478

Comment 8 mlammon 2019-04-12 14:07:23 UTC
Our regression testing passed and this is no longer issue.

Comment 11 errata-xmlrpc 2019-04-30 17:50:30 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-2019:0947

Comment 12 Red Hat Bugzilla 2023-09-14 04:45:52 UTC
The needinfo request[s] on this closed bug have been removed as they have been unresolved for 1000 days