bitpay / bitpay-checkout-for-woocommerce

BitPay Checkout for WooCommerce
MIT License
14 stars 22 forks source link

Refund functionality bug #75

Closed shaunek-hero closed 4 months ago

shaunek-hero commented 6 months ago

We found what we consider a serious bug in the "refund" functionality.

TLDR; After initiating a refund through the BitPay dashboard the Woocommerce order status was eventually updated to "Refunded" (wc-refunded), but then AFTER that the order status was changed to "Processing" (wc-processing). This is unfortunate because we can very easily ship out orders that are supposed to be in Refunded status. This is a big problem for us. We would like to figure out how this can be fixed, we might also be willing to provide coding assistance as well, but honestly we aren't sure the best direction to fix. At this point we will be waiting for a fix before we launch BitPay for our customers in prod because this is a showstopper for us.

Setup: Our plugin config is setup includes setting "BitPay Confirmed Invoice Status" to "Do not change" and "BitPay Complete Invoice Status" to wc-processing... we have it set this way because we want to make sure that we don't set the Woo order status to wc-processing until we know the crypto transaction is complete.

As a side note here is a dump of our "woocommerce_bitpay_checkout_gateway_settings"....

a:25:{s:7:"enabled";s:3:"yes";s:11:"bitpay_logo";s:20:"BitPay-Accepted-Card";s:23:"bitpay_logo_image_white";s:0:"";s:22:"bitpay_logo_image_dark";s:0:"";s:20:"bitpay_checkout_info";s:0:"";s:29:"bitpay_checkout_merchant_info";s:0:"";s:25:"bitpay_checkout_tier_info";s:0:"";s:11:"description";s:2:"Hi";s:25:"bitpay_checkout_token_dev";s:44:"____________________________________________";s:26:"bitpay_checkout_token_prod";s:44:"____________________________________________";s:24:"bitpay_checkout_endpoint";s:10:"production";s:20:"bitpay_checkout_flow";s:1:"2";s:20:"bitpay_checkout_slug";s:0:"";s:22:"bitpay_custom_redirect";s:0:"";s:16:"bitpay_close_url";s:0:"";s:20:"bitpay_checkout_mini";s:1:"2";s:29:"bitpay_checkout_capture_email";s:1:"1";s:32:"bitpay_checkout_checkout_message";s:4:"cool";s:21:"bitpay_checkout_error";s:13:"/bitpay-error";s:29:"bitpay_checkout_error_message";s:21:"Transaction Cancelled";s:46:"bitpay_checkout_order_process_confirmed_status";s:13:"bitpay-ignore";s:45:"bitpay_checkout_order_process_complete_status";s:13:"wc-processing";s:36:"bitpay_checkout_order_expired_status";s:1:"1";s:15:"bitpay_log_mode";s:1:"1";s:12:"instructions";s:63:"Pay with BitPay using one of the supported cryptocurrencies<br>";}

Details: What we see in the logs (which are attached below) as well as in or Woocommerce order screen, the IPN/webhooks were processed just fine all the way through the point where the refund IPN was received. At that point the order status changed to Refunded (wc-refunded). However, after that our system received a few more messages including a message that had a status of "complete" in it, and this triggered our order status to be changed to Processing (wc-processing).

Please check it out, the BitPay invoice ID is Tv3y8qpm4Ciq6yNqGojgEj, and our stage site's order id is 35170. Even though we were using our staging site, this is on the BitPay prod system, not test.bitpay.com. Also, one thing to note is that in our system we have customized the names of the Woocommerce order statuses such that instead of showing "Processing" for wc-processing, our system shows "Shipping Queue" for wc-processing. So when you look at the screenshot below when it says "Shipping Queue" you should read that as "Processing" in a regular Woocommerce setup. It is litterally the same underlying status, with a different label.

Woo-order-for-Tv3y8qpm4Ciq6yNqGojgEj

Here are the logs, search for Tv3y8qpm4Ciq6yNqGojgEj across these two log files to see the full history 20240124_transactions.log 20240125_transactions.log

bobbrodie commented 6 months ago

Thank you so much, @shaunek-hero -- this is incredibly helpful. I'll talk this through with the team handling the webhooks, since there might not be a change necessary on the plugin. We could consider adding logic to not allow changes to certain statuses after refunding, but I'm opening a dialog and we'll keep you posted.

What we see in the logs (which are attached below) as well as in or Woocommerce order screen, the IPN/webhooks were processed just fine all the way through the point where the refund IPN was received. At that point the order status changed to Refunded (wc-refunded). However, after that our system received a few more messages including a message that had a status of "complete" in it, and this triggered our order status to be changed to Processing (wc-processing).

Just to confirm, when you mention that a few more messages were received, you mean that additional IPNs came in, correct?

shaunek-hero commented 6 months ago

@bobbrodie Yes, and by "a few" I should have said "exactly one" message came after. I could be wrong here, since I have JUST realized that the log files don't record the entire payload, but instead just the "data" element of the payload, and without that I can't precisely line up everything myself (outside me adding more logging or taking advantage of your expertise/knowledge). But in any case I see an entry in the log that looks like this:

======================INCOMING IPN===========================
Array
(
    [id] => 6qmkqLyq7r2pgHaDnmkny6
    [invoice] => Tv3y8qpm4Ciq6yNqGojgEj
    [supportRequest] => 7wQVAw9jkp2tNBZBW2UPNK
    [refundAddress] => bc1qnl50pxan5se3qz4ck60eclse4tu98myk6las4p
    [txid] => 491b78cfffdbfa6faec96d028dd4a19edc445505b3b8c963c10f3093f16a0864
    [type] => full (current rate)
    [status] => success
    [amount] => 6.48
    [transactionCurrency] => BTC
    [transactionAmount] => 0.000164
    [transactionRefundFee] => 0
    [currency] => USD
    [lastRefundNotification] => 2024-01-24T20:32:24.866Z
    [refundFee] => 0
    [immediate] => 
    [buyerPaysRefundFee] => 
    [requestDate] => 2024-01-24T20:32:24.000Z
)

I believe this is the message that changed the Woo order status to wc-refunded. Then then next message I see is shaped more like the other IPN messages for invoice Tv3y8qpm4Ciq6yNqGojgEj, and it's status is "complete" - I believe this message changed our order status back to wc-processing

======================INCOMING IPN===========================
Array
(
    [id] => Tv3y8qpm4Ciq6yNqGojgEj
    [url] => https://bitpay.com/invoice?id=Tv3y8qpm4Ciq6yNqGojgEj
    [status] => complete
    [price] => 6.48
    [currency] => USD
    [invoiceTime] => 1706127177665
    [expirationTime] => 1706128374020
    [currentTime] => 1706127828098
    [exceptionStatus] => 
    [buyerFields] => Array
        (
        )

    [paymentSubtotals] => Array
        (
            [BTC] => 16400
            [BCH] => 2773700
            [ETH] => 2953000000000000
            [GUSD] => 648
            [PAX] => 6480000000000000000
            [BUSD] => 6480000000000000000
            [USDC] => 6480000
            [XRP] => 12715052
            [DOGE] => 8348845200
            [DAI] => 6490000000000000000
            [WBTC] => 16400
            [LTC] => 9976300
            [SHIB] => 7.45684695052E+23
            [APE] => 4997734000000000000
            [EUROC] => 5954796
            [MATIC] => 8956561000000000000
            [ETH_m] => 2923000000000000
            [MATIC_e] => 8956561000000000000
            [USDC_m] => 6480000
            [USDT] => 6490000
            [PYUSD] => 6480000
        )

    [paymentTotals] => Array
        (
            [BTC] => 16400
            [BCH] => 2773700
            [ETH] => 2953000000000000
            [GUSD] => 648
            [PAX] => 6480000000000000000
            [BUSD] => 6480000000000000000
            [USDC] => 6480000
            [XRP] => 12715052
            [DOGE] => 8425349300
            [DAI] => 6490000000000000000
            [WBTC] => 16400
            [LTC] => 9976300
            [SHIB] => 7.45684695052E+23
            [APE] => 4997734000000000000
            [EUROC] => 5954796
            [MATIC] => 8956561000000000000
            [ETH_m] => 2923000000000000
            [MATIC_e] => 8956561000000000000
            [USDC_m] => 6480000
            [USDT] => 6490000
            [PYUSD] => 6480000
        )

    [exchangeRates] => Array
        (
        )

    [amountPaid] => 16400
    [orderId] => 35170
    [transactionCurrency] => BTC
    [lnInvoiceId] => 187b7bf1689faddca0a221d82754bdb0cc9643d6ba06fd93663dd684e6641ce6
    [lnPaymentRequest] => lnbc164u1pjmzufxpp5rpahhutgn7kaeg9zy8vzw49akrxfvs7khgr0mymx8htgfenyrnnqdpy23mrx7fcw9cx6dzrd9cnv72ww9rk76n8g44qcqzzsxqzk0rzjqfnrerglfngp97cy05jw7rlmm6vsf4awp7pc0fkykryk2047gj8egrpvs5qqdfcqqyqqqqlgqqqqqqgq2qsp58z9ueyp05jvlry8yys8h7rskup2rvrauslwegxrs45waruumfghs9qyyssqwxz6r8puhrqg6mlsalpczjqzdpzfn7ll3wwwpac794dxvtpvwpzxvpyqg55w60zd9fzhmuxhnhkjwu6tk75vt3tgglp5prg9m7ymrjspngyx4d
)
shaunek-hero commented 6 months ago

I did have an idea on a change that could be beneficial even beyond this specific bug. The idea would be to update some of the methods in BitPayIpnProcess to not change the Woo order's status if the existing/current order status is in a list of predefined statuses that are essentially "final state statuses," meaning statuses that shouldn't be updated.

For example, if an order is already in wc-refunded status, the status of that order probably shouldn't be updated via the BitPay IPN messages again. Same thing for wc-cancelled, wc-failed, and even wc-completed. To further illustrate this last one, wc-completed, it would be unfortunate if an order was in wc-processing and got shipped very quickly by the warehouse and got moved to wc-complete, but then an IPN message came through with invoice status "complete" and then the Woo order status got updated back to wc-processing - it might get shipped again if the merchant doesn't have some other countermeasure. Another example is that if a Woocommerce admin updates an order status to wc-cancelled maybe the plugin shouldn't try to update the status anymore - not to say that order notes can't be added for each IPN, but the Woo order status probably should stay in wc-cancelled and not move to any statuses such as wc-processing.

In addition to this I'm thinking it might be good to do a tiny refactor around the order notes being logged as they aren't completely consistent IMO.

If you largely agree with this idea I could do a PR with my suggestions and you could see if it would meet your expectations.

bobbrodie commented 6 months ago

Hey @shaunek-hero just a heads up -- I'm talking to a few folks:

Just for some background, we've been refactoring the plugin over time and are working to introduce as little disruption as possible. Right now, we are working on introducing unit and functional tests that will cover all the versions of PHP, WordPress, and Woo that we support. This will allow us to test scenarios like webhook order.

The idea would be to update some of the methods in BitPayIpnProcess to not change the Woo order's status if the existing/current order status is in a list of predefined statuses that are essentially "final state statuses," meaning statuses that shouldn't be updated.

After talking about this earlier, we think this might be the best way to go. We do have control over how we process webhooks, so if we can set a clearly documented set of rules that apply to eCom sites in general, that will be a great place to start.

If an order is already in wc-refunded status, the status of that order probably shouldn't be updated via the BitPay IPN messages again

This should be OK. A refund request can be canceled through the API if it's not processing or confirmed, however I don't think this should prevent this logic.

Same thing for wc-cancelled, wc-failed, and even wc-completed

That makes sense as well, yep.

Another example is that if a Woocommerce admin updates an order status to wc-cancelled maybe the plugin shouldn't try to update the status anymore - not to say that order notes can't be added for each IPN, but the Woo order status probably should stay in wc-cancelled and not move to any statuses such as wc-processing.

I think this could be helpful, as long as we log it to the notes in a way that shows it was a received, but unprocessed IPN.

In addition to this I'm thinking it might be good to do a tiny refactor around the order notes being logged as they aren't completely consistent IMO.

We're tackling this one and have it coming up. It came up in conversation just last week on 1/18 :)

If you largely agree with this idea I could do a PR with my suggestions and you could see if it would meet your expectations.

We definitely appreciate it, but I definitely don't want you to feel obligated. If it's OK with you, I'd love to get this story on our board today and start work. It aligns nicely with our automated testing initiative, which will also make the functions more testable. This effort will be prioritized above that of course, so we can get you up and running.

I'm working with a few people on this, and we'll review the logic to make sure we're not missing anything. Once the PR is up, I'll tag you if that's OK. We would love to have your feedback.

I can't thank you enough for your collaboration. You are helping make the plugin better, and we're excited that its usage is growing!

bobbrodie commented 6 months ago

Hey there @shaunek-hero just a quick update, we are working on this, and are planning to expose hooks to allow people to extend/override the behavior. That way, we'll have a nice base, but there may be reasons people want to hook into it, so we can give that flexibility.

shaunek-hero commented 5 months ago

Awesome, yes adding some hooks in there would be a really great idea!

bobbrodie commented 5 months ago

Sounds great @shaunek-hero -- this is at the top of our list and the feature is in progress :)

bobbrodie commented 5 months ago

@shaunek-hero Just keeping you in the loop, we're toward the end of development on this and are working on validating a few things in the IPN details while reviewing the plugin updates together. Thanks!

bobbrodie commented 5 months ago

@shaunek-hero we have an open PR for this #76 that we're testing. If you'd like to take a look as well that would be awesome. This will be part of our 5.4.0 release. Thanks!

shaunek-hero commented 5 months ago

I'll check that out today, thanks!