Openfoodnetwork: Loading Tax Rates report gave snail page

[sstead]

Description

I was trying to view the Tax Rates report in Aus production, logged in as a regular enterprise user. When I tried to view the report I got an instant snail page (not a page timeout).

Could this be because Aus Production has 3 taxes setup?

Expected Behavior

I should be able to view the report

Actual Behavior

I got the snail page.

Steps to Reproduce

1. Login to Aus Production (as enterprise or superadmin)
2. Go to report and select the Tax Rates report
3. Select an enterprise
4. Click Search and you should quickly see a snail page.

Animated Gif/Screenshot

Context

Trying to view tax report

Severity

s4 - I'm not sure how many people use this report?

Your Environment

PC, Chrome, Aus Production

[mkllnk]

From Bugsnag #3128:

NoMethodError in spree/admin/reports#sales_tax
undefined method `collect' for nil:NilClass

View on Bugsnag

Stacktrace

app/models/spree/order_decorator.rb:297 - block in tax_adjustment_totals
app/models/spree/order_decorator.rb:295 - each
app/models/spree/order_decorator.rb:295 - each_with_object
app/models/spree/order_decorator.rb:295 - tax_adjustment_totals
lib/open_food_network/sales_tax_report.rb:51 - block (2 levels) in table
lib/open_food_network/sales_tax_report.rb:51 - block in table
lib/open_food_network/sales_tax_report.rb:49 - table
app/controllers/spree/admin/reports_controller_decorator.rb:128 - sales_tax

View full stacktrace

[myriamboure]

This report is actively used by some French users who are within VAT scheme and declare VAT every month... I just tested on French production and VAT rate reports display without issue so it must be something with one of the latest PR merged... France will not be able to upgrade to the release to come if we don't fix that then :-(

[myriamboure]

I put s3 and not s2 just because it is not live yet in a place where it's a core feature, but if would have been live in France I would have put s2 as our users would have been stuck and not able to access the VAT data to declare...

[luisramos0]

I'll have a look at this one in an hour or so.

[luisramos0]

I cant replicate this problem locally and I don't understand it in AUS live.

This is the offending line (the last one where tax_rates is nil):
https://github.com/openfoodfoundation/openfoodnetwork/blob/be7fea9d144b37ae06ff866de006cf73ed300944/app/models/spree/order_decorator.rb#L294-L297
and this is the method that is returning nil:
https://github.com/openfoodfoundation/openfoodnetwork/blob/be7fea9d144b37ae06ff866de006cf73ed300944/app/models/spree/adjustment_decorator.rb#L44-L68
[].collect would not return the same error, so I believe a return nil is what we are looking for here.

Maybe some data problem that breaks tax_rate.match() and returns nil here? https://github.com/openfoodfoundation/spree/blob/fe0a1311abb097bf3ac8001a24246c6cff5ecdbb/core/app/models/spree/tax_rate.rb#L28-L33

I believe it's a problem with the data of a specific order (or group of orders) that is breaking the report.
Can someone else have a look please?

[sauloperez]

I'll give it a try

[luisramos0]

maybe this is only happening in AUS live and was already broken in previous release? can we revert master from AUS live and install a previous version and see if this report is broken there?
if that is the case it means this is not a bug related to this release and we could proceed with the release in parallel with fixing this bug in AUS live.

[sauloperez]

app/models/spree/adjustment_decorator.rb was last changed on 2017-04-29 and app/models/spree/order_decorator.rb on 2018-02-20, so nothing related to this release.

Also, Bugsnag's report clearly shows this is a preexistent issue, so

if that is the case it means this is not a bug related to this release and we could proceed with the release in parallel with fixing this bug in AUS live.

I would do this.

All the clues that you shared make sense @luisramos0 . I'd investigate them a bit further. Particularly the issue you mention about #match.

[mkllnk]

@sauloperez

Bugsnag's report clearly shows this is a preexistent issue

From which Bugsnag data do you draw that conclusion? The Australian Bugsnag issue shows data only for one day, 23 Nov 2018.

[sauloperez]

I don't remember exactly now but none of these lines seem to be new.

[luisramos0]

@myriamboure @mkllnk @sauloperez what's your vote here? should we block the release or should we proceed?

[myriamboure]

If you think it's from before let's release, if there is an issue we will revert I guess in France until we fix the problem... or we will have a s2 bug to fix quickly ;-) But you have my go.

[sauloperez]

My point was to move. Preexistent issues should not stop a release.

[luisramos0]

ok, lets move and watch it as we release.

[luisramos0]

I run this report live in france for demo hub and it works after the release. So I confirm it's only a AUS issue.
@myriamboure do you want to confirm the report is still working for you? Thanks!

[sauloperez]

Then it must be taking more than unicorn_timeout in AUS, which is also 120sec

[mkllnk]

It's not a timeout issue. See the stacktrace above and Sally's description:

I got an instant snail page (not a page timeout).

[mkllnk]

I looked into the Australian production database and found a cause for this. There are orders that have adjustments (fees) including tax. Some of these adjustments are calculated based on line items that have been deleted. The logic to find a tax rate doesn't expect a missing line item and returns nil.

    # @return [Array<Spree::TaxRate>]
    def tax_rates
      case originator
      when Spree::TaxRate
        [originator]
      when EnterpriseFee
        case source
        when Spree::LineItem
          tax_category = originator.inherits_tax_category? ? source.product.tax_category : originator.tax_category
          return tax_category ? tax_category.tax_rates.match(source.order) : []
        when Spree::Order
          return originator.tax_category ? originator.tax_category.tax_rates.match(source) : []
        end
        # No default defined here. `source` is nil and this returns `nil`
      else
        find_closest_tax_rates_from_included_tax
      end
    end

  def tax_adjustment_totals
    tax_adjustments.each_with_object(Hash.new) do |adjustment, hash|
      tax_rates = adjustment.tax_rates # This is `nil` and the next line blows up on calling `collect`
      tax_rates_hash = Hash[tax_rates.collect do |tax_rate|
        tax_amount = tax_rates.one? ? adjustment.included_tax : tax_rate.compute_tax(adjustment.amount)
        [tax_rate, tax_amount]
      end]
      hash.update(tax_rates_hash) { |_tax_rate, amount1, amount2| amount1 + amount2 }
    end
  end

Now I'm wondering:

• Should we make tax_rates return an empty array [] or use find_closest_tax_rates_from_included_tax as default? I'm tending to the latter for now.
• Why did the adjustment persist even though the line item was deleted? There could be a bug. The oldest of these adjustments is from 2013 and the newest is a few days old. It's likely that this bug still exists.

The SQL code to find these adjustments:

select count(*) from spree_adjustments left join spree_line_items on spree_adjustments.source_id=spree_line_items.id where source_type='Spree::LineItem' and source_id is not null and spree_line_items.id is null;

Impact of this problem by number of affected adjustments with most recent date of adjustment:

• Aus: 621, 2018-07-05
• France: 44, 2018-12-10
• UK: 6612, 2018-12-04

[mkllnk]

Spree::LineItem deletes any adjustments connected it when destroyed:

has_many :adjustments, :as => :adjustable, :dependent => :destroy

[sauloperez]

I haven't read the code you pasted above but if Spree has that dependent destroy then there is something about it that is not working, right?

If the line item is deleted you won't need the adjustment anymore.

[luisramos0]

Nice one @mkllnk
Have you tested it in a normal scenario? Create order with line item adjustments, then delete line item, look if adjustment is there or not. Is the adjustment being destroyed for this normal case?

[mkllnk]

Thanks @luisramos0. I tried to re-produce this in a spec and the adjustment got deleted. But thanks to your hint I now tried it through the admin panel and can re-produce this:

• Go to Enterprises / Enterprise Fees and add a packing fee with flat percent per item.
• Adjust the percentage to 10%.
• Include that fee in an order cycle.
• Create an order with multiple line items.
• Go to admin / orders / edit order.
• Observer that there is a fee for each item.
• Click the trash icon to delete an item, but don't click "Update And Recalculate Fees".
• Observe that the line item is gone, but the fee is still there.

I remember that we came across this problem before and that's when we changed the Update button to be Update And Recalculate Fees. And I'm sure there was a reason to solve it this way. We probably said that people just have to click the button as workaround. But it's still buggy. :-(

[mkllnk]

That actually leads to a wrong order display, because the fees are not listed separately:

The 20 cents difference are the lost fee that should have been deleted.

[luisramos0]

Nice, it's pretty clear now!

"And I'm sure there was a reason to solve it this way."

Maybe just lack of time or difficulty to make the line_item.destroy also remove the adjustment?
Shall we fix it in v2? I am working on line item destroy at the moment in #3205

[luisramos0]

It could just be a problem with the dependent: destroy on the polymorphic relationship?
https://github.com/openfoodfoundation/spree/blob/41906362d931695e0616194341a68d2c4c85aaaf/core/app/models/spree/line_item.rb#L8
https://github.com/openfoodfoundation/spree/blob/41906362d931695e0616194341a68d2c4c85aaaf/core/app/models/spree/adjustment.rb#L29

[mkllnk]

I think I should still fix the report to deal with this inconsistent data. That will close this issue. The deletion of fees associated to removed line items can be done in v1 or v2. I always prefer to solve things in master first if we can, but not if that means we have to solve it twice. Your call, you are working on that code at the moment.

[luisramos0]

If I were you I wouldn't touch the report actually. The data is broken, so it's ok if the report breaks. I'd just fix the data and make sure it will not happen again.
In terms of fixing the root cause, I'll give it a try as I look at #3205 and we can decide afterwards.

[mkllnk]

I didn't wait for your reply and started working on this, because the report is used in Australia and France regularly. Fixing the data is not simple, because we change the total of existing orders. Maybe someone intended to still charge an admin fee even though the item was removed. For example transaction fees should persist if they were charged already. The inconsistent data issue was actually reported over a year ago in #1629.

I didn't touch the report itself, but refactored the tax rate finding logic and moved it into a service as it's completely independent of Spree. #3229 should fix the report and maybe some other cases as well.

[luisramos0]

awesome, sounds good @mkllnk