← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1632075] [NEW] Nova Unexpected API error when launching instance

 

Public bug reported:

I am new to Openstack. I just created a three node installation. 
I am following the instructions on http://docs.openstack.org/kilo/install-guide/install/apt/openstack-install-guide-apt-kilo.pdf 
I created the image and tried to launch an instance. The command 

 nova boot --flavor m1.tiny --image cirros-0.3.4-x86_64 --nic net-
id=189adb53-86fc-4163-8344-19195111aad7 --security-group default --key-
name demo-key ARTURO

took 30 seconds and then failed with the following message:

ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'oslo_messaging.exceptions.MessagingTimeout'> (HTTP 500) (Request-ID: req-4d7a1129-9b7e-4eb7-a673-e2750f646260)
root@controller:~#
root@controller:~# nova boot --flavor m1.tiny --image cirros-0.3.4-x86_64 --nic net-id=189adb53-86fc-4163-8344-19195111aad7 --security-group default --key-name demo-key ARTURO
ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'oslo_messaging.exceptions.MessagingTimeout'> (HTTP 500) (Request-ID: req-83fe2d4b-4b81-4b66-ae86-770e67a53078)


This is the piece of nova-api logfile that I catched after running the instance launch:


P/1.1" status: 404 len: 298 time: 0.0182340
2016-10-10 19:10:23.704 31936 INFO nova.osapi_compute.wsgi.server [req-5e920b8f-ff9d-441d-8192-916f7718a1ea 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] 192.168.5.140 "GET /v2/99c381588bd4474d8ff67d7d263ad4ec/flavors?is_public=None HTTP/1.1" status: 200 len: 1407 time: 0.0167220
2016-10-10 19:10:23.722 31936 INFO nova.osapi_compute.wsgi.server [req-fcfb8fe7-8716-4e72-90b6-f41cb1acfd28 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] 192.168.5.140 "GET /v2/99c381588bd4474d8ff67d7d263ad4ec/flavors/1 HTTP/1.1" status: 200 len: 615 time: 0.0156641


2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions [req-83fe2d4b-4b81-4b66-ae86-770e67a53078 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] Unexpected exception in API method
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions Traceback (most recent call last):
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/extensions.py", line 478, in wrapped
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 73, in wrapper
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 73, in wrapper
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 73, in wrapper
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/servers.py", line 629, in create
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     **create_kwargs)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/hooks.py", line 154, in inner
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     rv = f(*args, **kwargs)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 1556, in create
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     check_server_group_quota=check_server_group_quota)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 1139, in _create_instance
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     reservation_id, max_count)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 834, in _validate_and_build_base_options
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     requested_networks, max_count)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 448, in _check_requested_networks
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     max_count)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/network/api.py", line 49, in wrapped
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return func(self, context, *args, **kwargs)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/network/api.py", line 399, in validate_networks
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     requested_networks)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/network/rpcapi.py", line 212, in validate_networks
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return self.client.call(ctxt, 'validate_networks', networks=networks)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 413, in call
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return self.prepare().call(ctxt, method, **kwargs)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     retry=self.retry)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     timeout=timeout, retry=retry)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 470, in send
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     retry=retry)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 459, in _send
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     result = self._waiter.wait(msg_id, timeout)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 342, in wait
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     message = self.waiters.get(msg_id, timeout=timeout)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 244, in get
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     'to message ID %s' % msg_id)
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions MessagingTimeout: Timed out waiting for a reply to message ID 6a5a85b7720a4c1db73e5e75c025cdae
2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions
2016-10-10 19:11:23.788 31936 INFO nova.api.openstack.wsgi [req-83fe2d4b-4b81-4b66-ae86-770e67a53078 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'oslo_messaging.exceptions.MessagingTimeout'>
2016-10-10 19:11:23.793 31936 INFO nova.osapi_compute.wsgi.server [req-83fe2d4b-4b81-4b66-ae86-770e67a53078 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] 192.168.5.140 "POST /v2/99c381588bd4474d8ff67d7d263ad4ec/servers HTTP/1.1" status: 500 len: 447 time: 60.0676620


nova.conf details:

[DEFAULT]
dhcpbridge_flagfile=/etc/nova/nova.conf
dhcpbridge=/usr/bin/nova-dhcpbridge
logdir=/var/log/nova
state_path=/var/lib/nova
lock_path=/var/lock/nova
force_dhcp_release=True
libvirt_use_virtio_for_bridges=True
verbose=True
ec2_private_dns_show_ip=True
api_paste_config=/etc/nova/api-paste.ini
enabled_apis=ec2,osapi_compute,metadata
rpc_backend = rabbit
auth_strategy = keystone
my_ip = 192.168.5.140
vncserver_listen = 192.168.5.140
vncserver_proxyclient_address = 192.168.5.140
auth_uri = http://controller:5000
auth_url = http://controller:35357
auth_plugin = password
project_domain_id = default
user_domain_id = default
project_name = service
username = neutron
password = root

[database]
connection = mysql://nova:root@controller/nova

[keystone_authtoken]
auth_uri = http://controller:5000
auth_url = http://controller:35357
auth_plugin = password
project_domain_id = default
user_domain_id = default
project_name = service
username = nova
password = root

[oslo_messaging_rabbit]
rabbit_host = controller
rabbit_userid = openstack
rabbit_password = root

[glance]
host = controller

[oslo_concurrency]
lock_path = /var/lib/nova/tmp

[neutron]
url = http://controller:9696
service_metadata_proxy = True
metadata_proxy_shared_secret = root
auth_strategy = keystone
admin_auth_url = http://controller:35357/v2.0
admin_tenant_name = service
admin_username = neutron
admin_password = root

** Affects: nova
     Importance: Undecided
         Status: New

** Attachment added: "Nova logfile"
   https://bugs.launchpad.net/bugs/1632075/+attachment/4758859/+files/nova-api.log

-- 
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/1632075

Title:
  Nova Unexpected API error when launching instance

Status in OpenStack Compute (nova):
  New

Bug description:
  I am new to Openstack. I just created a three node installation. 
  I am following the instructions on http://docs.openstack.org/kilo/install-guide/install/apt/openstack-install-guide-apt-kilo.pdf 
  I created the image and tried to launch an instance. The command 

   nova boot --flavor m1.tiny --image cirros-0.3.4-x86_64 --nic net-
  id=189adb53-86fc-4163-8344-19195111aad7 --security-group default
  --key-name demo-key ARTURO

  took 30 seconds and then failed with the following message:

  ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'oslo_messaging.exceptions.MessagingTimeout'> (HTTP 500) (Request-ID: req-4d7a1129-9b7e-4eb7-a673-e2750f646260)
  root@controller:~#
  root@controller:~# nova boot --flavor m1.tiny --image cirros-0.3.4-x86_64 --nic net-id=189adb53-86fc-4163-8344-19195111aad7 --security-group default --key-name demo-key ARTURO
  ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'oslo_messaging.exceptions.MessagingTimeout'> (HTTP 500) (Request-ID: req-83fe2d4b-4b81-4b66-ae86-770e67a53078)

  
  This is the piece of nova-api logfile that I catched after running the instance launch:


  P/1.1" status: 404 len: 298 time: 0.0182340
  2016-10-10 19:10:23.704 31936 INFO nova.osapi_compute.wsgi.server [req-5e920b8f-ff9d-441d-8192-916f7718a1ea 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] 192.168.5.140 "GET /v2/99c381588bd4474d8ff67d7d263ad4ec/flavors?is_public=None HTTP/1.1" status: 200 len: 1407 time: 0.0167220
  2016-10-10 19:10:23.722 31936 INFO nova.osapi_compute.wsgi.server [req-fcfb8fe7-8716-4e72-90b6-f41cb1acfd28 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] 192.168.5.140 "GET /v2/99c381588bd4474d8ff67d7d263ad4ec/flavors/1 HTTP/1.1" status: 200 len: 615 time: 0.0156641


  
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions [req-83fe2d4b-4b81-4b66-ae86-770e67a53078 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] Unexpected exception in API method
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions Traceback (most recent call last):
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/extensions.py", line 478, in wrapped
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 73, in wrapper
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 73, in wrapper
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 73, in wrapper
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/servers.py", line 629, in create
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     **create_kwargs)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/hooks.py", line 154, in inner
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     rv = f(*args, **kwargs)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 1556, in create
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     check_server_group_quota=check_server_group_quota)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 1139, in _create_instance
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     reservation_id, max_count)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 834, in _validate_and_build_base_options
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     requested_networks, max_count)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 448, in _check_requested_networks
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     max_count)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/network/api.py", line 49, in wrapped
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return func(self, context, *args, **kwargs)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/network/api.py", line 399, in validate_networks
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     requested_networks)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/network/rpcapi.py", line 212, in validate_networks
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return self.client.call(ctxt, 'validate_networks', networks=networks)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 413, in call
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     return self.prepare().call(ctxt, method, **kwargs)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     retry=self.retry)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     timeout=timeout, retry=retry)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 470, in send
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     retry=retry)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 459, in _send
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     result = self._waiter.wait(msg_id, timeout)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 342, in wait
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     message = self.waiters.get(msg_id, timeout=timeout)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 244, in get
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions     'to message ID %s' % msg_id)
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions MessagingTimeout: Timed out waiting for a reply to message ID 6a5a85b7720a4c1db73e5e75c025cdae
  2016-10-10 19:11:23.786 31936 ERROR nova.api.openstack.extensions
  2016-10-10 19:11:23.788 31936 INFO nova.api.openstack.wsgi [req-83fe2d4b-4b81-4b66-ae86-770e67a53078 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'oslo_messaging.exceptions.MessagingTimeout'>
  2016-10-10 19:11:23.793 31936 INFO nova.osapi_compute.wsgi.server [req-83fe2d4b-4b81-4b66-ae86-770e67a53078 00df357eb20a408c9b2ee368fb02953d 99c381588bd4474d8ff67d7d263ad4ec - - -] 192.168.5.140 "POST /v2/99c381588bd4474d8ff67d7d263ad4ec/servers HTTP/1.1" status: 500 len: 447 time: 60.0676620

  
  nova.conf details:

  [DEFAULT]
  dhcpbridge_flagfile=/etc/nova/nova.conf
  dhcpbridge=/usr/bin/nova-dhcpbridge
  logdir=/var/log/nova
  state_path=/var/lib/nova
  lock_path=/var/lock/nova
  force_dhcp_release=True
  libvirt_use_virtio_for_bridges=True
  verbose=True
  ec2_private_dns_show_ip=True
  api_paste_config=/etc/nova/api-paste.ini
  enabled_apis=ec2,osapi_compute,metadata
  rpc_backend = rabbit
  auth_strategy = keystone
  my_ip = 192.168.5.140
  vncserver_listen = 192.168.5.140
  vncserver_proxyclient_address = 192.168.5.140
  auth_uri = http://controller:5000
  auth_url = http://controller:35357
  auth_plugin = password
  project_domain_id = default
  user_domain_id = default
  project_name = service
  username = neutron
  password = root

  [database]
  connection = mysql://nova:root@controller/nova

  [keystone_authtoken]
  auth_uri = http://controller:5000
  auth_url = http://controller:35357
  auth_plugin = password
  project_domain_id = default
  user_domain_id = default
  project_name = service
  username = nova
  password = root

  [oslo_messaging_rabbit]
  rabbit_host = controller
  rabbit_userid = openstack
  rabbit_password = root

  [glance]
  host = controller

  [oslo_concurrency]
  lock_path = /var/lib/nova/tmp

  [neutron]
  url = http://controller:9696
  service_metadata_proxy = True
  metadata_proxy_shared_secret = root
  auth_strategy = keystone
  admin_auth_url = http://controller:35357/v2.0
  admin_tenant_name = service
  admin_username = neutron
  admin_password = root

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


Follow ups