yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1652952] Re: nova api returns error on boot

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem@xxxxxxxxxx>
Date: Thu, 29 Dec 2016 20:20:18 -0000
Reply-to: Bug 1652952 <1652952@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
You can also refer to the Mitaka release notes:

http://docs.openstack.org/releasenotes/nova/mitaka.html

** Changed in: nova
       Status: New => Invalid

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

Title:
  nova api returns error on boot

Status in OpenStack Compute (nova):
  Invalid

Bug description:
  On attempting to execute nova boot, I get an sqalchemy error.   For
  example, the following command:

  nova boot --image ebc4576e-aebd-4852-a8ea-47eb238d06f5 --flavor
  m1.medium --availability-zone nova "Cirros1"

  Get this error:  ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'sqlalchemy.exc.ProgrammingError'> (HTTP 500) (Request-ID: req-3e168cb1-0930-453e-8b4c-b2fbbcf4a34e)

  Other nova operations (e.g. list services, images, ) work fine, so the
  API is up and running at least partially.

  The environment is as follows: nova-* version 13.1.2, python client
  version 3.3.1.

  Controller is running on Ubuntu 16.04 VM with MariaDB and RabbitMQ.
  Compute node is a separate machine with Ubuntu 16.04

  Full trace from nova-api.log below.   Thanks for your help!

  2016-12-28 11:05:24.930 4195 INFO nova.osapi_compute.wsgi.server [req-bfcd2a52-a075-4cb0-ad8e-c3692080a6d6 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] 192.168.1.190 "GET /v2/00520eb6df384f7eb6f41c5186347681 HTTP/1.1" status: 404 len: 264 time: 0.3224659
  2016-12-28 11:05:24.959 4195 INFO nova.osapi_compute.wsgi.server [req-8371ba5f-eff1-4ead-9343-4d1040d4ea8e 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] 192.168.1.190 "GET /v2/ HTTP/1.1" status: 200 len: 572 time: 0.0242190
  2016-12-28 11:05:26.108 4195 INFO nova.osapi_compute.wsgi.server [req-3e4d7666-81e6-4edb-b12d-5775ba134f2e 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] 192.168.1.190 "GET /v2/00520eb6df384f7eb6f41c5186347681/images/ebc4576e-aebd-4852-a8ea-47eb238d06f5 HTTP/1.1" status: 200 len: 877 time: 0.7298751
  2016-12-28 11:05:26.162 4195 INFO nova.api.openstack.wsgi [req-e500a326-20a9-4278-92c3-8c21661c5b75 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] HTTP exception thrown: Flavor m1.medium could not be found.
  2016-12-28 11:05:26.174 4195 INFO nova.osapi_compute.wsgi.server [req-e500a326-20a9-4278-92c3-8c21661c5b75 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] 192.168.1.190 "GET /v2/00520eb6df384f7eb6f41c5186347681/flavors/m1.medium HTTP/1.1" status: 404 len: 300 time: 0.0593221
  2016-12-28 11:05:26.240 4195 INFO nova.osapi_compute.wsgi.server [req-8fa4ad89-aabe-4077-a2c1-89e3f975abe7 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] 192.168.1.190 "GET /v2/00520eb6df384f7eb6f41c5186347681/flavors?is_public=None HTTP/1.1" status: 200 len: 1407 time: 0.0610151
  2016-12-28 11:05:26.308 4195 INFO nova.osapi_compute.wsgi.server [req-b8ad7ea8-10f6-4745-9eab-253e1849aa68 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] 192.168.1.190 "GET /v2/00520eb6df384f7eb6f41c5186347681/flavors/3 HTTP/1.1" status: 200 len: 619 time: 0.0634990
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions [req-489bfe3f-b2ee-404d-97fa-7cf64d3c9b98 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] Unexpected exception in API method
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions Traceback (most recent call last):
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/extensions.py", line 478, in wrapped
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 73, in wrapper
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 73, in wrapper
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/validation/__init__.py", line 73, in wrapper
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/servers.py", line 629, in create
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     **create_kwargs)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/hooks.py", line 154, in inner
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     rv = f(*args, **kwargs)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 1563, in create
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     check_server_group_quota=check_server_group_quota)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 1176, in _create_instance
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     instance_group, check_server_group_quota, filter_properties)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 1034, in _provision_instances
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     quotas.rollback()
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     self.force_reraise()
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     six.reraise(self.type_, self.value, self.tb)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 976, in _provision_instances
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     req_spec.create()
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 223, in wrapper
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     return fn(self, *args, **kwargs)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/objects/request_spec.py", line 432, in create
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     db_spec = self._create_in_db(self._context, updates)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/enginefacade.py", line 709, in wrapper
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     return fn(*args, **kwargs)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/nova/objects/request_spec.py", line 403, in _create_in_db
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     db_spec.save(context.session)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/models.py", line 48, in save
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     session.flush()
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2027, in flush
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     self._flush(objects)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2145, in _flush
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     transaction.rollback(_capture_exception=True)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     compat.reraise(exc_type, exc_value, exc_tb)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2109, in _flush
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     flush_context.execute()
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 373, in execute
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     rec.execute(self)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 532, in execute
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     uow
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 174, in save_obj
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     mapper, table, insert)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 800, in _emit_insert_statements
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     execute(statement, params)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 914, in execute
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     return meth(self, multiparams, params)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     return connection._execute_clauseelement(self, multiparams, params)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     compiled_sql, distilled_params
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     context)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     util.raise_from_cause(newraise, exc_info)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 200, in raise_from_cause
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     reraise(type(exception), exception, tb=exc_tb)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     context)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     cursor.execute(statement, parameters)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/cursors.py", line 158, in execute
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     result = self._query(query)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/cursors.py", line 308, in _query
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     conn.query(q)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 820, in query
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 1002, in _read_query_result
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     result.read()
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 1285, in read
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     first_packet = self.connection._read_packet()
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 966, in _read_packet
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     packet.check_error()
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 394, in check_error
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     err.raise_mysql_exception(self._data)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     _check_mysql_exception(errinfo)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions   File "/usr/lib/python2.7/dist-packages/pymysql/err.py", line 112, in _check_mysql_exception
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions     raise errorclass(errno, errorvalue)
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions ProgrammingError: (pymysql.err.ProgrammingError) (1146, u"Table 'nova.request_specs' doesn't exist") [SQL: u'INSERT INTO request_specs (created_at, updated_at, instance_uuid, spec) VALUES (%(created_at)s, %(updated_at)s, %(instance_uuid)s, %(spec)s)'] [parameters: {'instance_uuid': 'ebd32190-0ab4-438b-aaf7-b9c827ba7121', 'created_at': datetime.datetime(2016, 12, 28, 16, 5, 27, 105058), 'spec': '{"nova_object.version": "1.5", "nova_object.changes": ["instance_uuid", "retry", "num_instances", "pci_requests", "limits", "availability_zone", "force_nodes", "image", "instance_group", "force_hosts", "numa_topology", "flavor", "project_id", "scheduler_hints", "ignore_hosts"], "nova_object.name": "RequestSpec", "nova_object.data": {"instance_uuid": "ebd32190-0ab4-438b-aaf7-b9c827ba7121", "retry": null, "num_instances": 1, "pci_requests": {"nova_object.version": "1.1", "nova_object.changes": ["requests"], "nova_object.name": "InstancePCIRequests", "nova_object.data": {"requests": []}, "nova_object.namespace": "nova"}, "limits": {"nova_object.version": "1.0", "nova_object.changes": ["vcpu", "memory_mb", "numa_topology", "disk_gb"], "nova_object.name": "SchedulerLimits", "nova_object.data": {"vcpu": null, "memory_mb": null, "disk_gb": null, "numa_topology": null}, "nova_object.namespace": "nova"}, "availability_zone": "nova", "force_nodes": null, "image": {"nova_object.version": "1.8", "nova_object.changes": ["status", "name", "container_format", "created_at", "disk_format", "updated_at", "id", "owner", "min_ram", "checksum", "min_disk", "properties", "size"], "nova_object.name": "ImageMeta", "nova_object.data": {"status": "active", "created_at": "2016-12-22T21:42:42Z", "name": "CirrosTest", "container_format": "bare", "min_ram": 0, "disk_format": "qcow2", "updated_at": "2016-12-23T01:02:29Z", "id": "ebc4576e-aebd-4852-a8ea-47eb238d06f5", "min_disk": 0, "checksum": "133eae9fb1c98f45894a4e60d8736619", "owner": "00520eb6df384f7eb6f41c5186347681", "properties": {"nova_object.version": "1.12", "nova_object.name": "ImageMetaProps", "nova_object.data": {}, "nova_object.namespace": "nova"}, "size": 13200896}, "nova_object.namespace": "nova"}, "instance_group": null, "force_hosts": null, "numa_topology": null, "ignore_hosts": null, "flavor": {"nova_object.version": "1.1", "nova_object.name": "Flavor", "nova_object.data": {"disabled": false, "root_gb": 40, "name": "m1.medium", "flavorid": "3", "deleted": false, "created_at": null, "ephemeral_gb": 0, "updated_at": null, "memory_mb": 4096, "vcpus": 2, "extra_specs": {}, "swap": 0, "rxtx_factor": 1.0, "is_public": true, "deleted_at": null, "vcpu_weight": 0, "id": 1}, "nova_object.namespace": "nova"}, "project_id": "00520eb6df384f7eb6f41c5186347681", "scheduler_hints": {}}, "nova_object.namespace": "nova"}', 'updated_at': None}]
  2016-12-28 11:05:27.141 4195 ERROR nova.api.openstack.extensions 
  2016-12-28 11:05:27.149 4195 INFO nova.api.openstack.wsgi [req-489bfe3f-b2ee-404d-97fa-7cf64d3c9b98 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] HTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'sqlalchemy.exc.ProgrammingError'>
  2016-12-28 11:05:27.153 4195 INFO nova.osapi_compute.wsgi.server [req-489bfe3f-b2ee-404d-97fa-7cf64d3c9b98 3993d77f9aca46c69a1e8630899fb4d3 00520eb6df384f7eb6f41c5186347681 - - -] 192.168.1.190 "POST /v2/00520eb6df384f7eb6f41c5186347681/servers HTTP/1.1" status: 500 len: 436 time: 0.8414090

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

[Bug 1652952] [NEW] nova api returns error on boot
From: Alex Reznik, 2016-12-28