Payment registered in Stripe when OFN declared a problem

[Cecilia-Hn]

Description

We've got some order R453734851 for hub ID 844 with this behavior :

1 - An order is done through OFN
2 - Payment done through Stripe
3 - Stripe indicates that the amount has been paid
4 - OFN declared a problem with the payment

Its a big problem for hub and their clients because the order status is invalid so the hub doesnt prepare the order and the client come to collect an order that wasn't prepared.

Expected Behavior

See the order on the OFN side with the "completed" status

Actual Behaviour

Order is claimed as incomplete by OFN

Steps to Reproduce

we don't know :(

Animated Gif/Screenshot

OFN :

Stripe :

Workaround

None

Severity

bug-s2: a non-critical feature is broken, no workaround

Your Environment

• Version used: v3.7.2
• Browser name and version: All
• Operating System and version (desktop or mobile): Both

[Matt-Yorkley]

There's a bit of complexity here, in that we might have fixed that bug already in the latest release but... that payment was authorized on Monday, we deployed on Tuesday around 3PM, and the payment capture happened on Tuesday at 5PM.

I'm not 100% though, just noting the background.

[RachL]

@Matt-Yorkley yes I think there is a really good chance that the bug is fixed. But how should we deal with past orders? Do we have an easy way to fetch all the orders that have had the problem so we can reimburse them? Like are all orders at payment states or should we consider other states as well?

[lbwright22]

Another example happened today R267366584 31st May 2021 @Matt-Yorkley

[filipefurtad0]

There is a related scenario (stock reduction between order placement and payment is authorization) which is a follow-up from the previous issue, and currently being fixed - see #7665. Maybe it accounts for this @RachL @lbwright22?

[Cecilia-Hn]

New case happened yesterday, order : R315312718
(the payment is registered on Stipe, nothing on OFN)

[Matt-Yorkley]

Alright there are two different cases here. Initial notes:

French Prod: Order R315312718, placed at 11:15 yesterday:

We had to roll back the release last week on a couple of servers, which meant French Production was almost 2 weeks behind on updates until we deployed a new release last night at around 19:40 after this order was placed. So unfortunately my previous comment on deployment of potential fixes might still apply, but it's not clear. This order was placed by the customer through regular checkout. The payment is marked as pending on the OFN side but it's completed in Stripe. Needs more investigation.

UK Prod: Order R267366584, placed at 05:01 on May 31st:

This order was placed via a subscription. On the OFN side it says the payment is complete. I tried to do a quick bit of debugging here and the Stripe API said:

The provided key <stripe key> does not have access to account <account id> (or that account does not exist).
Application access may have been revoked.

This might be related to the seller's Stripe account setup? @lbwright22 could you open a separate issue and add any related details, if you have any?

[RachL]

@Matt-Yorkley FR was rolled back? On slack you've mentioned Aus, US, and Katuma only if I'm not mistaken?

[Matt-Yorkley]

Ah! My mistake! Yes, it was Katuma, not France. 🤦‍♂️

[Matt-Yorkley]

Ah ok... so with R315312718 the order never actually completed the checkout process? There was an error and the checkout didn't proceed to the order completion page? Is that correct @Cecilia-Hn ?

[Cecilia-Hn]

There were no order in OFN and no order confirmation as well

[Matt-Yorkley]

Dev notes:

There's a lot of moving parts here! There were no relevant Bugsnag errors for that order, which is very strange. It looks like it's possible in some rare cases to process a payment but for the order to subsequently not compete (for some other reason, like stock running out), which could create a situation where the payment has been taken but the order was not completed.

This is due to the order we do things in:

• Order#process_payments! gets called in the before_transition to: :complete hook
• Order#finalize! gets called in the after_transition to: :complete hook, and this is where a) stock is reduced and the b) order is marked as completed

If something unexpected happens between those two steps, the payment will be complete but the order will not be ⚠️

There are a few things we can do here:

• add a check for this specific situation during checkout processing, and add an explicit Bugnsag call if it's encountered, to increase visibility of this potential issue and aid debugging
• add a final explicit stock check just before capturing the stripe payment, which we previously added for Paypal here: Paypal stock clashes #6391
• automatically void the stripe payment if we encounter this issue where the order completion failed (for whatever reason) after the payment had already been processed (and captured)

[Matt-Yorkley]

Alright, I did a bit of a live-debugging deep-dive today and mapped out the code paths for the different flows where additional authorization is required or not required. Also tried to map out edge cases that could cause issues, and found a couple. The flows look a bit like this:

With no additional authorization required:

With additional authorization (the redirect! bit is where the user leaves OFN and goes to Stripe):

[Matt-Yorkley]

Edge case issues:

When the stock runs out between being redirected to Stripe and being redirected back to OFN

• The user gets bounced to the cart page and shown the normal feedback that says items in the cart have gone out of stock, which is good. What they don't get is feedback letting them know what happened with the payment, which is not good.
• The payment object does not get captured (which is good), but it stays there on the order (we should probably take an action here like explicitly cancelling it)
• If the user edit their cart at this point and tries again (and is successful) we still have that previous payment sitting around in pending state, alongside the new completed payment.
• The order's state stays as "payment". We should probably use the "restart checkout" logic here, where we essentially reset the order to cart state.

When authorization fails the first time, and is then retried

• It seems like this can result in multiple payments on the order in different states (like one failed and one complete). The code doesn't always handle this well. Similar/related to: "Mixing payments" on orders: adding a cash payment over a Stripe SCA payment (error 500) #7653
• There seems to be some issues around lack of explicit ordering in the code that fetches the "last" payment; the returned payment is not always the one we expect!
• We should look at cases where the first attempt fails authorization and then the user retires the checkout with a) the same card or b) a different card

[Cecilia-Hn]

Hi all,
There is new report from our client,
Order : R475133320
Date : 9.06
OFN hub Client : Delphine
Final customer : Sophie

The 9th june, Delphine is connected to stripe, she sees Sophie's payment uncaptured
Delphine went on OFN and saw Sophie's order as unfinalised
Delphine went back on stripe for catupring Sophie's payment but she didn't need to do any action, the payment was captured magically
Delphine went back on OFN and Sophie's order was well finalised

Does someone have an idea of capture payment delay ?

[Cecilia-Hn]

Hi !
We've got new informations, hope it helps cause our customer is very annoyed by this :/

An OC was open until 11.59 PM on 16th june,
three payment were on pending status for this same OC until 11.20 AM this morning,
right after that ou producer connected at her Stripe account at 11.15 AM.
The three orders concerned about this weird payment delay are :

• R388335642
• R062344327
• R214508066

Does someone have an idea of capture payment delay ?
@Matt-Yorkley

[Cecilia-Hn]

A new case :

A customer has done an order R864750185 this morning.
Then this customer realized that he did not received the confirmation order by email, so he contact the hub, then, the hub has connect to his stripe account and saw that the payment was not captured by stripe and "magically", the client received the confirmation order by mail and the payment was captured.

Have we got a clue ?

@Matt-Yorkley

[RachL]

@Cecilia-Hn have you check on sendgrid when the confirmation email was sent? If it was right away we can rule out any magic tricks :)

[Cecilia-Hn]

About Stripe for R864750185 , we've got these information :

About Sendgrid :

[RachL]

Nice! So confirmation email are sent only when there is a capture on Stripe side. It reminds me of #7417 where a guy from Stripe was suggesting we could remove this capture:

Currently CoopCircuits manages this pre-authorization with capture_method = manual on all your payments. If this parameter is passed to automatic, or is not passed, your payments will no longer use the pre-authorization feature. You can ask the CoopCircuit team if this integration is available.

Maybe a clue?

[lbwright22]

An occurrence very similar to this happened in UK yesterday:
Order ID R744745111
Customer received this message on checkout:

and assumed order had not been placed. However, order confirmation email was sent and money from customer's Stripe account was taken at the time.

Bugsnag is here: https://app.bugsnag.com/yaycode/open-food-network-js-uk/errors/5f587e8727d37a0017aabc06

[andrewpbrett]

I took a look through this issue, I think there's potentially several different things going on, some of which are likely fixed in v3.8.4 and/or by @Matt-Yorkley's PR #7779, which is ready for testing.

However, these last few comments sound really odd, so I want to clarify what we're saying here @Cecilia-Hn - it sounds like these are the steps to reproduce:

• Order is placed via shopfront checkout
• Customer sees an error message, does not receive confirmation email
• Hub manager logs into OFN backend some time later and sees payment as Pending in OFN
• Hub manager logs into their Stripe account and does nothing else, or maybe looks at the payment but does not ever click the capture button?? <-- this is the part that seems really odd
• Payment is captured in Stripe, and OFN order is finalized?

Is that right?

[Cecilia-Hn]

Hi Andrew and thanks a lot.
I know it's very odd.

Your steps seems correct except that the customer does not saw error message.

• Order is placed via shopfront checkout
• Customer does not receive confirmation email
• Hub manager logs into OFN backend some time later and sees payment as Pending in OFN
• Hub manager logs into their Stripe account and does nothing else, or maybe looks at the payment but does not ever click the capture button
• Payment is captured in Stripe, and OFN order is finalized

We wrote to Stripe for having more informations about payment delay on their side, I'll come back to you as we'll get an answer.

[RachL]

@Cecilia-Hn so far our only clue is what is now describe here: #7922 (orders were dealing with products going out of stock during the authorization process).

I'm closing here. If we have other requests coming in which are not linked to a stock problem, we can reopen.

[Cecilia-Hn]

Hi,

I think we may need to re open this issue.
We've got a new case from R207347030 order : the payment through Stripe is captured when OFN Payment is still uncaptured.

What do you think ?

All informations bellow :

3D Secure authentification is done here

Payment is uncaptured

[filipefurtad0]

Thanks for reporting @Cecilia-Hn .
Do you know how the order was placed - shopfront, backoffice or subscription?

[Cecilia-Hn]

@filipefurtad0 Thanks !
Yes, it was a shopfront order.

[lin-d-hop]

We are still seeing this in UK as well. The pain it is causing is high! And I am not sure all the occurrences are actually being reported.

[lin-d-hop]

Always through the shopfront for UK experience.

[filipefurtad0]

The payment (id=179982) for that order is in state failed has a cvv_response_message likesource_redirect_slug (replaced some customer info with <removed_string> below):

https://hooks.stripe.com/redirect/authenticate/src_1JPWCVKNkMQwqy0M6jONUjaB?client_secret=src_client_secret_<removed_string>source_redirect_slug=live_<removed_string>

There are 52 such payments in FR-prod:

openfoodnetwork=> SELECT COUNT(*) FROM spree_payments WHERE cvv_response_message LIKE '%source_redirect_slug%';
 count 
-------
    52
(1 row)

The first payment with this message appeared in 2021-03-19.

And 4 of them UK-prod:

openfoodnetwork=> SELECT COUNT(*) FROM spree_payments WHERE cvv_response_message LIKE '%source_redirect_slug%';
 count 
-------
     4
(1 row)

Hopefully this is a clue. I'm not sure they (all) relate to the same scenario.

We've seen a similar message before, on a different context:
#7687

[filipefurtad0]

If the order cycle closes during checkout on the shopfront, and while payment is being processed, then:

• the customer will be redirected to the shopfront, or homepage - as expected, depending if there are more OC open
• the order will remain in a state = payment; no order confirmations arrive
• the payment remains authorized and uncaptured, on Stripe

This seems to be different than the scenario above though... In this case, the order does not have any payments:

So there might be more scenarios which account for this bug.

[andrewpbrett]

Thanks for the update @Cecilia-Hn - definitely correct to reopen this. That screenshot you provided was super helpful. With the timestamp I was able to look through the logs on FR and find the request that we saw after the customer authorized and was redirected to OFN.

The next line in the logs is:

Redirected by /home/openfoodnetwork/apps/openfoodnetwork/releases-old/2021-08-10-144554/app/controllers/application_controller.rb:127:in 'require_distributor_chosen'

So we're not marking the payment as complete in OFN because of that redirect. I think @filipefurtad0 is on the right track here, but I need to dig a little more to figure out why current_distributor might be false, it looks like there's a few different paths to go down.

In any case, though, it might be a good idea to move the handling of the redirect from Stripe to its own controller action entirely.

[andrewpbrett]

@RachL @filipefurtad0 could you elaborate on this comment? #7692 (comment)

You say that Stripe said that they automatically capture payments after seven days, but in this documentation, it says that the payment is actually held and then released after seven days:

https://stripe.com/docs/payments/capture-later

I'm wondering if this is the same flow, or if there's another one that we're not accounting for.

[RachL]

@andrewpbrett I'm afraid I made that comment based on an email exchange I had with stripe for issue #7417. And I was writing to them in French, so a lot can go wrong with my translations. Maybe I could reach out to them again and ask specific questions/ answers in English? They seemed quite reactive.

[andrewpbrett]

@RachL Yes that would be great if you could ask them to clarify, thank you!

[andrewpbrett]

@RachL Also based on the issue description for #7417 it looks like they're saying that the transaction is in fact canceled after 7 days, not captured:

-Stripe requests authorization to withdraw funds from the bank.
-The funds are locked for you in the customer's bank account.
-Within 7 calendar days, you will be able to capture the funds. If you do not capture the funds after this limit, the funds will be released and the order canceled.

(I assume this was quoting Stripe's reply but I'm not positive)

[lin-d-hop]

Multiple reports a week of this. This is one of the worst bugs we've had and its hung around all of August. There's no one to work on it but it is an S1.

[RachL]

@andrewpbrett stripe went back to me and asked that a developer contact them directly. They are happy to have a look at our integration. They are available through their chat system or with https://support.stripe.com/contact/email?topic=api_integration

You will need to use this link while being loogedin FR's account (this way they answer faster as they see we are customers). You can do it with your personal access you have on FR account. Otherwise, if you log in with the credentials on bitwarden there is a 2FA on my phone, so I need to be around^^

[andrewpbrett]

For the specific payment most recently posted by @Cecilia-Hn, the problem was that we were redirecting to the home page.

As @Matt-Yorkley theorized, this may be due to the person being logged in on the non-www domain and then being redirected by the payment provider to the www domain (or vice versa).

To test this theory, I started a cart session and entered a card that requires SCA redirection. When I got to the SCA auth page I copied the URL and visited it in a new private window, to simulate the situation where the customer is authorizing the SCA payment but not logged in on the domain that they're about to be redirected to. Sure enough, I got:

Redirected by [...]/application_controller.rb:127:in 'require_distributor_chosen'

So I believe the specific, most latest scenario described by this issue will be resolved by #8090, which is already merged and will be in the next release.

It would be good to look into whether the 56 payments that @filipefurtad0 found and see if we can verify if they were all related to this same scenario (non-www vs www). I'll take some time to do that now. If it starts to take longer than an hour or two, I'd say we should move it to its own issue and close this one.

[andrewpbrett]

The four payments in the UK that @filipefurtad0 found are all from late July/early August. So @lin-d-hop's report that this is still happening multiple times per week looks like a separate issue. #8090 will prevent the scenario that @Cecilia-Hn most recently mentioned, but probably not whatever is still happening in the UK.

@lin-d-hop are you able to provide any order numbers of examples that you've seen recently to help narrow this down?

[Matt-Yorkley]

Seems like this case where the order cycle closes just before the user gets redirected back is still a good candidate for improvement, right? #7692 (comment)

[andrewpbrett]

Seems like this case where the order cycle closes just before the user gets redirected back is still a good candidate for improvement, right?

I think so, yes; but I think it's unlikely that that's the root cause of these payment issues. If the order cycle closes while the customer is performing the SCA auth, the customer gets a clear message indicating what happened. They're also redirected by the check_order_cycle_expiry method; the payment that @Cecilia-Hn mentions was redirected by require_distributor_chosen.

I looked at the logs in the UK, and there's nothing that matches the entries you would expect for the order cycle closing scenario: there are no redirects by the check_order_cycle_expiry method while attempting to process a payment intent in any recent logs (I went back to August 18).

So I believe:

• Allow sessions to work across subdomains #8090 will, once deployed, resolve one way that this was happening
• The scenario where the order cycle closes while the customer is authorizing the payment needs a separate issue (I'll create one). As far as I can tell, this scenario has not happened recently in the UK.
• There's still potentially a third scenario that we're not accounting for. I think it also needs a separate issue (I can also create this one unless @lin-d-hop has additional info on them) I looked for any payments in the UK that are currently in state = requires_authorization and there are 16; these are probably a good place to start investigating. These are their id's and updated_at:

[["2021-05-16", 374727], ["2021-05-25", 377352], ["2021-05-26", 377522], ["2021-07-30", 393002], ["2021-07-31", 393154], ["2021-07-31", 393157], ["2021-08-02", 393404], ["2021-08-05", 394307], ["2021-08-07", 394667], ["2021-08-08", 394957], ["2021-08-09", 395301], ["2021-08-09", 395306], ["2021-08-19", 397252], ["2021-08-23", 397055], ["2021-08-25", 398568], ["2021-09-02", 400105]]

[andrewpbrett]

I'm going to close this in favor of those two issues which more concisely describe the current state of the problem.