Webhook checkout throws a 503 HTTP Status (Only for expired payments)

[michelheitbrink]

This week we see a lot of 503 HTTP errors on the Mollie checkout webhook. Its triggered when a payment has the status expired. After a lot of debugging we found the cause. The 503 status is thrown in the execute function of the Mollie\Payment\Controller\Checkout\Webhook. In the process a rollback is triggered.

After further inspection we want to share our findings:

This is the flow of a specific failing webhook. Found in our mollie.log. (For obvious reason i replaced all the id's in this example)

[2023-08-22T16:40:25.073644+00:00] Mollie.ERROR: error: "No order(s) found for transaction id tr_example_id" [] []
[2023-08-22T16:40:25.098238+00:00] Mollie.INFO: info: Locking: mollie.order.example_id [] []
[2023-08-22T16:40:25.215534+00:00] Mollie.INFO: webhook: {"resource":"payment","id":"tr_example_id","mode":"live","amount":{"value":"533.95","currency":"EUR"},"settlementAmount":null,"amountRefunded":null,"amountRemaining":null,"amountChargedBack":null,"description":"example description","method":"bancontact","status":"expired","createdAt":"2023-08-22T11:39:21+00:00","paidAt":null,"canceledAt":null,"expiresAt":null,"failedAt":null,"dueDate":null,"billingEmail":null,"profileId":"example_profile_id","sequenceType":"oneoff","redirectUrl":"https://example.com/mollie/checkout/process/?order_id=example_id&payment_token=example_payment_tokenm&utm_nooverride=1","cancelUrl":null,"webhookUrl":"https://example.com/mollie/checkout/webhook/?isAjax=1&orderId[]=encrypted_id","mandateId":null,"subscriptionId":null,"orderId":null,"settlementId":null,"locale":null,"metadata":{"order_id":"example_id","store_id":"11","payment_token":"example_payment_tokenm"},"details":null,"restrictPaymentMethodsToCountry":null,"_links":{"self":{"href":"https://api.mollie.com/v2/payments/tr_examnple_id","type":"application/hal+json"},"dashboard":{"href":"https://my.mollie.com/dashboard/org_example/payments/tr_examnple_id","type":"text/html"},"documentation":{"href":"https://docs.mollie.com/reference/v2/payments-api/get-payment","type":"text/html"}},"_embedded":null,"isCancelable":null,"amountCaptured":null,"captureMode":null,"captureDelay":null,"captureBefore":null,"applicationFee":null,"routing":null,"authorizedAt":null,"expiredAt":"2023-08-22T12:40:03+00:00","customerId":null,"countryCode":null} [
] []
[2023-08-22T16:40:25.385820+00:00] Mollie.INFO: info: Unlocking: mollie.order.example_id [] []
[2023-08-22T16:40:25.386330+00:00] Mollie.INFO: info: Key "mollie.order.example_id" unlocked [] []
[2023-08-22T16:40:25.386462+00:00] Mollie.ERROR: error: Rolled back transaction has not been completed correctly. [] []   

Following the log we created a trace:

1. \Mollie\Payment\Controller\Checkout\Webhook::execute is called
2. At first the orders aren't found but the fallback is triggered and the order is found.
3. \Mollie\Payment\Model\Mollie::processTransactionForOrder is executed for the found order.
4. The lock service is applied on line 360 (\Mollie\Payment\Model\Mollie).
5. In the execute function the exception is triggered inside the try catch. The finally is unlocking the applied lock.
6. The error is logged in a parent try catch: Rolled back transaction has not been completed correctly

This error can be thrown at 2 places:

• At the start of a mysql transaction.
• At a commit of a mysql transaction

Expected result:

• Status of the order is updated to expired.
• Customer is redirected to a failed payment page.

Current result:

• Status is unchanged. Order is still pending
• Customer sees an 503 Error.

Versions: Magento -> 2.4.6-p1 Mollie -> 2.30.1

[Frank-Magmodules]

Hello @michelheitbrink, thanks a lot for your exceptionally clear issue description; it surely helps us understand the issue. We are actively investigating it with a specific focus on achieving your expected result. I will provide you with further information once our research is complete.

[Frank-Magmodules]

Hi There @michelheitbrink ,

Thank you for opening this issue. Unfortunately, we are not able to reproduce this issue in a clean Magento 2 environment. Therefore we would like to ask you to please disable all modules and see if this problem still occurs. If this is not the case it should be easier to pinpoint the root cause of this by re-enabling the modules 1 by 1 to see if the problem still occurs.

If the problem occurs in an environment with all modules disabled we would like to take a closer look. Please contact us directly to share the details for this in a safe manner.

[Frank-Magmodules]

Hello @michelheitbrink, We haven't received any updates or additional information regarding this issue. Could you please inform me whether the issue is still relevant, and if it's not, kindly close the matter? Thank you!

[Frank-Magmodules]

HI There @michelheitbrink , as I haven't received a response regarding this matter, I believe it can be closed. In case you encounter the issue again, please don't hesitate to reopen it or create a new one.