5300 Avoid race conditions in Spree::StockItem #5406

kristinalim · 2020-05-12T07:13:03Z

What? Why?

References Products Sold Exceed Max Stock Level #5300

I've looked into #5300, exploring if the negative inventory levels could be related to a missing callback for guest checkout, subscriptions, and the now removed backorders, but this doesn't seem to be the case.

The issue seems to be that stock levels in Spree::StockItem, which we check for stock levels before completing an order, could be updated by another order before the stock level is updated by the current order.

This PR introduces two changes:

Optimistic locking for Spree::StockItem via lock_version.
Require count_on_hand in Spree::StockItem to be positive if not backorderable.

What should we test?

Scenario 1: Stock restrictions for customer checking out should still work. Open two browser sessions, one logged in as admin (Session A), another logged in as customer (Session B).

Session A: Set the stock level of a product to limited stock with e.g. 4.
Session B: Add less than total stock left to cart, e.g. 3.
Session A: Update the stock level of the product to be less than the quantity in cart, e.g. 2.
Session B: Attempt to check out. This should warn of insufficient stock.
Session B: Reduce quantity in cart, e.g. 2.
Session B: Checkout should succeed.

Scenario 2: Stock restrictions for admin setting up an order should still work. Open two browser sessions, both logged in as admin.

Session A: Set the stock level of a product to limited stock with e.g. 4.
Session B: Create an order, Add less than total stock left to cart, e.g. 3.
Session A: Update the stock level of the product to be less than the quantity in cart, e.g. 2.
Session B: Attempt to complete the order. This should succeed but reduce the quantity in the order to the max available.

Release notes

Address race condition resulting in orders exceeding available stock.

Changelog Category: Fixed

app/models/spree/stock_item_decorator.rb

luisramos0

Nice one @kristinalim
From what I read, with lock_version there will be some ActiveRecord::StaleObjectError exceptions be thrown. Do you know where and how will this affect the user journey?
Will this be a generic checkout error shown to the user?

I wonder if this can be tested in a concurrency spec like the checkout_controller_concurrency_spec.

app/models/spree/stock_item.rb

db/migrate/20200514174526_reset_negative_nonbackorderable_count_on_hand_in_stock_items.rb

spec/models/spree/line_item_spec.rb

mkllnk

There are some good changes in here but I'm not sure I understood where the root cause is. Are you assuming that an admin is updating the stock level while somebody checks out?

I also don't see any code dealing with the stale object errors. Is the plan to observe them in Bugsnag first to know when they actually happen?

app/models/spree/stock_item.rb

spec/models/spree/stock_item_spec.rb

mkllnk · 2020-05-20T08:00:47Z

app/models/spree/stock_item.rb

@@ -10,6 +10,7 @@ class StockItem < ActiveRecord::Base
    # rubocop:disable Rails/UniqueValidationWithoutIndex
    validates :variant_id, uniqueness: { scope: :stock_location_id }
    # rubocop:enable Rails/UniqueValidationWithoutIndex
+    validates :count_on_hand, numericality: { greater_than_or_equal_to: 0, unless: :backorderable? }


This will make the checkout fail. Did you test what the user would see in this scenario?

why is that?

as far as I can see, this should never happen, if it happens and if it blows up we will see it in bugsnag.

luisramos0 · 2020-05-27T09:56:05Z

@kristinalim please move back to Code Review when you think this is ready to be re-reviewed. Thanks!

luisramos0 · 2020-06-22T17:25:11Z

I am having a look at this.
I thought of creating PRs on top of Kristina's branch but Kristina may not be available in the next few days so I decided to work directly on Kristinas branch. I started by rebasing the PR and update stock_item to spree 2.1 (rails 4 version).

luisramos0 · 2020-06-22T19:41:09Z

I have found that checkout controller already contains this:
rescue ActiveRecord::StaleObjectError
So we will be ok on that front.

With this last version I tried reproducing the problem by placing two orders at the same time. I only get the correct behavior, one of the sessions gets this:

I am now trying to write a spec that simulates two users checking out at the same time with insufficient stock for both.
I am working at controller level extending spec/controllers/checkout_controller_concurrency_spec.rb

mkllnk · 2020-06-23T00:53:16Z

With this last version I tried reproducing the problem by placing two orders at the same time. I only get the correct behavior

And with master? Can you actually re-produce the error? I still don't know why the synchronisation doesn't work in this case.

luisramos0 · 2020-06-24T15:14:39Z

I was trying to extend https://github.com/openfoodfoundation/openfoodnetwork/blob/9e730e6445231c16396de2da7c33bff26c0aed74/spec/controllers/checkout_controller_concurrency_spec.rb

With a spec that would test for different orders with the same stock limited variant.
I can create a lot of deadlocks but they are not consistent...

I realize that the existing spec still passes without this:

And the second thread doesnt even get to the load_order call back.

Which is exactly the same problem in my attempt here.
I dont understand why the second thread doesnt even get to load_order... I cant underastand what's going on.

I have spent too much time on this already without success. So I am leaving it.
I suggest we just go ahead with this PR as is. Thoughts?

…em#stock_location

We are not using the return value of this method anywhere.

…r zero Fix setting of count on hand in line item specs

…from spree 2.0.4

luisramos0 · 2020-06-24T15:17:19Z

rebased to resolve conflicts.

sauloperez · 2020-07-16T15:17:27Z

This looks pretty good but I noticed this while reading https://api.rubyonrails.org/classes/ActiveRecord/Locking/Optimistic.html:

This locking mechanism will function inside a single Ruby process. To make it work across all web requests, the recommended approach is to add lock_version as a hidden field to your form.

We have two workers on our infra so this will be needed. It could come on a separate PR but the issue won't be fully fixed until we address this.

luisramos0 · 2020-07-16T15:23:44Z

yeah, this PR is not fixing 5300, just improving the situation.

@sauloperez can you clarify what exactly is preventing you from approving this PR? Is it the question to @mkllnk ?

sauloperez · 2020-07-16T15:33:17Z

I didn't notice this isn't closing #5300 . If this is about introducing optimistic locking while bringing in the necessary models, this is Test ready IMO.

filipefurtad0 · 2020-07-17T17:14:05Z

Hi @kristinalim ,

I tried to reproduce the issue as reported in #5300, but without success. I thank you for the detailed test cases! I went through them:

Scenario 1: Opened two browser sessions, one logged in as admin (Session A), another logged in as customer (Session B).

Session A: I've set the stock level of a product to the limited stock of 4.
Session B: Added 3 items
Session A: Updated the stock level of the product to 2.
Session B: Attempted to check out. This warned of insufficient stock, and redirected to the /cart page, as shown below:

Session B: Reduced quantity in cart to 2; While in the /cart page, pressing Update triggered the warning in the red tab appear again, although the quantity in car was already compatible with the available stock -> a "memory-effect" was observed while testing another PR (#5766). I will investigate this issue - system retaining previous state and showing previously shown warnings - and report later. <- After pressing Update a second time and making the warning disappear redirection to the checkout page followed.
Session B: Checkout succeed.

Scenario 2: Opened two browser sessions, both logged in as admin.

Session A: I've set the stock level of a product to limited stock, in this case, 4 items.
Session B: Created an order, adding less than total stock left to cart: 3 items.
Session A: Updated the stock level of the product to be less than the quantity in cart: I've set it to 2 items.
Session B: Attempting to complete the order displays the message "Error saving payment":

and triggers Bugnsnag:
https://app.bugsnag.com/open-food-france/open-food-france-prod/errors/5f11cd5d9f0dd90017a69e3d?event_id=5f11cd5d005b6e2ca49f0000&i=sk&m=nw

I have reproduced Scenario 2 with the same values in master-branch: the order is successfully created (Session B) and I verified that negative stock values are allowed:

Scenario 2 doesn't seem to be working as expected. Perhaps this PR could be improved? I'm moving it into In Dev for now. The other option would be to merge and open an issue on this concern. Please let me know if you find this beneficial in this case.

RachL · 2020-07-17T17:23:35Z

@filipefurtad0 I don't think Kristina will be able to pick this up as she has no time to contribute at the moment. As it looks to me that it is already improving the situation, without making what we have in prod worse, I would merge and open a dedicated issue. What do you think?

filipefurtad0 · 2020-07-17T20:33:59Z

Thank you for your feedback @RachL ,

I agree, the situation is improved: as Scenario 2 shows, after this PR it's not possible to reach negative stock levels, through backoffice orders - which is the second change introduced by the PR.

Opened issue #5784 about the error.

Thanks again!

luisramos0 · 2020-07-17T21:33:49Z

It's great you can replicate the problem Filipe! I thought we would not be able to replicate it.

I agree with the approach but I think 5784 is a sub-issue of 5300 and thus still an S2 to be worked on. Does that make sense?
If we can replicate 5784 locally I think it will be straight forward to add some defensive code to let the user know the product is out of stock.

filipefurtad0 · 2020-07-17T21:47:18Z

Cheers to @kristinalim and the wonderful testing notes! 🎉
Upgraded to S2, and moved to dev-ready.

Thanks @luisramos0 !

kristinalim self-assigned this May 12, 2020

kristinalim changed the title ~~Add optimistic locking to Spree::StockItem~~ 5300 Add optimistic locking to Spree::StockItem May 12, 2020

kristinalim changed the title ~~5300 Add optimistic locking to Spree::StockItem~~ 5300 [WIP] Add optimistic locking to Spree::StockItem May 12, 2020

kristinalim changed the title ~~5300 [WIP] Add optimistic locking to Spree::StockItem~~ 5300 [WIP] Avoid race conditions in Spree::StockItem May 12, 2020

kristinalim force-pushed the fix/5300-optimistic_locking_in_stock_items branch from b958358 to 37b8d48 Compare May 12, 2020 07:59

luisramos0 reviewed May 12, 2020

View reviewed changes

app/models/spree/stock_item_decorator.rb Outdated Show resolved Hide resolved

kristinalim force-pushed the fix/5300-optimistic_locking_in_stock_items branch 2 times, most recently from 9d2a8e1 to 089dab4 Compare May 14, 2020 08:56

kristinalim changed the title ~~5300 [WIP] Avoid race conditions in Spree::StockItem~~ 5300 Avoid race conditions in Spree::StockItem May 14, 2020

luisramos0 reviewed May 16, 2020

View reviewed changes

app/models/spree/stock_item.rb Show resolved Hide resolved

db/migrate/20200514174526_reset_negative_nonbackorderable_count_on_hand_in_stock_items.rb Show resolved Hide resolved

Matt-Yorkley reviewed May 18, 2020

View reviewed changes

spec/models/spree/line_item_spec.rb Show resolved Hide resolved

Matt-Yorkley approved these changes May 18, 2020

View reviewed changes

mkllnk reviewed May 20, 2020

View reviewed changes

luisramos0 force-pushed the fix/5300-optimistic_locking_in_stock_items branch from c03a678 to e4b346d Compare June 22, 2020 16:54

luisramos0 self-assigned this Jun 22, 2020

luisramos0 force-pushed the fix/5300-optimistic_locking_in_stock_items branch from b855fa2 to e4e037f Compare June 22, 2020 17:36

kristinalim added 9 commits June 24, 2020 16:15

Bring Spree::StockItem code from spree_core into the app

0e71183

Specify RSpec.describe in StockItem spec file

84d973d

Auto-correct violationso of Rubocop Style/RedundantSelf

b783118

Auto-correct violationso of Rubocop Style/*

0fd66f9

Auto-correct violationso of Rubocop Layout/*

d172501

Address violation of Rubocop Style/NumericPredicate

22c0693

Address violation of Rubocop Rails/ReadWriteAttribute

1e8543d

Address violation of Rubocop Rails/Delegate

2acf61f

Address violation of Rubocop Rails/Validation:

bc530b9

kristinalim and others added 10 commits June 24, 2020 16:15

Ignore Rails/UniqueValidationWithoutIndex for unique index of StockIt…

0a1cb71

…em#stock_location

Use break instead of return in StockItem#process_backorders

fb20f22

We are not using the return value of this method anywhere.

Update specs for StockItem with transpec

13ecf0e

Update stock item count on hand in Spree core specs

774b372

Add lock_version to Spree::StockItem

e539137

Require count on hand in non backorderable StockItem to be positive o…

4694f1b

…r zero Fix setting of count on hand in line item specs

Reset negative count on hand in existing non backorderable stock items

20fd3c2

Move rubocop exception to rubocop todo

e12e50a

Bring changes to stock_item from spree 2.1, the previous version was …

34207fc

…from spree 2.0.4

Restructure the spec a little

ba50491

luisramos0 force-pushed the fix/5300-optimistic_locking_in_stock_items branch from e4e037f to ba50491 Compare June 24, 2020 15:17

luisramos0 mentioned this pull request Jun 27, 2020

Make OFN independent of spree_core #4826

Closed

sauloperez approved these changes Jul 16, 2020

View reviewed changes

filipefurtad0 self-assigned this Jul 17, 2020

filipefurtad0 added the pr-staged-fr staging.coopcircuits.fr label Jul 17, 2020

filipefurtad0 removed the pr-staged-fr staging.coopcircuits.fr label Jul 17, 2020

filipefurtad0 mentioned this pull request Jul 17, 2020

Error 422 when placing backoffice orders with more items than those available on hand #5784

Open

luisramos0 merged commit 62a3b6b into openfoodfoundation:master Jul 17, 2020

luisramos0 mentioned this pull request Aug 3, 2020

Products Sold Exceed Max Stock Level #5300

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

5300 Avoid race conditions in Spree::StockItem #5406

5300 Avoid race conditions in Spree::StockItem #5406

kristinalim commented May 12, 2020 •

edited

luisramos0 left a comment

mkllnk left a comment

mkllnk May 20, 2020

sauloperez Jul 16, 2020

luisramos0 Jul 16, 2020

luisramos0 commented May 27, 2020

luisramos0 commented Jun 22, 2020

luisramos0 commented Jun 22, 2020

mkllnk commented Jun 23, 2020

luisramos0 commented Jun 24, 2020 •

edited

luisramos0 commented Jun 24, 2020

sauloperez commented Jul 16, 2020 •

edited

luisramos0 commented Jul 16, 2020

sauloperez commented Jul 16, 2020 •

edited

filipefurtad0 commented Jul 17, 2020 •

edited

RachL commented Jul 17, 2020

filipefurtad0 commented Jul 17, 2020 •

edited

luisramos0 commented Jul 17, 2020

filipefurtad0 commented Jul 17, 2020

5300 Avoid race conditions in Spree::StockItem #5406

5300 Avoid race conditions in Spree::StockItem #5406

Conversation

kristinalim commented May 12, 2020 • edited

What? Why?

What should we test?

Release notes

luisramos0 left a comment

Choose a reason for hiding this comment

mkllnk left a comment

Choose a reason for hiding this comment

mkllnk May 20, 2020

Choose a reason for hiding this comment

sauloperez Jul 16, 2020

Choose a reason for hiding this comment

luisramos0 Jul 16, 2020

Choose a reason for hiding this comment

luisramos0 commented May 27, 2020

luisramos0 commented Jun 22, 2020

luisramos0 commented Jun 22, 2020

mkllnk commented Jun 23, 2020

luisramos0 commented Jun 24, 2020 • edited

luisramos0 commented Jun 24, 2020

sauloperez commented Jul 16, 2020 • edited

luisramos0 commented Jul 16, 2020

sauloperez commented Jul 16, 2020 • edited

filipefurtad0 commented Jul 17, 2020 • edited

RachL commented Jul 17, 2020

filipefurtad0 commented Jul 17, 2020 • edited

luisramos0 commented Jul 17, 2020

filipefurtad0 commented Jul 17, 2020

kristinalim commented May 12, 2020 •

edited

luisramos0 commented Jun 24, 2020 •

edited

sauloperez commented Jul 16, 2020 •

edited

sauloperez commented Jul 16, 2020 •

edited

filipefurtad0 commented Jul 17, 2020 •

edited

filipefurtad0 commented Jul 17, 2020 •

edited