exception.ConstraintCheck in get_or_create_project()

[Dave McCowan]

Exception and Traceback in get_or_create_project().

Oct 20 02:58:54.015465 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:53.990 3656 ERROR barbican.model.repositories
Oct 20 02:58:54.015963 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.003 3657 DEBUG barbican.model.repositories [req-2f0ba979-3295-4532-859e-70472ccfd6e5 29821aca2cf94f41a49d4c1b7944e24c - - default default] Getting session... get_session /opt/stack/new/barbican/barbican/model/repositories.py:353
Oct 20 02:58:54.016430 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers [req-072cd426-220c-47e6-93e1-f7abead1784e 29821aca2cf94f41a49d4c1b7944e24c - - default default] Order creation failure seen - please contact site administrator.: ConstraintCheck: A defined SQL constraint check failed: u'pymysql.err.IntegrityError 1062, u"Duplicate entry \'c8a9e2717ed448f7b10579474f8fea2d\' for key \'uc_projects_external_ids\'" [SQL: u\'INSERT INTO projects id, created_at, updated_at, deleted_at, deleted, status, external_id VALUES %ids, %created_ats, %updated_ats, %deleted_ats, %deleteds, %statuss, %external_ids\'] [parameters: {\'status\': \'ACTIVE\', \'deleted\': 0, \'created_at\': datetime.datetime2017, 10, 20, 2, 58, 53, 979691, \'updated_at\': datetime.datetime2017, 10, 20, 2, 58, 53, 979691, \'deleted_at\': None, \'external_id\': u\'c8a9e2717ed448f7b10579474f8fea2d\', \'id\': \'f983dbee-a03f-4c70-8f02-b47dc2d94fcd\'}]',
Oct 20 02:58:54.016868 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers Traceback (most recent call last):
Oct 20 02:58:54.017014 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers File "/opt/stack/new/barbican/barbican/api/controllers/__init__.py", line 103, in handler
Oct 20 02:58:54.017164 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers return fn(inst, *args, **kwargs)
Oct 20 02:58:54.017314 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers File "/opt/stack/new/barbican/barbican/api/controllers/__init__.py", line 89, in enforcer
Oct 20 02:58:54.017454 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers return fn(inst, *args, **kwargs)
Oct 20 02:58:54.017603 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers File "/opt/stack/new/barbican/barbican/api/controllers/__init__.py", line 151, in content_types_enforcer
Oct 20 02:58:54.017749 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers return fn(inst, *args, **kwargs)
Oct 20 02:58:54.018930 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers File "/opt/stack/new/barbican/barbican/api/controllers/orders.py", line 203, in on_post
Oct 20 02:58:54.019096 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers project = res.get_or_create_project(external_project_id)
Oct 20 02:58:54.019249 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers File "/opt/stack/new/barbican/barbican/common/resources.py", line 49, in get_or_create_project
Oct 20 02:58:54.019396 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers project_repo.create_from(project)
Oct 20 02:58:54.019543 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers File "/opt/stack/new/barbican/barbican/model/repositories.py", line 411, in create_from
Oct 20 02:58:54.019698 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers raise exception.ConstraintCheck(error=error_msg)
Oct 20 02:58:54.019844 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers ConstraintCheck: A defined SQL constraint check failed: u'pymysql.err.IntegrityError 1062, u"Duplicate entry \'c8a9e2717ed448f7b10579474f8fea2d\' for key \'uc_projects_external_ids\'" [SQL: u\'INSERT INTO projects id, created_at, updated_at, deleted_at, deleted, status, external_id VALUES %ids, %created_ats, %updated_ats, %deleted_ats, %deleteds, %statuss, %external_ids\'] [parameters: {\'status\': \'ACTIVE\', \'deleted\': 0, \'created_at\': datetime.datetime2017, 10, 20, 2, 58, 53, 979691, \'updated_at\': datetime.datetime2017, 10, 20, 2, 58, 53, 979691, \'deleted_at\': None, \'external_id\': u\'c8a9e2717ed448f7b10579474f8fea2d\', \'id\': \'f983dbee-a03f-4c70-8f02-b47dc2d94fcd\'}]',
Oct 20 02:58:54.020280 ubuntu-xenial-infracloud-chocolate-0000332527 <email address hidden>[3654]: 2017-10-20 02:58:54.004 3656 ERROR barbican.api.controllers

[Dave McCowan (dave-mccowan)]

This is a race condition between "get" and "create". When "get" fails, then a create happens. With two threads running, each can have a "get" failure, followed by racing "creates".

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/514103
Committed: https://git.openstack.org/cgit/openstack/barbican/commit/?id=71829664b2ac4547c54940ad62bd8d0123f6e422
Submitter: Zuul
Branch: master

commit 71829664b2ac4547c54940ad62bd8d0123f6e422
Author: Dave McCowan <email address hidden>
Date: Sun Oct 22 22:19:26 2017 -0400

    Fix Race Condition in get_or_create_project()

    get_or_create_project() first calls a get (query of the database).
    If that fails, then it calls create. The issues is when
    there are two threads and both fail the original get, then
    each will call create. One of those creates will fail, resulting
    in the traceback.

    One way to protect this critical region is to call create first,
    then if that fails, call get.

    In this case, get_or_create_project() is called for every
    Barbican API operation. The create action (which is slow), happens
    once per project for the life of the cloud. The get action happens
    every other time. For performance gains, I left call get first,
    since that call succeeds almost always.

    Change-Id: I2f13b495a6b45e226e0742291f76ee88dbcf52df
    Closes-bug: #1726203

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/barbican 6.0.0.0b2 development milestone.