Mirantis OpenStack

Race condition while creating/deleting cinder volumes (Fuel 8.0 build 284)

Bug #1525905 reported by Ivan Lozgachev on 2015-12-14

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	Mirantis OpenStack	Fix Released	High	MOS Cinder	Mirantis OpenStack 8.0

Bug Description

Original test report can be found here http://mos-scale.vm.mirantis.net/test_results/build_8.0-284/jenkins-10_env_run_rally-91-ubuntu-MSK-2015-12-12-13:48:28-2015-12-13-12:58:29/rally_report.html#/CinderVolumes.create_and_delete_volume-3/failures

The error observed while running Rally tests. Traceback:

2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api Traceback (most recent call last):
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/taskflow/engines/action_engine/executor.py", line 82, in _execute_task
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api result = task.execute(**arguments)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/cinder/volume/flows/api/create_volume.py", line 551, in execute
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api reservations = QUOTAS.reserve(context, **reserve_opts)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/cinder/quota.py", line 808, in reserve
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api project_id=project_id)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/cinder/quota.py", line 399, in reserve
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api project_id=project_id)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/cinder/db/api.py", line 823, in quota_reserve
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api until_refresh, max_age, project_id=project_id)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 183, in wrapper
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api return f(*args, **kwargs)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 221, in wrapped
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api return f(*args, **kwargs)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 889, in quota_reserve
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api session=session)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/cinder/db/sqlalchemy/api.py", line 756, in _reservation_create
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api reservation_ref.save(session=session)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/oslo_db/sqlalchemy/models.py", line 48, in save
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api session.flush()
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2004, in flush
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api self._flush(objects)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2122, in _flush
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api transaction.rollback(_capture_exception=True)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api compat.reraise(exc_type, exc_value, exc_tb)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2086, in _flush
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api flush_context.execute()
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 373, in execute
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api rec.execute(self)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 532, in execute
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api uow
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 174, in save_obj
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api mapper, table, insert)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 781, in _emit_insert_statements
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api execute(statement, params)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 914, in execute
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api return meth(self, multiparams, params)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api return connection._execute_clauseelement(self, multiparams, params)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api compiled_sql, distilled_params
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api context)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api util.raise_from_cause(newraise, exc_info)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api reraise(type(exception), exception, tb=exc_tb)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api context)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api cursor.execute(statement, parameters)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 219, in execute
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api self.errorhandler(self, exc, value)
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 38, in defaulterrorhandler
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api raise errorvalue
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api DBDuplicateEntry: (_mysql_exceptions.IntegrityError) (1062, "Duplicate entry '74126' for key 'PRIMARY'") [SQL: u'INSERT INTO reservations (created_at, updated_at, deleted_at, deleted, uuid, usage_id, project_id, resource, delta, expire) VALUES (%s, %s, %s, %s, %s, %s, %s, %s, %s, %s)'] [parameters: (datetime.datetime(2015, 12, 13, 7, 43, 34, 403538), None, None, 0, '73bd13d5-99b6-4f7b-80b2-2bc4bd58f74b', 4220L, 'f2497e25b28f4f10ae2f14958f83e1c0', 'gigabytes', 1, datetime.datetime(2015, 12, 14, 7, 43, 34, 346873))]
2015-12-13 07:43:34.480 26104 ERROR cinder.volume.api

Original error trace from cinderclient:

Traceback (most recent call last):
  File "/opt/stack/.venv/lib/python2.7/site-packages/rally/task/runner.py", line 64, in _run_scenario_once
    method_name)(**kwargs) or scenario_output
  File "/opt/stack/.venv/lib/python2.7/site-packages/rally/plugins/openstack/scenarios/cinder/volumes.py", line 134, in create_and_delete_volume
    volume = self._create_volume(size, **kwargs)
  File "/opt/stack/.venv/lib/python2.7/site-packages/rally/task/atomic.py", line 84, in func_atomic_actions
    f = func(self, *args, **kwargs)
  File "/opt/stack/.venv/lib/python2.7/site-packages/rally/plugins/openstack/scenarios/cinder/utils.py", line 138, in _create_volume
    volume = self.clients("cinder").volumes.create(size, **kwargs)
  File "/opt/stack/.venv/lib/python2.7/site-packages/cinderclient/v1/volumes.py", line 187, in create
    return self._create('/volumes', body, 'volume')
  File "/opt/stack/.venv/lib/python2.7/site-packages/cinderclient/base.py", line 299, in _create
    resp, body = self.api.client.post(url, body=body)
  File "/opt/stack/.venv/lib/python2.7/site-packages/cinderclient/client.py", line 315, in post
    return self._cs_request(url, 'POST', **kwargs)
  File "/opt/stack/.venv/lib/python2.7/site-packages/cinderclient/client.py", line 275, in _cs_request
    **kwargs)
  File "/opt/stack/.venv/lib/python2.7/site-packages/cinderclient/client.py", line 258, in request
    raise exceptions.from_response(resp, body)
ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-d55120e5-914e-4f23-95f5-56e4b1427df1)

Please see attached cinder log.

Tags:

Revision history for this message

Ivan Lozgachev (ilozgachev) wrote on 2015-12-14:

cinder-api.log.1.tar.gz Edit (7.2 MiB, application/x-tar)

Nastya Urlapova (aurlapova) on 2015-12-14

Changed in fuel:
milestone:	none → 8.0
assignee:	nobody → MOS Cinder (mos-cinder)

Ilya Kutukov (ikutukov) on 2015-12-14

Changed in fuel:
status:	New → Confirmed
importance:	Undecided → Medium
importance:	Medium → High

Ivan Kolodyazhny (e0ne) on 2015-12-16

affects:	fuel → mos
Changed in mos:
milestone:	8.0 → none

Roman Podoliaka (rpodolyaka) on 2015-12-17

Changed in mos:
milestone:	none → 8.0

Revision history for this message

Ivan Kolodyazhny (e0ne) wrote on 2015-12-25:

FIx is already committed. We added retry-on-deadlock

Changed in mos:
status:	Confirmed → Fix Committed

Anastasia Kuznetsova (akuznetsova) on 2016-01-25

tags:

added: cinder scale

Anastasia Kuznetsova (akuznetsova) on 2016-01-25

tags:

added: area-cinder
removed: cinder

Revision history for this message

Ivan Lozgachev (ilozgachev) wrote on 2016-02-03:

Verified on ENV-10 Build 482 and ENV-14 Build 496

Changed in mos:
status:	Fix Committed → Fix Released

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Bug attachments

cinder-api.log.1.tar.gz Edit

Add attachment

Remote bug watches

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