Inserting of event fails in postgresql

[Arthur Svechnikov]

Inserting of event fails in Postgresql. OS Ubuntu 12.04. Bug can reproduce by the command "nova keypair-add test". Some events should be added. Stacktrace of error:

2014-07-04 17:27:37.093 19815 DEBUG oslo.messaging._drivers.amqp [-] unpacked context: {'tenant': u'0d1667ff484941b9b5e97ec6e0b966f3', 'project_name': u'admin', 'user_id': u'1207fa8b3b4e42c1bcc15a19a398d607', 'roles': [u'admin', u'_member_', u'heat_stack_owner'], 'timestamp': u'2014-07-04T13:27:37.017705', 'auth_token': '<SANITIZED>', 'remote_address': u'xxx.xxx.xxx.xxx', 'quota_class': None, 'is_admin': True, 'user': u'1207fa8b3b4e42c1bcc15a19a398d607', 'service_catalog': [{u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://xxx.xxx.xxx.xxx:8776/v1/0d1667ff484941b9b5e97ec6e0b966f3', u'region': u'RegionOne', u'publicURL': u'http://xxx.xxx.xxx.xxx:8776/v1/0d1667ff484941b9b5e97ec6e0b966f3', u'internalURL': u'http://xxx.xxx.xxx.xxx:8776/v1/0d1667ff484941b9b5e97ec6e0b966f3', u'id': u'5a0b9c62c02a418295496c65372b124b'}], u'type': u'volume', u'name': u'cinder'}], 'request_id': u'req-1f083cbf-7bee-49c8-92d1-1d497a9a16df', 'instance_lock_checked': False, 'project_id': u'0d1667ff484941b9b5e97ec6e0b966f3', 'user_name': u'admin', 'read_deleted': u'no'} _safe_log /usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/common.py:193
2014-07-04 17:27:37.094 19815 DEBUG ceilometer.event.endpoint [-] Saving event "keypair.create.start" process_notification /opt/stack/ceilometer/ceilometer/event/endpoint.py:63
2014-07-04 17:27:37.116 19815 ERROR ceilometer.openstack.common.db.sqlalchemy.session [-] DB exception wrapped.
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session Traceback (most recent call last):
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/opt/stack/ceilometer/ceilometer/openstack/common/db/sqlalchemy/session.py", line 439, in _wrap
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session return f(self, *args, **kwargs)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/opt/stack/ceilometer/ceilometer/openstack/common/db/sqlalchemy/session.py", line 705, in flush
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session return super(Session, self).flush(*args, **kwargs)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1824, in flush
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session self._flush(objects)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1942, in _flush
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session transaction.rollback(_capture_exception=True)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session compat.reraise(exc_type, exc_value, exc_tb)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1906, in _flush
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session flush_context.execute()
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session rec.execute(self)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 525, in execute
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session uow
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session table, insert)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 569, in _emit_insert_statements
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session execute(statement, params)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in execute
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session params)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session compiled_sql, distilled_params
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in _execute_context
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session context)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1024, in _handle_dbapi_exception
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session exc_info
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 196, in raise_from_cause
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session reraise(type(exception), exception, tb=exc_tb)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 867, in _execute_context
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session context)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 324, in do_execute
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session cursor.execute(statement, parameters)
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session ProgrammingError: (ProgrammingError) column "generated" is of type double precision but expression is of type timestamp without time zone
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session LINE 1: ...) VALUES ('73197c42-4efe-4570-9d72-14e92850108c', '2014-07-0...
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session ^
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session HINT: You will need to rewrite or cast the expression.
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session 'INSERT INTO event (message_id, generated, event_type_id) VALUES (%(message_id)s, %(generated)s, %(event_type_id)s) RETURNING event.id' {'generated': datetime.datetime(2014, 7, 4, 13, 27, 37, 89016), 'event_type_id': 31, 'message_id': u'73197c42-4efe-4570-9d72-14e92850108c'}
2014-07-04 17:27:37.116 19815 TRACE ceilometer.openstack.common.db.sqlalchemy.session
2014-07-04 17:27:37.123 19815 ERROR ceilometer.storage.impl_sqlalchemy [-] Failed to record event: (ProgrammingError) column "generated" is of type double precision but expression is of type timestamp without time zone
LINE 1: ...) VALUES ('73197c42-4efe-4570-9d72-14e92850108c', '2014-07-0...
                                                             ^
HINT: You will need to rewrite or cast the expression.
 'INSERT INTO event (message_id, generated, event_type_id) VALUES (%(message_id)s, %(generated)s, %(event_type_id)s) RETURNING event.id' {'generated': datetime.datetime(2014, 7, 4, 13, 27, 37, 89016), 'event_type_id': 31, 'message_id': u'73197c42-4efe-4570-9d72-14e92850108c'}

[Arthur Svechnikov (asvechnikov)]

It seems that db structures are different for mysql and postgresql.

mysql> describe meter;
+-------+--------------+------+-----+---------+----------------+
| Field | Type | Null | Key | Default | Extra |
+-------+--------------+------+-----+---------+----------------+
| id | int(11) | NO | PRI | NULL | auto_increment |
| name | varchar(255) | NO | MUL | NULL | |
| type | varchar(255) | YES | | NULL | |
| unit | varchar(255) | YES | | NULL | |
+-------+--------------+------+-----+---------+----------------+

posgresql
ceilometer=# \d meter
                                         Table "public.meter"
      Column | Type | Modifiers
-------------------+-----------------------------+----------------------------------------------------
 id | integer | not null default nextval('meter_id_seq'::regclass)
 counter_name | character varying(255) |
 user_id | character varying(255) |
 project_id | character varying(255) |
 resource_id | character varying(255) |
 resource_metadata | text |
 counter_type | character varying(255) |
 counter_volume | double precision |
 timestamp | timestamp without time zone |
 message_signature | character varying(1000) |
 message_id | character varying(1000) |
 counter_unit | character varying(255) |
 recorded_at | timestamp without time zone |

[Arthur Svechnikov (asvechnikov)]

I mean that main problem in that

MySQL structure
Table | Column | Type
event | generated | double precision
sample| recorded_at| double precision

PostgreSQL structure
Table | Column | Type
event | generated | double precision
sample| recorded_at| timestamp without time zone

But sqlalchemy.model.PreciseTimestamp uses DateTime for PostgreSQL and Decimal for MySQL.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/106793
Committed: https://git.openstack.org/cgit/openstack/ceilometer/commit/?id=afc9834a34fee5a4aba4ba8d8bd46a2928207ec2
Submitter: Jenkins
Branch: master

commit afc9834a34fee5a4aba4ba8d8bd46a2928207ec2
Author: Artur Svechnikov <email address hidden>
Date: Mon Jul 14 19:22:25 2014 +0400

    Fix columns migrating for PostgreSQL

    Columns generated in event table and t_datetime in
    trait table shouldn't be type of double precision.

    Change-Id: Ib9c5c8de034b5d1ccaa070b6de7c0d682160200c
    Closes-Bug: #1337851