Sometimes order statuses do not get updated properly due to timing problem

[shaunek-hero]

We are using version 5.3.2.

Normally the IPN messages come in and the Woo order status updates just fine, but we have now seen two different orders have an issue where an IPN message was delivered but the order status did not get updated to the appropriate status. @farjad6 , my coworker, has determined that this is a timing issue. Let me describe step by step what happened:

• Our server received an IPN message with the status of "paid"
• The BitPayIpnProcess->execute() method starts and there is a line in that method that calls $bitpay_invoice = $this->factory->create()->getInvoice( $invoice_id, Facade::POS, false ); which we think does a live HTTP call to get the invoice
• In this scenario the status of the invoice from this call is "complete" already. But since the IPN message was for "paid" the control flows to the BitPayIpnProcess->process_processing() method
• This results in an error in the BitPayIpnProcess->validate_bitpay_status_in_available_statuses() method. The error log file shows the following

  
  ======================INCOMING IPN ERROR===========================
  Wrong BitPay status. Status: complete available statuses: Array
  (
  [0] => paid
  )

=================================================

- Since it errored out it didn't add a comment to the order and also didn't update the order status.
- Soon after our server received an IPN message with status of "confirmed"
- A very similar problem happened where since the invoice was already in "completed" status it errored in `BitPayIpnProcess->validate_bitpay_status_in_available_statuses()` method with this error:

======================INCOMING IPN ERROR=========================== Wrong BitPay status. Status: complete available statuses: Array ( [0] => confirmed )

=================================================

- Since it errored out, it didn't obey our settings, which is set to change the order status to "wc-processing".
- When our server received the IPN for "complete" it processed just fine. HOWEVER, since we have the setting set to not change the order status when the "complete" messages are received it took no action.
- The end result is that our order status was still in "wc-pending" whereas we expected it to end up at "wc-processing"

I hope I've illustrated the problem here. I will go ahead and send the log file for that day as well as the error log file to the email address you previously shared with me. 

One last point on this is that we saw this sequence happen today, but we did see this happen one time before on March 12 as well.

Please let me know if you have any questions.

[bobbrodie]

@shaunek-hero this is an interesting one. From a validation standpoint, this is important:

The BitPayIpnProcess->execute() method starts and there is a line in that method that calls $bitpay_invoice = $this->factory->create()->getInvoice( $invoice_id, Facade::POS, false ); which we think does a live HTTP call to get the invoice

It does perform a live lookup, because we should check that the inbound webhook is valid. Another solution here would be HMAC, which would eliminate the need to make the extra network call, but I don't believe that's currently implemented.

I'll talk to a few teammates and see what might be a good path forward here. I'm thinking that we might need to think of something creative based on a combination of the IPN + the state that's fetched. For example, if a paid IPN comes in but the live status is complete, then we should be able to safely assume that the IPN is valid.

[bobbrodie]

Hey @shaunek-hero just a quick update on this -- we've talked it over as a group and are documenting a way forward with today's validation method of using a GET on the invoice. We'll continue to discuss HMAC to help eliminate the need for the extra API call.

To summarize:

• We're planning logic to handle the difference between the webhook status and the validation GET, and after we finish that we'll follow up here prior to implementation
• If / when HMAC hits the roadmap, we'll keep you in the loop

[shaunek-hero]

Okay thanks for the update.

Just wanted to let you know we have seen this happen a couple more times since our original report. We unfortunately aren't getting strong take up on our Bitpay payment option, so we are only getting a few orders a week this way, which translates into our 4-5 occurrences of this being a relatively high percentage of the overall orders. Good thing is our operations guys know how to spot and handle these cases now.

Thanks for working on this!

[p-maguire]

@shaunek-hero & @bobbrodie The plugin allows Admins to set a WooCommerce Order status change for the following BitPay Invoice status updates via Webhook:

• Paid
• Confirmed
• Complete

Since we’re validating Webhook data against the live Invoice data, I think we can use this as a guide for a change to the plugin:

• Paid Webhook will pass validation against an Invoice status of Paid, Confirmed, or Complete
• Confirmed Webhook will pass validation against an Invoice status of Confirmed or Complete
• Complete Webhook will pass validation against an Invoice status of Complete

I don’t think we need to be concerned about other statuses for this case since we're primarily concerned about making sure that Webhooks update an Order’s status for processing.

[shaunek-hero]

@p-maguire I discussed this with my colleague @farjad6 and we think your idea would work nicely for what we have seen.