yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1253612] Re: Launch Instance Boot from image - creates a new volume fails

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Nikola Đipanov <ndipanov@xxxxxxxxxx>
Date: Tue, 25 Mar 2014 16:11:20 -0000
Reply-to: Bug 1253612 <1253612@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Similar as the bug https://bugs.launchpad.net/nova/+bug/1280357, I think
marking this one as a won't fix and getting the cinder interactions with
events done early in juno makes the most sense to me here.

** Changed in: nova
       Status: Confirmed => Won't Fix

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1253612

Title:
  Launch Instance Boot from image - creates a new volume fails

Status in OpenStack Compute (Nova):
  Won't Fix

Bug description:
  steps to reproduce:
  1. Launch a new instance with a Boot Source from image (creates a new volume).

  Nova-Compute side fails with the below logs:
  2013-11-21 11:31:30.708 19098 ERROR nova.compute.manager [req-8b32d1cd-42be-4daa-a3a3-2a1429d199c3 b94edf2504c84223b58e254314528902 679545ff6c1e4401adcafa0857aefe2e] [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Instance failed block device setup
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Traceback (most recent call last):
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1376, in _prep_block_device
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     self._await_block_device_map_created))
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/virt/block_device.py", line 283, in attach_block_devices
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     block_device_mapping)
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/virt/block_device.py", line 238, in attach
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     wait_func(context, vol['id'])
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 901, in _await_block_device_map_created
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     attempts=attempts)
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] VolumeNotCreated: Volume cff27c84-5f73-40e4-8356-72bd7b3e0b4f did not finish being created even after we waited 71 seconds or 60 attempts.
  2013-11-21 11:31:30.708 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]
  2013-11-21 11:31:30.806 19098 AUDIT nova.compute.manager [req-8b32d1cd-42be-4daa-a3a3-2a1429d199c3 b94edf2504c84223b58e254314528902 679545ff6c1e4401adcafa0857aefe2e] [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Terminating instance
  2013-11-21 11:31:31.571 19098 ERROR nova.virt.libvirt.driver [-] [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] During wait destroy, instance disappeared.
  2013-11-21 11:31:31.845 19098 ERROR nova.virt.libvirt.vif [req-8b32d1cd-42be-4daa-a3a3-2a1429d199c3 b94edf2504c84223b58e254314528902 679545ff6c1e4401adcafa0857aefe2e] [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Failed while unplugging vif
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Traceback (most recent call last):
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/vif.py", line 666, in unplug_mlnx_direct
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     vnic_mac, run_as_root=True)
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/utils.py", line 177, in execute
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     return processutils.execute(*cmd, **kwargs)
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/openstack/common/processutils.py", line 178, in execute
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     cmd=' '.join(cmd))
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] ProcessExecutionError: Unexpected error while running command.
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Command: sudo nova-rootwrap /etc/nova/rootwrap.conf ebrctl del-port default fa:16:3e:24:92:1f
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Exit code: 1
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Stdout: ''
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Stderr: 'ERROR:eswitchd.cli.conn_utils:Action  delete_port failed: Detach vnic failed\nError in del-port commandAction  delete_port failed: Detach vnic failed'
  2013-11-21 11:31:31.845 19098 TRACE nova.virt.libvirt.vif [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]
  2013-11-21 11:31:31.988 19098 INFO nova.virt.libvirt.driver [req-8b32d1cd-42be-4daa-a3a3-2a1429d199c3 b94edf2504c84223b58e254314528902 679545ff6c1e4401adcafa0857aefe2e] [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Deletion of /var/lib/nova/instances/013c675b-1bd6-402e-8e73-7d99a4222cc8 complete
  2013-11-21 11:31:32.359 19098 ERROR nova.compute.manager [req-8b32d1cd-42be-4daa-a3a3-2a1429d199c3 b94edf2504c84223b58e254314528902 679545ff6c1e4401adcafa0857aefe2e] [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Error: Volume cff27c84-5f73-40e4-8356-72bd7b3e0b4f did not finish being created even after we waited 71 seconds or 60 attempts.
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] Traceback (most recent call last):
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1028, in _build_instance
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     context, instance, bdms)
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1393, in _prep_block_device
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     instance=instance)
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 1376, in _prep_block_device
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     self._await_block_device_map_created))
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/virt/block_device.py", line 283, in attach_block_devices
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     block_device_mapping)
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/virt/block_device.py", line 238, in attach
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     wait_func(context, vol['id'])
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 901, in _await_block_device_map_created
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]     attempts=attempts)
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8] VolumeNotCreated: Volume cff27c84-5f73-40e4-8356-72bd7b3e0b4f did not finish being created even after we waited 71 seconds or 60 attempts.
  2013-11-21 11:31:32.359 19098 TRACE nova.compute.manager [instance: 013c675b-1bd6-402e-8e73-7d99a4222cc8]

  This happens due to 60 attempts limitation in "/usr/lib/python2.6/site-packages/nova/compute/manager.py +879".
  need to change the "max_tries=60" default value at "_await_block_device_map_created()" OR at least make it configurable.
  after changing the value to "100" Instance spawned successfully.

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1253612/+subscriptions