Activity log for bug #1431986

Date Who What changed Old value New value Message
2015-03-13 17:55:55 Ashwin Agate bug added bug
2015-03-13 18:15:33 Ashwin Agate description Seeing database deadlock error in ceilometer-collector logs when ceilometer-expirer runs at the same time. deadlock error Deadlock found when trying to get lock; try restarting transaction {code} 2015-03-12 04:30:03.875 26730 ERROR ceilometer.dispatcher.database [-] Failed to record metering data: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'INSERT INTO sample (meter_id, resource_id, volume, timestamp, recorded_at, message_signature, message_id) VALUES (%s, %s, %s, %s, %s, %s, %s)' (23L, 30218L, 1, Decimal('1426134602.661871'), Decimal('1426134602.737072'), '7693ba4aeb7af6583a90381ad8f155827a4d78dad8fe6cb6fa8b18b6ca7a101a', '72ad5a1d-c870-11e4-90cb-00fc1dc4bd2e') 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database Traceback (most recent call last): 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/dispatcher/database.py", line 92, in record_metering_data 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database self.meter_conn.record_metering_data(meter) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/storage/impl_sqlalchemy.py", line 345, in record_metering_data 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database message_id=data['message_id']) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 729, in execute 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database return meth(self, multiparams, params) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 322, in _execute_on_connection 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database return connection._execute_clauseelement(self, multiparams, params) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database compiled_sql, distilled_params 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 958, in _execute_context 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database context) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1155, in _handle_dbapi_exception 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database util.raise_from_cause(newraise, exc_info) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database reraise(type(exception), exception, tb=exc_tb) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 951, in _execute_context 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database context) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 436, in do_execute 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database cursor.execute(statement, parameters) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/MySQLdb/cursors.py", line 205, in execute 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database self.errorhandler(self, exc, value) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database raise errorclass, errorvalue 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database DBDeadlock: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'INSERT INTO sample (meter_id, resource_id, volume, timestamp, recorded_at, message_signature, message_id) VALUES (%s, %s, %s, %s, %s, %s, %s)' (23L, 30218L, 1, Decimal('1426134602.661871'), Decimal('1426134602.737072'), '7693ba4aeb7af6583a90381ad8f155827a4d78dad8fe6cb6fa8b18b6ca7a101a', '72ad5a1d-c870-11e4-90cb-00fc1dc4bd2e') {code} which is followed by savepoint error ('SAVEPOINT sa_savepoint_2 does not exist) {code} 2015-03-12 04:30:04.185 26730 ERROR ceilometer.dispatcher.database [-] Failed to record metering data: (OperationalError) (1305, 'SAVEPOINT sa_savepoint_2 does not exist') 'ROLLBACK TO SAVEPOINT sa_savepoint_2' () 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database Traceback (most recent call last): 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/dispatcher/database.py", line 92, in record_metering_data 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database self.meter_conn.record_metering_data(meter) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/storage/impl_sqlalchemy.py", line 338, in record_metering_data 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database data['resource_metadata']) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/storage/impl_sqlalchemy.py", line 311, in _create_resource 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database meta_map[_model]) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1350, in __exit__ 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database self.rollback() 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1322, in rollback 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database self._do_rollback() 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1384, in _do_rollback 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database self._savepoint, self._parent) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 550, in _rollback_to_savepoint_impl 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database self.engine.dialect.do_rollback_to_savepoint(self, name) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 427, in do_rollback_to_savepoint 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database connection.execute(expression.RollbackToSavepointClause(name)) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 729, in execute 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database return meth(self, multiparams, params) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 322, in _execute_on_connection 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database return connection._execute_clauseelement(self, multiparams, params) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database compiled_sql, distilled_params 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 958, in _execute_context 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database context) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1155, in _handle_dbapi_exception 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database util.raise_from_cause(newraise, exc_info) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database reraise(type(exception), exception, tb=exc_tb) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 951, in _execute_context 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database context) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 436, in do_execute 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database cursor.execute(statement, parameters) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/MySQLdb/cursors.py", line 205, in execute 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database self.errorhandler(self, exc, value) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database raise errorclass, errorvalue 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database OperationalError: (OperationalError) (1305, 'SAVEPOINT sa_savepoint_2 does not exist') 'ROLLBACK TO SAVEPOINT sa_savepoint_2' () 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database {code} Looks like ceilometer-expirer is causing database deadlock to happen Seeing database deadlock error in ceilometer-collector logs when ceilometer-expirer runs at the same time. See two errors 1.) and 2.) below 1.) Deadlock error: Deadlock found when trying to get lock; try restarting transaction 2015-03-12 04:30:03.875 26730 ERROR ceilometer.dispatcher.database [-] Failed to record metering data: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'INSERT INTO sample (meter_id, resource_id, volume, timestamp, recorded_at, message_signature, message_id) VALUES (%s, %s, %s, %s, %s, %s, %s)' (23L, 30218L, 1, Decimal('1426134602.661871'), Decimal('1426134602.737072'), '7693ba4aeb7af6583a90381ad8f155827a4d78dad8fe6cb6fa8b18b6ca7a101a', '72ad5a1d-c870-11e4-90cb-00fc1dc4bd2e') 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database Traceback (most recent call last): 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/dispatcher/database.py", line 92, in record_metering_data 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database self.meter_conn.record_metering_data(meter) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/storage/impl_sqlalchemy.py", line 345, in record_metering_data [...] 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database self.errorhandler(self, exc, value) 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database raise errorclass, errorvalue 2015-03-12 04:30:03.875 26730 TRACE ceilometer.dispatcher.database DBDeadlock: (OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction') 'INSERT INTO sample (meter_id, resource_id, volume, timestamp, recorded_at, message_signature, message_id) VALUES (%s, %s, %s, %s, %s, %s, %s)' (23L, 30218L, 1, Decimal('1426134602.661871'), Decimal('1426134602.737072'), '7693ba4aeb7af6583a90381ad8f155827a4d78dad8fe6cb6fa8b18b6ca7a101a', '72ad5a1d-c870-11e4-90cb-00fc1dc4bd2e') 2.) Savepoint Error Which is followed by savepoint error ('SAVEPOINT sa_savepoint_2 does not exist) 2015-03-12 04:30:04.185 26730 ERROR ceilometer.dispatcher.database [-] Failed to record metering data: (OperationalError) (1305, 'SAVEPOINT sa_savepoint_2 does not exist') 'ROLLBACK TO SAVEPOINT sa_savepoint_2' () 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database Traceback (most recent call last): 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/dispatcher/database.py", line 92, in record_metering_data 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database self.meter_conn.record_metering_data(meter) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/storage/impl_sqlalchemy.py", line 338, in record_metering_data 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database data['resource_metadata']) 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database File "/opt/stack/venvs/openstack/local/lib/python2.7/site-packages/ceilometer/storage/impl_sqlalchemy.py", line 311, in _create_resource 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database meta_map[_model]) [...] 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database raise errorclass, errorvalue 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database OperationalError: (OperationalError) (1305, 'SAVEPOINT sa_savepoint_2 does not exist') 'ROLLBACK TO SAVEPOINT sa_savepoint_2' () 2015-03-12 04:30:04.185 26730 TRACE ceilometer.dispatcher.database Looks like ceilometer-expirer is causing database deadlock to happen. Possible solution: Changing the expirer to delete from one table at a time and then doing a commit, instead of deleting from all the tables sample, resource and meter in a single transaction
2015-03-13 18:20:41 Ashwin Agate summary ceilometer expirer causes database deadlock when collector is running Database deadlock in ceilometer-collector when ceilometer-expirer is running
2015-03-18 18:37:18 Ashwin Agate ceilometer: assignee Ashwin Agate (ashwin-agate)
2015-03-18 19:09:39 OpenStack Infra ceilometer: status New In Progress
2015-08-12 19:33:01 gordon chung ceilometer: importance Undecided Low
2015-08-31 21:32:21 OpenStack Infra ceilometer: assignee Ashwin Agate (ashwin-agate) ZhiQiang Fan (aji-zqfan)
2015-09-17 17:30:31 gordon chung ceilometer: milestone liberty-rc1
2015-09-19 11:50:57 OpenStack Infra ceilometer: status In Progress Fix Committed
2015-09-25 07:47:02 Thierry Carrez ceilometer: status Fix Committed Fix Released
2015-09-26 10:11:58 OpenStack Infra tags in-stable-kilo
2015-10-11 16:17:26 Chuck Short nominated for series ceilometer/kilo
2015-10-11 16:17:26 Chuck Short bug task added ceilometer/kilo
2015-10-11 16:17:35 Chuck Short ceilometer/kilo: status New Fix Committed
2015-10-11 16:17:40 Chuck Short ceilometer/kilo: milestone 2015.1.2
2015-10-13 18:26:42 Chuck Short ceilometer/kilo: status Fix Committed Fix Released
2015-10-15 09:41:48 Thierry Carrez ceilometer: milestone liberty-rc1 5.0.0
2016-01-21 20:18:20 Dave Walker ceilometer/kilo: status Fix Released Fix Committed
2016-01-21 20:18:20 Dave Walker ceilometer/kilo: milestone 2015.1.2 2015.1.3
2016-01-21 23:11:56 Dave Walker ceilometer/kilo: status Fix Committed Fix Released