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