Openfoodnetwork: [Spree 2.1] Fix services/restart_checkout_spec and requests/checkout/stripe_connect_spec (8 broken specs)

Created on 2 Mar 2020  路  12Comments  路  Source: openfoodfoundation/openfoodnetwork 
 46) RestartCheckout#call when the order is in a subsequent state when order ship address is nil resets the order state, and clears incomplete shipments and payments
      Failure/Error: config.after(:each)            { DatabaseCleaner.clean }

      SystemStackError:
        stack level too deep
      # ./spec/spec_helper.rb:113:in `block (2 levels) in <top (required)>'
      # ------------------
      # --- Caused by: ---
      # PG::NotNullViolation:
      #   ERROR:  null value in column "calculable_type" violates not-null constraint
      #   DETAIL:  Failing row contains (596, null, 184, null, null, null).
      #   ./spec/spec_helper.rb:113:in `block (2 levels) in <top (required)>'

  47) RestartCheckout#call when the order is in a subsequent state when order ship address is not empty resets the order state, and clears incomplete shipments and payments
      Failure/Error: config.after(:each)            { DatabaseCleaner.clean }

      SystemStackError:
        stack level too deep
      # ./spec/spec_helper.rb:113:in `block (2 levels) in <top (required)>'
      # ------------------
      # --- Caused by: ---
      # PG::NotNullViolation:
      #   ERROR:  null value in column "calculable_type" violates not-null constraint
      #   DETAIL:  Failing row contains (600, null, 187, null, null, null).
      #   ./spec/spec_helper.rb:113:in `block (2 levels) in <top (required)>'

  48) RestartCheckout#call when the order is in a subsequent state when order ship address is empty does not reset the order state nor clears incomplete shipments and payments
      Failure/Error: config.after(:each)            { DatabaseCleaner.clean }

      SystemStackError:
        stack level too deep
      # ./spec/spec_helper.rb:113:in `block (2 levels) in <top (required)>'
      # ------------------
      # --- Caused by: ---
      # PG::NotNullViolation:
      #   ERROR:  null value in column "calculable_type" violates not-null constraint
      #   DETAIL:  Failing row contains (604, null, 190, null, null, null).
      #   ./spec/spec_helper.rb:113:in `block (2 levels) in <top (required)>'

These 3 specs are also failing on the clean up stage after the spec succeeds so I am adding them to the scope of this issue:
rspec ./spec/requests/checkout/stripe_connect_spec.rb:134
rspec ./spec/requests/checkout/stripe_connect_spec.rb:207
rspec ./spec/requests/checkout/stripe_connect_spec.rb:223

picture luisramos0

Most helpful comment

Amazing detective work @Matt-Yorkley :clap: :clap: :clap:

If it helps: that method didnt change from spree 2.0 to spree 2.1

picture luisramos0 on 4 Mar 2020
👍2

All 12 comments

Possibly related: https://github.com/rails/rails/issues/34358

Matt-Yorkley picture Matt-Yorkley on 2 Mar 2020

It looks like this record with null attribute that's causing the error has to be a Spree::Calculator. The error only occurs after the test has completely finished and the data is being removed by DatabaseCleaner.clean...

Matt-Yorkley picture Matt-Yorkley on 2 Mar 2020

similar thing to #4890

luisramos0 picture luisramos0 on 3 Mar 2020

Okay, there's something nasty going on here. This is what I've got so far:

  • Some transactions related to saving associated objects are partially failing and being left open
  • It looks like an error is being raised somewhere and maybe rescued in an unexpected way (or stopping a secondary error from propagating) during the saving of those objects (that's the "stack level too deep" bit)
  • DatabaseCleaner then attempts to forcefully close all open transactions after the example has run (to clean up), which is triggering SQL updates with invalid (partially populated) data _after the test has finished_.
  • In this example, the object in the broken transaction is clearly a Spree::Calculator, and there are at least 3 that should be created in this test as part of either a ShippingMethod or PaymentMethod.

Bumping the database_cleaner version changes the errors slightly and displays this warning during the examples: WARNING: there is already a transaction in progress. The error is now:

WARNING: there is already a transaction in progress

SystemStackError: stack level too deep

  0) RestartCheckout#call when the order is in a subsequent state when order ship address is nil resets the order state, and clears incomplete shipments and payments
     Failure/Error: DatabaseCleaner.clean

     SystemStackError:
       stack level too deep
     # ./spec/spec_helper.rb:112:in `block (2 levels) in <top (required)>'
     # ------------------
     # --- Caused by: ---
     # PG::NotNullViolation:
     #   ERROR:  null value in column "created_at" violates not-null constraint
     #   DETAIL:  Failing row contains (12302, null, 0.00, 0.00, null, 0.00, null, null, null, null, null, null, 0.00, null, null, null, null, null, null, null, null, null, null).
     #   ./spec/spec_helper.rb:112:in `block (2 levels) in <top (required)>'

...and this record is _not_ a Spree::Calulator...?

Matt-Yorkley picture Matt-Yorkley on 4 Mar 2020

If we follow the suggestion here: https://github.com/rails/rails/issues/17776#issuecomment-65140214 ...and enable config.eager_load = true in environments/test.rb we get some very interesting new error output:

SystemStackError: stack level too deep

  0) RestartCheckout#call when the order is in a subsequent state when order ship address is nil resets the order state, and clears incomplete shipments and payments
     Failure/Error: ensure_correct_adjustment_without_included_tax

     SystemStackError:
       stack level too deep
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_d<...>t_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./app/models/spree/shipment_decorator.rb:4:in `ensure_correct_adjustment_with_included_tax'
     # ./spec/factories/shipment_factory.rb:34:in `block (3 levels) in <top (required)>'
     # ./spec/services/restart_checkout_spec.rb:16:in `block (4 levels) in <top (required)>'
     # ./spec/spec_helper.rb:111:in `block (2 levels) in <top (required)>'

I think this method in shipment_decorator.rb is what we're looking for @luisramos0 :point_up:

Matt-Yorkley picture Matt-Yorkley on 4 Mar 2020

Amazing detective work @Matt-Yorkley :clap: :clap: :clap:

If it helps: that method didnt change from spree 2.0 to spree 2.1

luisramos0 picture luisramos0 on 4 Mar 2020
👍2

I had a quick look and it seems this method is only callled in a loop after the spec is over. I am not sure it is the source of the problem.
But I think your hypothesis is good, there must be something wrong in the spec that leads to this...

luisramos0 picture luisramos0 on 4 Mar 2020

the eager_load change makes the stack level too deep issue appear in other specs. This doesnt necessarily mean it is not the right way to go!

luisramos0 picture luisramos0 on 4 Mar 2020
👍1

Yeah, I don't think we should use it, I was just trying to shed more light on the problem...

Matt-Yorkley picture Matt-Yorkley on 4 Mar 2020
👍1

Amazing investigation @Matt-Yorkley ! I can't be of much help here since I don't have room to dig deep enough... I just want to suggest we upgrade DatabaseCleaner in master. What you've seen with the upgraded version is reason enough IMO.

sauloperez picture sauloperez on 5 Mar 2020

These 3 specs are also failing on the clean up stage after the spec succeeds so I am adding them to the scope of this issue:
rspec ./spec/requests/checkout/stripe_connect_spec.rb:134
rspec ./spec/requests/checkout/stripe_connect_spec.rb:207
rspec ./spec/requests/checkout/stripe_connect_spec.rb:223

luisramos0 picture luisramos0 on 6 Mar 2020
👍1

After fixing some extra strong params issues in checkout controller I see two more specs in stripe_connect have this problem:
rspec ./spec/requests/checkout/stripe_connect_spec.rb:293
rspec ./spec/requests/checkout/stripe_connect_spec.rb:308

It's now 8 specs in total.

luisramos0 picture luisramos0 on 9 Mar 2020
Was this page helpful?
0 / 5 - 0 ratings

Related issues

shen-sat picture shen-sat  路  3Comments
kirstenalarsen picture kirstenalarsen  路  3Comments
myriamboure picture myriamboure  路  3Comments
filipefurtad0 picture filipefurtad0  路  3Comments
sauloperez picture sauloperez  路  3Comments