Bug 848083 - Race condition in broker implicit user creation
Race condition in broker implicit user creation
Status: CLOSED CURRENTRELEASE
Product: OpenShift Origin
Classification: Red Hat
Component: Pod (Show other bugs)
2.x
Unspecified Unspecified
urgent Severity high
: ---
: ---
Assigned To: Dan McPherson
libra bugs
: Triaged
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2012-08-14 10:33 EDT by Clayton Coleman
Modified: 2015-05-14 22:02 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2012-09-17 17:29:52 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Clayton Coleman 2012-08-14 10:33:11 EDT
Executing two broker REST API GET calls when the user does not implicitly exist can result in one of them failing.  The broker is implementing get_or_create_user logic, but if the create call fails the broker is not using the existing user (instead it returns 500

The account page has switched to making parallel calls to the broker in order to speed up the long latency of the page, which triggers this every time in unit tests and some of the time when users log in and go directly to the account page.  This blocks US2516 completion.

Dump below:

Started GET "/broker/rest/user/keys.json" for 127.0.0.1 at Mon Aug 13 21:22:25 -0400 2012


Started GET "/broker/rest/user.json" for 127.0.0.1 at Mon Aug 13 21:22:25 -0400 2012
  Processing by KeysController#index as JSON
MongoDataStore.find(CloudUser, app_test113449073452eee53@test1.com, app_test113449073452eee53@test1.com)

  Processing by UserExtController#show as JSON
MongoDataStore.find(CloudUser, app_test113449073452eee53@test1.com, app_test113449073452eee53@test1.com)

Adding user app_test113449073452eee53@test1.com...inside base_controller
MongoDataStore.find(CloudUser, app_test113449073452eee53@test1.com, app_test113449073452eee53@test1.com)

Adding user app_test113449073452eee53@test1.com...inside base_controller
MongoDataStore.find(CloudUser, app_test113449073452eee53@test1.com, app_test113449073452eee53@test1.com)

DEBUG: Attempting to add user 'app_test113449073452eee53@test1.com'
MongoDataStore.create(CloudUser, app_test113449073452eee53@test1.com, app_test113449073452eee53@test1.com, #hidden)

Completed 500 Internal Server Error in 785ms
[REQ_ID=5a990aef4a474dc0a7cb8add5a0ab970] ACTION=SHOW_USER 

StickShift::UserException (User with login 'app_test113449073452eee53@test1.com' already exists):
  

Completed 200 OK in 788ms (Views: 7.5ms)
Rendered /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.13/lib/action_dispatch/middleware/templates/rescues/_trace.erb (4.2ms)
Rendered /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.13/lib/action_dispatch/middleware/templates/rescues/_request_and_response.erb (7.0ms)
Rendered /usr/lib/ruby/gems/1.8/gems/actionpack-3.0.13/lib/action_dispatch/middleware/templates/rescues/diagnostics.erb within rescues/layout (28.4ms)
Comment 1 Clayton Coleman 2012-08-14 10:33:49 EDT
We are expecting two simultaneous requests made by a new user to succeed (esp. two simultaneous GET operations).
Comment 2 Dan McPherson 2012-08-14 16:12:21 EDT
https://github.com/openshift/crankcase/pull/378
Comment 3 Meng Bo 2012-08-15 03:42:03 EDT
Changes has been merged in devenv_1990, move bug to ON_QA.
Comment 4 Meng Bo 2012-08-15 03:44:10 EDT
Checked this issue on devenv_1990, trigger three executions at the same time with non-exist user, no 500 error appears.




Started GET "/broker/rest/user/keys.json" for 127.0.0.1 at Wed Aug 15 03:40:02 -0400 2012
  Processing by KeysController#index as JSON
MongoDataStore.find(CloudUser, aaaxxxzzzvvv@redhat.com, aaaxxxzzzvvv@redhat.com)



Started GET "/broker/rest/user/keys.json" for 127.0.0.1 at Wed Aug 15 03:40:02 -0400 2012
  Processing by KeysController#index as JSON
MongoDataStore.find(CloudUser, aaaxxxzzzvvv@redhat.com, aaaxxxzzzvvv@redhat.com)



Started GET "/broker/rest/user/keys.json" for 127.0.0.1 at Wed Aug 15 03:40:02 -0400 2012
  Processing by KeysController#index as JSON
MongoDataStore.find(CloudUser, aaaxxxzzzvvv@redhat.com, aaaxxxzzzvvv@redhat.com)

Adding user aaaxxxzzzvvv@redhat.com...inside base_controller
MongoDataStore.find(CloudUser, aaaxxxzzzvvv@redhat.com, aaaxxxzzzvvv@redhat.com)

Adding user aaaxxxzzzvvv@redhat.com...inside base_controller
MongoDataStore.find(CloudUser, aaaxxxzzzvvv@redhat.com, aaaxxxzzzvvv@redhat.com)

Adding user aaaxxxzzzvvv@redhat.com...inside base_controller
MongoDataStore.find(CloudUser, aaaxxxzzzvvv@redhat.com, aaaxxxzzzvvv@redhat.com)

DEBUG: Attempting to add user 'aaaxxxzzzvvv@redhat.com'
MongoDataStore.create(CloudUser, aaaxxxzzzvvv@redhat.com, aaaxxxzzzvvv@redhat.com, #hidden)

DEBUG: Attempting to add user 'aaaxxxzzzvvv@redhat.com'
MongoDataStore.create(CloudUser, aaaxxxzzzvvv@redhat.com, aaaxxxzzzvvv@redhat.com, #hidden)

DEBUG: Attempting to add user 'aaaxxxzzzvvv@redhat.com'
MongoDataStore.create(CloudUser, aaaxxxzzzvvv@redhat.com, aaaxxxzzzvvv@redhat.com, #hidden)

[REQ_ID=4e7a4e0cc5e444c7ae56896ea5617da6] ACTION=LIST_KEYS Found 0 ssh keys
Completed 200 OK in 438ms (Views: 6.2ms)
[REQ_ID=17cd67a6ecfc44dbb42f82e3270a160c] ACTION=LIST_KEYS Found 0 ssh keys
Completed 200 OK in 446ms (Views: 1.1ms)
[REQ_ID=9d737bd791da49e2b0324b7f7e9ecae1] ACTION=LIST_KEYS Found 0 ssh keys
Completed 200 OK in 553ms (Views: 3.1ms)

Note You need to log in before you can comment on or make changes to this bug.