Public bug reported: Intermittent failures trying to boot an instance using devstack/master on precise VM. In most cases deleting the failed instance and retrying the boot command seems to work.
2013-12-03 11:28:24.514 DEBUG nova.compute.manager [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] Re-scheduling run_instance: attempt 1 from (pid=5873) _reschedule /opt/stack/nova/nova/compute/mana ger.py:1167 2013-12-03 11:28:24.514 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Making synchronous call on conductor ... from (pid=5873) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:553 2013-12-03 11:28:24.514 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] MSG_ID is ea9adfa2f6564cd193d6baec7bf7f8a3 from (pid=5873) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:556 2013-12-03 11:28:24.515 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] UNIQUE_ID is 33300a17273f4529bd36156c4406ada3. from (pid=5873) _add_unique_id /opt/stack/nova/nova/openstack/common/rpc/amqp.py:341 2013-12-03 11:28:24.627 DEBUG nova.openstack.common.lockutils [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Got semaphore "compute_resources" from (pid=5873) lock /opt/stack/nova/nova/openstack/common/lockutils.py:167 2013-12-03 11:28:24.628 DEBUG nova.openstack.common.lockutils [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Got semaphore / lock "update_usage" from (pid=5873) inner /opt/stack/nova/nova/openstack/common/lockutils.py:247 2013-12-03 11:28:24.628 DEBUG nova.openstack.common.lockutils [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Semaphore / lock released "update_usage" from (pid=5873) inner /opt/stack/nova/nova/openstack/common/lockutils.py:251 2013-12-03 11:28:24.630 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Making asynchronous cast on scheduler... from (pid=5873) cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:582 2013-12-03 11:28:24.630 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] UNIQUE_ID is 501ebe16dd814daaa37c648f8f9848df. from (pid=5873) _add_unique_id /opt/stack/nova/nova/openstack/common/rpc/amqp.py:341 2013-12-03 11:28:24.642 ERROR nova.compute.manager [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] Error: internal error process exited while connecting to monitor: char device redirected to /dev/pt s/30 Failed to allocate 536870912 B: Cannot allocate memory 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] Traceback (most recent call last): 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/compute/manager.py", line 1049, in _build_instance 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] set_access_ip=set_access_ip) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/compute/manager.py", line 1453, in _spawn 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] LOG.exception(_('Instance failed to spawn'), instance=instance) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/compute/manager.py", line 1450, in _spawn 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] block_device_info) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2161, in spawn 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] block_device_info) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3395, in _create_domain_and_network 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] domain = self._create_domain(xml, instance=instance, power_on=power_on) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3338, in _create_domain 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] domain.XMLDesc(0)) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3333, in _create_domain 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] domain.createWithFlags(launch_flags) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 179, in doit 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] result = proxy_call(self._autowrap, f, *args, **kwargs) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 139, in proxy_call 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] rv = execute(f,*args,**kwargs) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 77, in tworker 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] rv = meth(*args,**kwargs) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/usr/lib/python2.7/dist-packages/libvirt.py", line 581, in createWithFlags 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] libvirtError: internal error process exited while connecting to monitor: char device redirected to /dev/pts/30 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] Failed to allocate 536870912 B: Cannot allocate memory 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] 2013-12-03 11:28:24.650 DEBUG nova.openstack.common.lockutils [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Semaphore / lock released "do_run_instance" from (pid=5873) inner /opt/stack/nova/nova/openstack/common/lockutils.py:251 ** Affects: nova Importance: Undecided Status: New -- 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/1257420 Title: boot instance fails, libvirt unable to allocate memory Status in OpenStack Compute (Nova): New Bug description: Intermittent failures trying to boot an instance using devstack/master on precise VM. In most cases deleting the failed instance and retrying the boot command seems to work. 2013-12-03 11:28:24.514 DEBUG nova.compute.manager [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] Re-scheduling run_instance: attempt 1 from (pid=5873) _reschedule /opt/stack/nova/nova/compute/mana ger.py:1167 2013-12-03 11:28:24.514 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Making synchronous call on conductor ... from (pid=5873) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:553 2013-12-03 11:28:24.514 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] MSG_ID is ea9adfa2f6564cd193d6baec7bf7f8a3 from (pid=5873) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:556 2013-12-03 11:28:24.515 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] UNIQUE_ID is 33300a17273f4529bd36156c4406ada3. from (pid=5873) _add_unique_id /opt/stack/nova/nova/openstack/common/rpc/amqp.py:341 2013-12-03 11:28:24.627 DEBUG nova.openstack.common.lockutils [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Got semaphore "compute_resources" from (pid=5873) lock /opt/stack/nova/nova/openstack/common/lockutils.py:167 2013-12-03 11:28:24.628 DEBUG nova.openstack.common.lockutils [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Got semaphore / lock "update_usage" from (pid=5873) inner /opt/stack/nova/nova/openstack/common/lockutils.py:247 2013-12-03 11:28:24.628 DEBUG nova.openstack.common.lockutils [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Semaphore / lock released "update_usage" from (pid=5873) inner /opt/stack/nova/nova/openstack/common/lockutils.py:251 2013-12-03 11:28:24.630 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Making asynchronous cast on scheduler... from (pid=5873) cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:582 2013-12-03 11:28:24.630 DEBUG nova.openstack.common.rpc.amqp [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] UNIQUE_ID is 501ebe16dd814daaa37c648f8f9848df. from (pid=5873) _add_unique_id /opt/stack/nova/nova/openstack/common/rpc/amqp.py:341 2013-12-03 11:28:24.642 ERROR nova.compute.manager [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] Error: internal error process exited while connecting to monitor: char device redirected to /dev/pt s/30 Failed to allocate 536870912 B: Cannot allocate memory 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] Traceback (most recent call last): 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/compute/manager.py", line 1049, in _build_instance 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] set_access_ip=set_access_ip) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/compute/manager.py", line 1453, in _spawn 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] LOG.exception(_('Instance failed to spawn'), instance=instance) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/compute/manager.py", line 1450, in _spawn 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] block_device_info) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2161, in spawn 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] block_device_info) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3395, in _create_domain_and_network 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] domain = self._create_domain(xml, instance=instance, power_on=power_on) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3338, in _create_domain 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] domain.XMLDesc(0)) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3333, in _create_domain 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] domain.createWithFlags(launch_flags) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 179, in doit 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] result = proxy_call(self._autowrap, f, *args, **kwargs) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 139, in proxy_call 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] rv = execute(f,*args,**kwargs) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 77, in tworker 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] rv = meth(*args,**kwargs) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] File "/usr/lib/python2.7/dist-packages/libvirt.py", line 581, in createWithFlags 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self) 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] libvirtError: internal error process exited while connecting to monitor: char device redirected to /dev/pts/30 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] Failed to allocate 536870912 B: Cannot allocate memory 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] 2013-12-03 11:28:24.642 TRACE nova.compute.manager [instance: a186938b-f4a1-4ff7-8681-9243bb1f4236] 2013-12-03 11:28:24.650 DEBUG nova.openstack.common.lockutils [req-2f0c2c13-c726-4738-a541-60dbcf6e5ea4 demo demo] Semaphore / lock released "do_run_instance" from (pid=5873) inner /opt/stack/nova/nova/openstack/common/lockutils.py:251 To manage notifications about this bug go to: https://bugs.launchpad.net/nova/+bug/1257420/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : yahoo-eng-team@lists.launchpad.net Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp