yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1171190] Re: sql error when launching an instance from a volume

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Thierry Carrez <thierry.carrez+lp@xxxxxxxxx>
Date: Wed, 29 May 2013 10:17:37 -0000
Reply-to: Bug 1171190 <1171190@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: nova
       Status: Fix Committed => Fix Released

** Changed in: nova
    Milestone: None => havana-1

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

Title:
  sql error when launching an instance from a volume

Status in OpenStack Compute (Nova):
  Fix Released
Status in OpenStack Compute (nova) grizzly series:
  In Progress

Bug description:
  When trying to launch a new instance (in Horizon) and boot from a
  existing volume sql exception is thrown and the request is
  unsuccessful.

  I'm using grizzly on Ubuntu 12.04 with PostgreSQL database. Following
  stacktrace is logged in nova-api.log:

  2013-04-21 18:58:02.821 7737 INFO nova.osapi_compute.wsgi.server [-]
  (7737) accepted ('172.25.128.51', 46344)

  2013-04-21 18:58:02.840 INFO nova.osapi_compute.wsgi.server [req-
  ff87c82b-f349-448e-b296-1623c00adb50 9ec7d20683fd483090b26f9256c79cd6
  f99bc13849b34ea2b2f5a22b7067185e] 172.25.128.51 "GET
  /v2/f99bc13849b34ea2b2f5a22b7067185e/flavors/detail HTTP/1.1" status:
  200 len: 2293 time: 0.0175982

  2013-04-21 18:58:02.845 7737 INFO nova.osapi_compute.wsgi.server [-]
  (7737) accepted ('172.25.128.51', 46345)

  2013-04-21 18:58:02.855 INFO nova.osapi_compute.wsgi.server [req-
  ce0d01af-9639-457e-b720-97a6abdf6822 9ec7d20683fd483090b26f9256c79cd6
  f99bc13849b34ea2b2f5a22b7067185e] 172.25.128.51 "GET
  /v2/f99bc13849b34ea2b2f5a22b7067185e/os-keypairs HTTP/1.1" status: 200
  len: 702 time: 0.0090740

  2013-04-21 18:58:02.861 7737 INFO nova.osapi_compute.wsgi.server [-]
  (7737) accepted ('172.25.128.51', 46346)

  2013-04-21 18:58:02.893 INFO nova.osapi_compute.wsgi.server [req-
  0522038c-3afe-4793-89cb-acab8cdb478b 9ec7d20683fd483090b26f9256c79cd6
  f99bc13849b34ea2b2f5a22b7067185e] 172.25.128.51 "GET
  /v2/f99bc13849b34ea2b2f5a22b7067185e/os-security-groups HTTP/1.1"
  status: 200 len: 312 time: 0.0310581

  2013-04-21 18:58:03.261 7737 INFO nova.osapi_compute.wsgi.server [-]
  (7737) accepted ('172.25.128.51', 46353)

  2013-04-21 18:58:03.600 ERROR nova.openstack.common.db.sqlalchemy.session [req-fd50c447-0059-4064-a41e-6be723e456ec 9ec7d20683fd483090b26f9256c79cd6 f99bc13849b34ea2b2f5a22b7067185e] DB exception wrapped.
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session Traceback (most recent call last):
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/nova/openstack/common/db/sqlalchemy/session.py", line 415, in _wrap
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     return f(*args, **kwargs)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/nova/openstack/common/db/sqlalchemy/session.py", line 587, in flush
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     return super(Session, self).flush(*args, **kwargs)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1718, in flush
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     self._flush(objects)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1789, in _flush
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     flush_context.execute()
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 331, in execute
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     rec.execute(self)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 475, in execute
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     uow
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     table, insert)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 558, in _emit_insert_statements
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     execute(statement, params)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1449, in execute
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     params)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1584, in _execute_clauseelement
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     compiled_sql, distilled_params
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1698, in _execute_context
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     context)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1691, in _execute_context
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     context)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session   File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 331, in do_execute
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session     cursor.execute(statement, parameters)
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session DataError: (DataError) invalid input syntax for integer: ""
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session LINE 1: ...LL, NULL, '1d9e13e2-ee56-4d87-a24a-35d347048411', '', NULL, ...
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session                                                              ^
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session  'INSERT INTO block_device_mapping (created_at, updated_at, deleted_at, deleted, instance_uuid, device_name, delete_on_termination, virtual_name, snapshot_id, volume_id, volume_size, no_device, connection_info) VALUES (%(created_at)s, %(updated_at)s, %(deleted_at)s, %(deleted)s, %(instance_uuid)s, %(device_name)s, %(delete_on_termination)s, %(virtual_name)s, %(snapshot_id)s, %(volume_id)s, %(volume_size)s, %(no_device)s, %(connection_info)s) RETURNING block_device_mapping.id' {'instance_uuid': 'e97b64e8-c99e-4e1f-898c-212fa0c5409d', 'virtual_name': None, 'no_device': None, 'connection_info': None, 'created_at': datetime.datetime(2013, 4, 21, 15, 58, 3, 598268), 'volume_id': u'1d9e13e2-ee56-4d87-a24a-35d347048411', 'deleted': 0, 'updated_at': None, 'device_name': u'vda', 'volume_size': u'', 'snapshot_id': None, 'deleted_at': None, 'delete_on_termination': False}
  2013-04-21 18:58:03.600 7737 TRACE nova.openstack.common.db.sqlalchemy.session
  2013-04-21 18:58:03.628 ERROR nova.api.openstack [req-fd50c447-0059-4064-a41e-6be723e456ec 9ec7d20683fd483090b26f9256c79cd6 f99bc13849b34ea2b2f5a22b7067185e] Caught error: (DataError) invalid input syntax for integer: ""
  LINE 1: ...LL, NULL, '1d9e13e2-ee56-4d87-a24a-35d347048411', '', NULL, ...
                                                               ^
   'INSERT INTO block_device_mapping (created_at, updated_at, deleted_at, deleted, instance_uuid, device_name, delete_on_termination, virtual_name, snapshot_id, volume_id, volume_size, no_device, connection_info) VALUES (%(created_at)s, %(updated_at)s, %(deleted_at)s, %(deleted)s, %(instance_uuid)s, %(device_name)s, %(delete_on_termination)s, %(virtual_name)s, %(snapshot_id)s, %(volume_id)s, %(volume_size)s, %(no_device)s, %(connection_info)s) RETURNING block_device_mapping.id' {'instance_uuid': 'e97b64e8-c99e-4e1f-898c-212fa0c5409d', 'virtual_name': None, 'no_device': None, 'connection_info': None, 'created_at': datetime.datetime(2013, 4, 21, 15, 58, 3, 598268), 'volume_id': u'1d9e13e2-ee56-4d87-a24a-35d347048411', 'deleted': 0, 'updated_at': None, 'device_name': u'vda', 'volume_size': u'', 'snapshot_id': None, 'deleted_at': None, 'delete_on_termination': False}
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack Traceback (most recent call last):
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/__init__.py", line 81, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return req.get_response(self.application)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1296, in send
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     application, catch_exc_info=False)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1260, in call_application
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     app_iter = application(self.environ, start_response)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return resp(environ, start_response)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py", line 450, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return self.app(env, start_response)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return resp(environ, start_response)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return resp(environ, start_response)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return resp(environ, start_response)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     response = self.app(environ, start_response)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return resp(environ, start_response)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return self.func(req, *args, **kwargs)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py", line 890, in __call__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     content_type, body, accept)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py", line 942, in _process_stack
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     action_result = self.dispatch(meth, request, action_args)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py", line 1022, in dispatch
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return method(req=request, **action_args)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/servers.py", line 898, in create
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     scheduler_hints=scheduler_hints)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/hooks.py", line 85, in inner
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     rv = f(*args, **kwargs)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 962, in create
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     scheduler_hints=scheduler_hints)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 676, in _create_instance
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     reservation_id, scheduler_hints)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 634, in _validate_and_provision_instance
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     QUOTAS.rollback(context, quota_reservations)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     self.gen.next()
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 616, in _validate_and_provision_instance
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     num_instances, i)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 911, in create_db_entry_for_new_instance
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     instance_type, image, block_device_mapping)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 807, in _populate_instance_for_bdm
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     instance_type, instance_uuid, mapping)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/compute/api.py", line 773, in _update_block_device_mapping
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     values)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/db/api.py", line 1034, in block_device_mapping_update_or_create
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return IMPL.block_device_mapping_update_or_create(context, values)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 113, in wrapper
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     return f(*args, **kwargs)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 2875, in block_device_mapping_update_or_create
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     bdm_ref.save(session=session)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/openstack/common/db/sqlalchemy/models.py", line 54, in save
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     session.flush()
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/nova/openstack/common/db/sqlalchemy/session.py", line 436, in _wrap
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack     raise exception.DBError(e)
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack DBError: (DataError) invalid input syntax for integer: ""
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack LINE 1: ...LL, NULL, '1d9e13e2-ee56-4d87-a24a-35d347048411', '', NULL, ...
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack                                                              ^
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack  'INSERT INTO block_device_mapping (created_at, updated_at, deleted_at, deleted, instance_uuid, device_name, delete_on_termination, virtual_name, snapshot_id, volume_id, volume_size, no_device, connection_info) VALUES (%(created_at)s, %(updated_at)s, %(deleted_at)s, %(deleted)s, %(instance_uuid)s, %(device_name)s, %(delete_on_termination)s, %(virtual_name)s, %(snapshot_id)s, %(volume_id)s, %(volume_size)s, %(no_device)s, %(connection_info)s) RETURNING block_device_mapping.id' {'instance_uuid': 'e97b64e8-c99e-4e1f-898c-212fa0c5409d', 'virtual_name': None, 'no_device': None, 'connection_info': None, 'created_at': datetime.datetime(2013, 4, 21, 15, 58, 3, 598268), 'volume_id': u'1d9e13e2-ee56-4d87-a24a-35d347048411', 'deleted': 0, 'updated_at': None, 'device_name': u'vda', 'volume_size': u'', 'snapshot_id': None, 'deleted_at': None, 'delete_on_termination': False}
  2013-04-21 18:58:03.628 7737 TRACE nova.api.openstack

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