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

Reply via email to