tempest

Conflict on isolated credential setup

Bug #1419043 reported by Sean Dague
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Identity (keystone)
Fix Released
Critical
Matthew Treinish
OpenStack Identity (keystone) 2015.1.0 "kilo"
Icehouse
Fix Released
Critical
Guang Yee
OpenStack Identity (keystone) 2014.1.4
Juno
Fix Released
Critical
Guang Yee
OpenStack Identity (keystone) 2014.2.3
tempest
Invalid
Undecided
Unassigned

Bug Description

From the following run (in progress) - http://logs.openstack.org/26/153426/2/gate/gate-tempest-dsvm-nova-v21-full/c80cf2c//console.html

2015-02-06 15:50:27.935 | ==============================
2015-02-06 15:50:27.935 | Failed 1 tests - output below:
2015-02-06 15:50:27.935 | ==============================
2015-02-06 15:50:27.935 |
2015-02-06 15:50:27.935 | setUpClass (tempest.api.compute.admin.test_aggregates_negative.AggregatesAdminNegativeTestJSON)
2015-02-06 15:50:27.936 | -----------------------------------------------------------------------------------------------
2015-02-06 15:50:27.936 |
2015-02-06 15:50:27.936 | Captured traceback:
2015-02-06 15:50:27.936 | ~~~~~~~~~~~~~~~~~~~
2015-02-06 15:50:27.936 | Traceback (most recent call last):
2015-02-06 15:50:27.936 | File "tempest/test.py", line 273, in setUpClass
2015-02-06 15:50:27.936 | cls.resource_setup()
2015-02-06 15:50:27.936 | File "tempest/api/compute/admin/test_aggregates_negative.py", line 31, in resource_setup
2015-02-06 15:50:27.936 | super(AggregatesAdminNegativeTestJSON, cls).resource_setup()
2015-02-06 15:50:27.936 | File "tempest/api/compute/base.py", line 341, in resource_setup
2015-02-06 15:50:27.936 | super(BaseComputeAdminTest, cls).resource_setup()
2015-02-06 15:50:27.936 | File "tempest/api/compute/base.py", line 44, in resource_setup
2015-02-06 15:50:27.937 | cls.os = cls.get_client_manager()
2015-02-06 15:50:27.937 | File "tempest/test.py", line 407, in get_client_manager
2015-02-06 15:50:27.937 | creds = cls.isolated_creds.get_primary_creds()
2015-02-06 15:50:27.937 | File "tempest/common/isolated_creds.py", line 273, in get_primary_creds
2015-02-06 15:50:27.937 | return self.get_credentials('primary')
2015-02-06 15:50:27.937 | File "tempest/common/isolated_creds.py", line 257, in get_credentials
2015-02-06 15:50:27.937 | credentials = self._create_creds(admin=is_admin)
2015-02-06 15:50:27.937 | File "tempest/common/isolated_creds.py", line 119, in _create_creds
2015-02-06 15:50:27.937 | tenant, email)
2015-02-06 15:50:27.937 | File "tempest/common/isolated_creds.py", line 65, in _create_user
2015-02-06 15:50:27.937 | username, password, tenant['id'], email)
2015-02-06 15:50:27.937 | File "tempest/services/identity/json/identity_client.py", line 168, in create_user
2015-02-06 15:50:27.938 | resp, body = self.post('users', post_body)
2015-02-06 15:50:27.938 | File "/opt/stack/new/tempest/.tox/full/local/lib/python2.7/site-packages/tempest_lib/common/rest_client.py", line 169, in post
2015-02-06 15:50:27.938 | return self.request('POST', url, extra_headers, headers, body)
2015-02-06 15:50:27.938 | File "tempest/common/service_client.py", line 69, in request
2015-02-06 15:50:27.938 | raise exceptions.Conflict(ex)
2015-02-06 15:50:27.938 | Conflict: An object with that identifier already exists
2015-02-06 15:50:27.938 | Details: An object with that identifier already exists
2015-02-06 15:50:27.938 | Details: {u'title': u'Conflict', u'message': u'Conflict occurred attempting to store role - Duplicate Entry', u'code': 409}
2015-02-06 15:50:27.938 |

Some how isolated_credential calls are failing.

It appears that this might be racing on creating identical roles on multiple users - http://logs.openstack.org/26/153426/2/gate/gate-tempest-dsvm-nova-v21-full/c80cf2c//logs/apache/keystone.txt.gz#_2015-02-06_15_27_17_988

That's about the time of the failure.

Revision history for this message
Sean Dague (sdague) wrote :

It looks like keystone races in setting up default role when creating 2 users simultaneously.

2015-02-06 15:27:17.980468 25961 INFO keystone.assignment.core [-] Creating the default role 9fe2ff9ee4384b1894a90878d3e92bab because it does not exist.
2015-02-06 15:27:17.982766 25959 INFO keystone.assignment.core [-] Creating the default role 9fe2ff9ee4384b1894a90878d3e92bab because it does not exist.
2015-02-06 15:27:17.988287 25959 DEBUG keystone.common.sql.core [-] Conflict role: (IntegrityError) (1062, "Duplicate entry '9fe2ff9ee4384b1894a90878d3e92bab' for key 'PRIMARY'") 'INSERT INTO role (id, name, extra) VALUES (%s, %s, %s)' ('9fe2ff9ee4384b1894a90878d3e92bab', '_member_', '{}') wrapper /opt/stack/new/keystone/keystone/common/sql/core.py:399
2015-02-06 15:27:17.988978 25959 WARNING keystone.common.wsgi [-] Conflict occurred attempting to store role - Duplicate Entry

That speaks to a deep race in the keystone allocator that should be fixed.

Changed in tempest:
importance: Undecided → High
Changed in keystone:
importance: Undecided → Critical
Revision history for this message
Matthew Treinish (treinish) wrote :

Looking at the code in:

http://git.openstack.org/cgit/openstack/keystone/tree/keystone/assignment/core.py#n236

It looks to me like if there are 2 incoming requests for a new user requests at roughly the same time and the role hasn't been created yet the 2 requests will race to create the role. I'll push out a fix soon that'll just add a lock to make sure this doesn't happen and only one can create the role.

Changed in keystone:
assignee: nobody → Matthew Treinish (treinish)
status: New → Confirmed
Revision history for this message
Matthew Treinish (treinish) wrote :

Looking through the failure logs this doesn't appear to be a tempest issue. Tempest is just triggering a race in keystone.

Changed in tempest:
importance: High → Undecided
status: New → Invalid
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (master)

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

Changed in keystone:
status: Confirmed → In Progress
Morgan Fainberg (mdrnstm)
Changed in keystone:
milestone: none → kilo-3
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to keystone (master)

Reviewed: https://review.openstack.org/153656
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=0b1027886ae6bc29abd86aa8ede499be5f5fc2ae
Submitter: Jenkins
Branch: master

commit 0b1027886ae6bc29abd86aa8ede499be5f5fc2ae
Author: Matthew Treinish <email address hidden>
Date: Fri Feb 6 13:52:00 2015 -0500

    Fix race on default role creation

    In add_user_to_project() it checks if the default role exists before
    trying to add the role to the user and project. If it doesn't exist it
    will attempt to create the role. However if 2 requests happen at
    roughly the same time the 2 role creations will race causing one to
    fail with a conflict error. This patch addresses this issue by catching
    the conflict exception and treating it as the create succeeded (which it
    did just elsewhere)

    Change-Id: Iab95ed8b3913c020eafa919231d764ba8b780571
    Closes-Bug: #1419043

Changed in keystone:
status: In Progress → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (stable/juno)

Fix proposed to branch: stable/juno
Review: https://review.openstack.org/153713

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on keystone (stable/juno)

Change abandoned by guang-yee (<email address hidden>) on branch: stable/juno
Review: https://review.openstack.org/153713
Reason: Yikes, doesn't appear to do auto member role creation in juno

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to keystone (stable/icehouse)

Fix proposed to branch: stable/icehouse
Review: https://review.openstack.org/153721

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to keystone (stable/juno)

Reviewed: https://review.openstack.org/153713
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=b84e22be601f9f6fc48a9e10a3fb508c576b1d93
Submitter: Jenkins
Branch: stable/juno

commit b84e22be601f9f6fc48a9e10a3fb508c576b1d93
Author: Matthew Treinish <email address hidden>
Date: Fri Feb 6 13:52:00 2015 -0500

    Fix race on default role creation

    In add_user_to_project() it checks if the default role exists before
    trying to add the role to the user and project. If it doesn't exist it
    will attempt to create the role. However if 2 requests happen at
    roughly the same time the 2 role creations will race causing one to
    fail with a conflict error. This patch addresses this issue by catching
    the conflict exception and treating it as the create succeeded (which it
    did just elsewhere)

    Conflicts:
     keystone/assignment/core.py

    Change-Id: Iab95ed8b3913c020eafa919231d764ba8b780571
    Closes-Bug: #1419043
    (cherry picked from commit 0b1027886ae6bc29abd86aa8ede499be5f5fc2ae)

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to keystone (stable/icehouse)

Reviewed: https://review.openstack.org/153721
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=5d2e2ce698eff6a328c2cbf9ab91901f95ba8958
Submitter: Jenkins
Branch: stable/icehouse

commit 5d2e2ce698eff6a328c2cbf9ab91901f95ba8958
Author: Matthew Treinish <email address hidden>
Date: Fri Feb 6 13:52:00 2015 -0500

    Fix race on default role creation

    In add_user_to_project() it checks if the default role exists before
    trying to add the role to the user and project. If it doesn't exist it
    will attempt to create the role. However if 2 requests happen at
    roughly the same time the 2 role creations will race causing one to
    fail with a conflict error. This patch addresses this issue by catching
    the conflict exception and treating it as the create succeeded (which it
    did just elsewhere)

    Conflicts:
     keystone/assignment/core.py

    Change-Id: Iab95ed8b3913c020eafa919231d764ba8b780571
    Closes-Bug: #1419043
    (cherry picked from commit 0b1027886ae6bc29abd86aa8ede499be5f5fc2ae)

Thierry Carrez (ttx)
Changed in keystone:
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in keystone:
milestone: kilo-3 → 2015.1.0
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

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