paytrail / paytrail-for-adobe-commerce

Paytrail payment service for Adobe Commerce (formerly known as Magento 2)
https://www.paytrail.com
MIT License
2 stars 7 forks source link

Simultaneous receipt and callback requests cause duplicate status changes #90

Open mattijv opened 4 months ago

mattijv commented 4 months ago

Describe the bug If the async callback from Paytrail to the /paytrail/callback controller happens at the same time as the customer returning from the payment portal, the order status/state will be updated twice.

To Reproduce

  1. Send the async callback request at the exact same time (within tolerances) that the customer returns from the payment portal.

Expected behavior The order does not get updated twice.

Screenshots We observed an issue on an order where the order status and state were updated twice in a quick succession. View from Magento admin showing the duplicate status/state changes

This happened when the async confirmation from Paytrail was sent during the same second as the customer returning from the payment portal:

Log showing simultaneous requests

Additional context The module code has this comment describing the exact issue, but I could not quickly locate any mechanism to actually remedy the issue.

Perhaps locking on the reference number would help prevent simultaneous execution?

bartoszkaluzny-solteq commented 4 months ago

Thank you for reporting this issue. Can you provide what module version are you using?

mattijv commented 4 months ago

The above problem happened with 2.1.0, which is not the latest version (2.1.4).

I, however, did compare the diff between those versions, and did not notice any (obvious, at least) changes that would affect the issue.

bartoszkaluzny-solteq commented 4 months ago

Maybe fix of loading orders in callback fixed your issue. However, your issue should not happened if callback_delay is set correctly. By default in config.xml there is callback_delay which should be set to 120 (seconds), which means that callback request will return with 120s delay between receipt request.

You can check if this callbackDelay is correctly set to payment request data, or maybe you have some issue there.

mattijv commented 4 months ago

The logs generated by the module indicate that the callbackDelay was correctly set to 120 on the order in question.

[2024-07-11TXXXXXX] main.INFO: {"stamp":"XXXXXX","reference":"XXXXXX","amount":XXXXXX,"currency":"EUR","language":"FI","items":[...],"customer":{...},"deliveryAddress":{...},"invoicingAddress":{...},
"redirectUrls":{"success":"https:\/\/XXXXXX\/paytrail\/receipt\/","cancel":"https:\/\/XXXXXX\/paytrail\/receipt\/"},"callbackUrls":{"success":"https:\/\/XXXXXX\/paytrail\/callback\/","cancel":"https:\/\/XXXXXX\/paytrail\/callback\/"},
"callbackDelay":120} [] []
bartoszkaluzny-solteq commented 4 months ago

Is this happened once or you have some other affected orders?

mattijv commented 4 months ago

We have identified two other orders (so three in total) with similar issues (duplicate updates and receipt/callback requests hitting at almost the same time) during the last couple months. Did not check too far back, but safe to say that this is not an isolated incident.

bartoszkaluzny-solteq commented 4 months ago

Ok, but all of those incidents happened on version 2.1.0? On latest version 2.1.4 you have no faced incident like this?

mattijv commented 4 months ago

We have not yet update to 2.1.4 in production, but, as mentioned, I am unsure if any of the changes introduced there will help (happy to be wrong about this, though).

We will be updating to the latest version, but will probably add our own locking system on top of that to prevent simultaneous requests from running.

That said, it should be fairly easy for you to verify if the issue is still present in the current version:

  1. Send the receipt request and pause it with a debugger here-ish.
  2. Send the callback request and pause it with a debugger around here.
  3. Step the two processes roughly in lockstep to simulate them executing in parallel.
  4. Observe the status history of the order. It should only get updated once, if the code works correctly.
bartoszkaluzny-solteq commented 4 months ago

Thank you for the steps. That's why there is callback_delay which should prevent those situations, and I couldn't reproduce the issue without using debugger.

Let's leave this issue open, and let me know if issue is still there, when you will do the update to the latest module version. If issue will be still there, we could add some locking system, but it shouldn't be needed if callback_delay works as intended.

mattijv commented 4 months ago

That's why there is callback_delay which should prevent those situations

Obviously there's something wrong with it, since the requests were simultaneous in the few problematic cases. And anyway it's not a durable solution as the receipt request could be delayed for any number of reasons. Personally, I'd much rather fix the root problem (== simultaneous requests cause issues).

That said, we will be implementing a locking solution to prevent this problem in the future so I expect we won't see the issue any more.

Happy to leave the issue open, though, so other users can maybe chime in if they happen to run into this.

kotivuori commented 2 months ago

@mattijv If possible, could you provide checkout-transaction-id values from these orders to tech@paytrail.com?