conductor breaks sqlite datetime fields

Bug #1084240 reported by Cory Stone
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
High
Russell Bryant

Bug Description

When using nova trunk with sqlite, instance updates fail to update datetime columns. Sqlite doesn't like strings being put into datetime columns. In his case, launched_at.

2012-11-28 12:53:09 3483 DEBUG nova.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_msg_id': u'8bc1666e8e5d49f996f8444e8acd3bea', u'_context_quota_class': None, u'_context_request_id': u'req-6184c2f3-4757-4dd3-8458-9cdc98d7fed2', u'_context_service_catalog': None, u'_context_user_name': None, u'_context_auth_token': '<SANITIZED>', u'args': {u'instance_uuid': u'8bbcbfef-1015-4ca1-ad2f-4a03f104a446', u'updates': {u'vm_state': u'active', u'task_state': None, u'expected_task_state': u'spawning', u'power_state': 1, u'launched_at': u'2012-11-28T18:53:09.747791'}}, u'_context_instance_lock_checked': False, u'_context_project_name': None, u'_context_is_admin': True, u'version': u'1.0', u'_context_project_id': u'account1', u'_context_timestamp': u'2012-11-28T18:51:53.162155', u'_context_read_deleted': u'no', u'_context_user_id': u'account1', u'method': u'instance_update', u'_context_remote_address': u'127.0.0.1'} _safe_log /opt/nova/nova/openstack/common/rpc/common.py:195
2012-11-28 12:53:09 3483 DEBUG nova.openstack.common.rpc.amqp [-] unpacked context: {'project_name': None, 'user_id': u'account1', 'roles': [u'admin'], 'timestamp': u'2012-11-28T18:51:53.162155', 'auth_token': '<SANITIZED>', 'remote_address': u'127.0.0.1', 'quota_class': None, 'is_admin': True, 'service_catalog': None, 'request_id': u'req-6184c2f3-4757-4dd3-8458-9cdc98d7fed2', 'instance_lock_checked': False, 'project_id': u'account1', 'user_name': None, 'read_deleted': u'no'} _safe_log /opt/nova/nova/openstack/common/rpc/common.py:195
2012-11-28 12:53:09 ERROR nova.exception [req-6184c2f3-4757-4dd3-8458-9cdc98d7fed2 account1 account1] DB exception wrapped.
2012-11-28 12:53:09 3483 TRACE nova.exception Traceback (most recent call last):
2012-11-28 12:53:09 3483 TRACE nova.exception File "/opt/nova/nova/exception.py", line 68, in _wrap
2012-11-28 12:53:09 3483 TRACE nova.exception return f(*args, **kwargs)
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1583, in flush
2012-11-28 12:53:09 3483 TRACE nova.exception self._flush(objects)
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1654, in _flush
2012-11-28 12:53:09 3483 TRACE nova.exception flush_context.execute()
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 331, in execute
2012-11-28 12:53:09 3483 TRACE nova.exception rec.execute(self)
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 475, in execute
2012-11-28 12:53:09 3483 TRACE nova.exception uow
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 59, in save_obj
2012-11-28 12:53:09 3483 TRACE nova.exception mapper, table, update)
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 485, in _emit_update_statements
2012-11-28 12:53:09 3483 TRACE nova.exception execute(statement, params)
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1449, in execute
2012-11-28 12:53:09 3483 TRACE nova.exception params)
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1584, in _execute_clauseelement
2012-11-28 12:53:09 3483 TRACE nova.exception compiled_sql, distilled_params
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1651, in _execute_context
2012-11-28 12:53:09 3483 TRACE nova.exception None, None)
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1647, in _execute_context
2012-11-28 12:53:09 3483 TRACE nova.exception context = constructor(dialect, self, conn, *args)
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 463, in _init_compiled
2012-11-28 12:53:09 3483 TRACE nova.exception param.append(processors[key](compiled_params[key]))
2012-11-28 12:53:09 3483 TRACE nova.exception File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/dialects/sqlite/base.py", line 166, in process
2012-11-28 12:53:09 3483 TRACE nova.exception raise TypeError("SQLite DateTime type only accepts Python "
2012-11-28 12:53:09 3483 TRACE nova.exception StatementError: SQLite DateTime type only accepts Python datetime and date objects as input. (original cause: TypeError: SQLite DateTime type only accepts Python datetime and date objects as input.) 'UPDATE instances SET updated_at=?, power_state=?, vm_state=?, task_state=?, launched_at=? WHERE instances.id = ?' [{'vm_state': u'active', 'task_state': None, u'instances_id': 1, 'launched_at': u' 2012-11-28T18:53:09.747791', 'power_state': 1}]
2012-11-28 12:53:09 3483 TRACE nova.exception
2012-11-28 12:53:09 3483 ERROR nova.openstack.common.rpc.amqp [-] Exception during message handling
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/openstack/common/rpc/amqp.py", line 276, in _process_data
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp rval = self.proxy.dispatch(ctxt, version, method, **args)
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/openstack/common/rpc/dispatcher.py", line 145, in dispatch
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/conductor/manager.py", line 51, in instance_update
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp context, instance_uuid, updates)
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/db/api.py", line 685, in instance_update_and_get_original
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp values)
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/db/sqlalchemy/api.py", line 127, in wrapper
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp return f(*args, **kwargs)
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/db/sqlalchemy/api.py", line 1831, in instance_update_and_get_original
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp copy_old_instance=True)
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/db/sqlalchemy/api.py", line 1889, in _instance_update
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp instance_ref.save(session=session)
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/db/sqlalchemy/models.py", line 55, in save
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp session.flush()
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/exception.py", line 73, in _wrap
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp raise DBError(e)
2012-11-28 12:53:09 3483 TRACE nova.openstack.common.rpc.amqp DBError: SQLite DateTime type only accepts Python datetime and date objects as input. (original cause: TypeError: SQLite DateTime type only accepts Python datetime and date objects as input.) 'UPDATE instances SET updated_at=?, power_state=?, vm_state=?, task_state=?, launched_at=? WHERE instances.id = ?' [{'vm_state': u'active', 'task_state': None, u'instances_id': 1, 'launched_at': u'2012-11-28T18:53:09.747791', 'power_state': 1}]

Revision history for this message
Russell Bryant (russellb) wrote :

Give this patch a try.

Changed in nova:
status: New → Triaged
importance: Undecided → High
assignee: nobody → Russell Bryant (russellb)
Revision history for this message
Russell Bryant (russellb) wrote :
Revision history for this message
Cory Stone (corystone) wrote :

This seems to work for me. No sqlite complaints.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

Fix proposed to branch: master
Review: https://review.openstack.org/17079

Changed in nova:
status: Triaged → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

Reviewed: https://review.openstack.org/17079
Committed: http://github.com/openstack/nova/commit/66e1a8b47544e225721f0ccd3a33580dde337793
Submitter: Jenkins
Branch: master

commit 66e1a8b47544e225721f0ccd3a33580dde337793
Author: Russell Bryant <email address hidden>
Date: Wed Nov 28 15:43:37 2012 -0500

    Convert datetimes for conductor instance_update.

    This patch ensures that jsonutils.to_primitive() is used on the updates
    being sent to conductor's instance_update method. This is primarily so
    that we convert datetimes to a string using a very specific format
    defined in the timeutils module. Then, in the conductor manager,
    convert these fields back into datetime objects using timeutils.

    The conversion to a string was already happening implicitly if you were
    using the kombu rpc driver. The reason is that kombu uses anyjson,
    which we hook in to and will automatically use our own to_primitive()
    to fix serialization problems for kombu. Doing it explicitly is better,
    and is required for the other rpc drivers to work.

    This is to address a problem with sqlite where it would raise an
    exception when we try to do an update to a datetime field with a string.

    Fix bug 1084240.

    Change-Id: I2d703a92df1e85f0f3a7a793b301fe16cbd81ff5

Changed in nova:
status: In Progress → Fix Committed
Thierry Carrez (ttx)
Changed in nova:
milestone: none → grizzly-2
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in nova:
milestone: grizzly-2 → 2013.1
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.