Openfoodnetwork: First order from a new customer does not contribute to customer balance on /customers page; new Customer not added to customer list

[filipefurtad0]

Description

Possibly introduced by #5925.

Updated

While testing testing #6879 it was found that after the first successful check-out, new customers are not appearing in the customers list of the enterprise, found in /admin/customers.

The balance from these orders is not being included in the overall customer balance.
It is correctly appearing in the bulk coop payments report, and on the customer transactions page.

So, if this first order is in any state other than 'paid' it will lead to discrepancies in the values of the balances displayed throughout the app.

Expected Behavior

After the first successful check-out, a new customer appears in the customers list of the enterprise. The balance of the order should be included in overall customer balance.

Actual Behaviour

After the first checkout, a customer is not added to the customer list on the enterprise.
The balance of this first order is not included on the customer balance.

Steps to Reproduce

Customer not added

1. Log in as a customer and visit a given shopfront, for the first time (no previous orders)
2. Add some items and place an order.

As admin:

1. Check this new customer is absent from the customer list in admin/customers

Incorrect customer balance

1. As the initial customer, place a second order.
2. As admin, see the customer was now added.
3. Now edit the first order bringing it to a "credit owed" or "balance due" state
4. Check customer balance in:
5. customer: /account#/transactions# - should be correct
6. admin: /order_management/reports/bulk_coop (payments report) - should be correct
7. admin: admin/customers - should be incorrect

Workaround

Adding customers manually works as before.
Update: placing a second orders adds the customer to /customer page.
No workaround for incorrect customer balance...

Severity

bug-s2

Your Environment

• Version used: master branch after several merges, on v3.2.7. This bug is currently not in production.
  Update: reproduced on v3.6-beta (in staging-uk)
• Browser name and version: Firefox 80
• Operating System and version (desktop or mobile): Desktop Ubuntu 20.04

Possible Fix

Probably introduced by #5925.

[RachL]

@filipefurtad0 this is preventing tagging as well. So I'm wondering if this isn't a blocker to release the PR.... and not an s3 🤔 ping @lin-d-hop @kirstenalarsen what do you think?

[filipefurtad0]

@RachL I don't think it would prevent the tagging feature for previous customers, which would already be in the customer list. New customers could still be added manually.

However: I've tried to reproduce this bug on different builds, to be sure this was introduced by #5925. I tested this and a basic tagging like, hiding a product (default) and showing it to certain customers (customer rule). All good, after staging:

• a recent PR #5722
• the current master (build 1718)
• v.3.2.7 (in production)

I would keep an eye for this on release testing.

[luisramos0]

@filipefurtad0 do you mean the original issue (no customer created) is gone?

[filipefurtad0]

Yes, seems gone @luisramos0. I tried to reproduced it in different environments/stagings, but couldn't.

[luisramos0]

ok, thanks for clarifying. I wonder what happened there...

[filipefurtad0]

I can't explain it either. I'm keeping my eyes on this issue though... Do you think it should remain open?

[luisramos0]

no, I agree: issue closed, eyes open :-)

[filipefurtad0]

Found this again, it is reproducible.
The first order from a new customer does not add this customer to the hub's customer list on /admin/customers.

It only gets added to this list after the second order is placed.

Here is an example. One order placed by our good old trusty Kurkuma Customer:

Appears on bulk-coop report:

Appears on the customers side as well:

But not on the /customers page:

This is a cash payment; but this is not related to payment capture: capturing the payment still does not make it appear in the /customer page.

[RachL]

outch. great catch @filipefurtad0 ! Let's keep it as s3, but it's a pretty annoying one I would say... ping @lin-d-hop FYI

[filipefurtad0]

It seems this first order can easily break customer balance...

Let's consider this example:

• Placed a first (Stripe-SCA) order and confirmed it does not appear /customers -> this tells us, that the bug is occurring irrespective of the payment method (on my previous comment a cash order was shown)
• This "not appearing order" is paid: it has customer balance = 0.
• Placed a second cash order, and did not capture the payment; this order appears on /customers.

So far so good, because the first order has balance = 0; however, if we edit the order, changing customer balance, we get to this situation (below, left - /customers page; right - bulk coop payments report):

So, after removing some items from the first order, there is now a credit owed -> this is not contributing for customer balance, which shows only the customer balance of second and subsequent orders.

On the customers side, all good: /account#/transactions#food-on-rails5-hub

I think this is an S2. What do you think @RachL ?

PS: I was thinking it could explain #7124, but the issue is not mentioning /customers page... Maybe worth checking if the very first order from that customer is contributing to customer balance; ping @mkllnk.

[RachL]

😭 Like this it looks like an s2 indeed. @filipefurtad0 were you testing with the toggle on or off?

[filipefurtad0]

Feature toggle was on (BETA_TESTERS: all), this was found while testing #6879. Upgrading to S2.

[sauloperez]

I just tried both placing an order as guest user and with a user I previously created from /admin and both showed up in /admin/customers running on 1311ff295 on my machine.

was a newly created user what you tried? Let's see if we can nail down the specifics.

[filipefurtad0]

Yes, I see this remains a "flaky" issue. Just reproduced again, by placing 3 (same) orders, with 3 different first-time customers, in staging-UK:

• One of them appears in the /customers list: R481011160 (cash)
• The other two don't: R024355332 and R238814785 (stripe SCA)

Only thing changing is payment method: this would point to a stripe SCA issue. But, on previous comments the issue is shown to be reproduced for cash payment method as well, so that should not be it.

Only difference between between the set payment methods is: in this hub SCA has no transaction fee; cash PM does.

[filipefurtad0]

Shipping and transaction fees, seem to play a role: If there are no fees, the customer is not added.

So, for the same payment gateway (in staging-UK):

• PM1 - cash (free) - new customer not added - R382632247
• PM2 - cash (£10) - new customer is added - R400760706

Same goes for shipping fees.

So, it seems that to reproduce this issue:

• a first time order needs to be placed, with
• no shipping nor transaction fees associated to the order

Hope this helps.

[Matt-Yorkley]

I can't replicate this in current master, either manually or by checking for the created customer in tests...?

[filipefurtad0]

Humm... tough one. I tried again with the steps above and the customer was added indeed.

There is something which seems to play a role. Seems not to be the fees. I'll need to investigate yet more.

[sauloperez]

it sounds like there's some action that may trigger a callback we need? and when not triggered it doesn't show up? perhaps you can get the exact DB state before/after reproducing? this can then be turned into a test setup and we can hopefully replicate it.

Likewise, I'll see if reproducing the state those two orders are in yields some result.

[mkllnk]

I'm looking at the code and it's quite complex. Basically, we create a customer record when an order is validated, usually before saving, when it's not in cart state. So the customer should already be created before creating a payment. Maybe let's refactor this and manually create the customer instead of in a callback. Working on it. :thinking:

[mkllnk]

I can't re-produce this either. I tried with a cash payment method, with and without fee. And with the fake credit card payment gateway. Always with a new user. And the customer record even gets created when the payment fails or the email address is invalid. @filipefurtad0 Is there any way you can make this reproducible?
Handy information would be:

• The commit id.
• The staging server or if it was local. I tried uk-staging but your data seems to be gone and I couldn't select a state.
• Exact steps:
  
  
  
  • From which page do you log in?
  
  
  • Which payment method?
  
  
  • With fee?
  
  
  • Shipping method with fee?
  
  

[sauloperez]

@filipefurtad0 and I went together through some logical reasoning and this is what we concluded.

There are two ways in which this could happen, either a) we're failing to create the customer record as you @mkllnk were investigating, or b) there's a flaw in the data-fetching logic.

Because we load the data differently in /accounts and /admin/customers a) would cause all orders to appear in /accounts and not in /admin/customers. We essentially load all user's orders regardless of their customer record in the former, while we fetch customers and orders in one shot in the latter. Likewise, the bulk coop report lists these first orders and doesn't care about customer records either.

b) seems less likely because although both /accounts and /admin/customers load the data slightly differently both rely on the same list of order states. Orders in an unexpected and not listed state wouldn't be fetched, however, the fact that the former works and the latter doesn't, refutes this hypothesis. Also, the bulk coop report relies on the completed_at column being set and it does work.

Something I get from all this is that now is time to remove duplication and share the data-fetching logic among these endpoints so don't diverge. If broken, it'll be so for all.

[sauloperez]

I'm looking at the code and it's quite complex. Basically, we create a customer record when an order is validated, usually before saving, when it's not in cart state. So the customer should already be created before creating a payment. Maybe let's refactor this and manually create the customer instead of in a callback. Working on it.

I went through the same code and indeed, the 2 callbacks involved and their conditionals make this logic sky-rocket the complexity. It's even hard to understand how it works. I believe it desperately needs to be pulled out into a service or even pub/sub if needed.

I sort of documented my findings in https://github.com/openfoodfoundation/openfoodnetwork/pull/7432.

[filipefurtad0]

Thanks for investigating @mkllnk and the summary of our chat and conclusions @sauloperez .

I've staged the build for this weeks release in staging-UK, and -ES and checked various scenarios (around payment methods, fees, taxes, addresses, strings used on name and address fields) also in staging-AU and was unable to reproduce the scenario in which a first time customer checks out, without customer creation on the admin side.

I agree that this step is the decisive one on the fail cascade. The consequences are well understood, and easily reproducible (admin changes, or cancels the order), but they "need" the first step to fail and on this I have no additional info.

So, maybe the way to proceed is to refactor and simplify - And hope that after this implementation we don't observe the bug again.
NB: while writing, a first step towards this just appeared on #7432 :rocket:

[sauloperez]

I tried to make it fail loudly in https://github.com/openfoodfoundation/openfoodnetwork/pull/7433. These two PRs should shed some light :crossed_fingers:

[mkllnk]

@sauloperez I wanted to know how bad this issue is and I queried orders without customer record. Australia has thousands of them but all before July 2015. I guess that was the time when we implemented the customer record. If I look only at newer records, the UK is the only instance with missing customer records, starting in September 2019 and continuing to March 2021.

Spree::Order.complete.where("updated_at > ?", Date.civil(2015, 9, 1)).where(customer: nil).count
#  (0.9ms)  SELECT COUNT(*) FROM "spree_orders" WHERE (completed_at IS NOT NULL) AND (updated_at > '2015-09-01') AND "spree_orders"."customer_id" IS NULL
#=> 0

sql='SELECT COUNT(*) FROM spree_orders WHERE (completed_at IS NOT NULL) AND (updated_at > $$2016-12-01$$) AND customer_id IS NULL'
ansible all-prod -u openfoodnetwork -a "psql -h localhost openfoodnetwork ofn_user -c '$sql'"

So I think that it's not common to have a missing customer record during checkout. Your theory of an admin creating an order is very plausible. The UK may have some users that create orders in that way.

[sauloperez]

Nice @mkllnk !

Australia has thousands of them but all before July 2015. I guess that was the time when we implemented the customer record.

Right. I remember reaching that conclusion somehow time ago. I agree with the explanation :+1: . Shall we maybe add that as a comment to models/customer.rb model :thinking: ? next devs may thank us.

So I think that it's not common to have a missing customer record during checkout. Your theory of an admin creating an order is very plausible.

If we could find any detail that make us distinguish from where each order is created. Back or frontoffice :detective: .

The UK may have some users that create orders in that way.

Do we have any integration creating orders from outside the app? AFAIK nope, right?

[mkllnk]

If we could find any detail that make us distinguish from where each order is created. Back or frontoffice

That reminds me, order have a created_by field. I'm not sure if we use it correctly, but that's why Spree introduced it.

Do we have any integration creating orders from outside the app?

@lin-d-hop Any Zaps creating orders?

[sauloperez]

That reminds me, order have a created_by field. I'm not sure if we use it correctly, but that's why Spree introduced it.

Worth taking a look. I might do that if you don't get to it today.

[sauloperez]

Some fresh news! I checked UK's Bugsnag and it's pretty clear now

In all these cases the validation fails due to Email can't be blank. Good news (or bad) is that form the 9 users affected, 2 of them are Filipe's accounts. Not so good is that the most affected hub is Tamar Valley Food Hub.

Source: https://app.bugsnag.com/yaycode/openfoodnetwork-uk/errors/6087c81e781ffd00070ee749?filters[event.since][0][type]=eq&filters[event.since][0][value]=30d&filters[error.status][0][type]=eq&filters[error.status][0][value]=open&filters[search][0][type]=eq&filters[search][0][value]=ensure_customer&filters[user.id][0]=932&pivot_tab=event

[filipefurtad0]

I've browsed through the Bugsnag errors and they seem quite similar to the one triggered while testing the PR which introduced this monitoring ability: It's worth stressing that it was triggered on a legitimate situation, so I'm not sure all these errors actually correspond to the bug scenario.

Update: but hopefully some of there are, or will be :+1: