Magento2: Deadlock when saving the order

Created on 25 May 2017  路  8Comments  路  Source: magento/magento2

I Started see that issue when our site under stress test loading, I'm not sure but in normal running our site does not met that issue

Preconditions

Magento: 2.0.10 EE
PHP : 7.0.18

Steps to reproduce

1.Using HP load runner to run the load test with 1000 vUsers
2.Placing order
3.Set send mail by cron "Asynchronous sending = YES"

  1. Leave the cron run with default expression time

*/1 * * * *

Expected result:

  • The problem will not appear

Actual result

Issue

36358:[2017-05-25 08:15:12] main.CRITICAL: PDOException: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction in /opt/nestle/magento/releases/20170524095845/vendor/magento/zendframework1/library/Zend/Db/Statement/Pdo.php:228
36359-Stack trace:
36360-#0 /opt/nestle/magento/releases/20170524095845/vendor/magento/zendframework1/library/Zend/Db/Statement/Pdo.php(228): PDOStatement->execute(Array)
36361-#1 /opt/nestle/magento/releases/20170524095845/vendor/magento/framework/DB/Statement/Pdo/Mysql.php(95): Zend_Db_Statement_Pdo->_execute(Array)
36362-#2 /opt/nestle/magento/releases/20170524095845/vendor/magento/zendframework1/library/Zend/Db/Statement.php(303): Magento\Framework\DB\Statement\Pdo\Mysql->_execute(Array)
36363-#3 /opt/nestle/magento/releases/20170524095845/vendor/magento/zendframework1/library/Zend/Db/Adapter/Abstract.php(480): Zend_Db_Statement->execute(Array)
36364-#4 /opt/nestle/magento/releases/20170524095845/vendor/magento/zendframework1/library/Zend/Db/Adapter/Pdo/Abstract.php(238): Zend_Db_Adapter_Abstract->query('UPDATE `sales_o...', Array)
36365-#5 /opt/nestle/magento/releases/20170524095845/vendor/magento/framework/DB/Adapter/Pdo/Mysql.php(453): Zend_Db_Adapter_Pdo_Abstract->query('UPDATE `sales_o...', Array)
36366-#6 /opt/nestle/magento/releases/20170524095845/vendor/magento/framework/DB/Adapter/Pdo/Mysql.php(511): Magento\Framework\DB\Adapter\Pdo\Mysql->_query('UPDATE `sales_o...', Array)
36367-#7 /opt/nestle/magento/releases/20170524095845/vendor/magento/zendframework1/library/Zend/Db/Adapter/Abstract.php(635): Magento\Framework\DB\Adapter\Pdo\Mysql->query('UPDATE `sales_o...', Array)
36368-#8 /opt/nestle/magento/releases/20170524095845/vendor/magento/module-sales/Model/ResourceModel/Attribute.php(101): Zend_Db_Adapter_Abstract->update('sales_order', Array, '(entity_id= 213...')

From my investigation

On file : vendor\magento\module-sales\Model\EmailSenderHandler.php

 public function sendEmails()
     {
         if ($this->globalConfig->getValue('sales_email/general/async_sending')) {
             $this->entityCollection->addFieldToFilter('send_email', ['eq' => 1]);
             $this->entityCollection->addFieldToFilter('email_sent', ['null' => true]);
             foreach ($this->entityCollection->getItems() as $item) {
                 if ($this->emailSender->send($item, true)) {
                     $this->entityResource->save(
                         $item->setEmailSent(true)
                     );
                 }
             }
    }
}

This function will getting order which just created and trying to send mail then update the flag "email_sent=1"
I confirm this issue will not appear when the site in normal load, but in high load order entity take much time to save and can be updated several times before the transaction completely

So my understand is:

  1. Order entity object is created
  2. Cron getting the order entity without filtering based on order's status
  3. Order entity trying to update few things several times but it takes a lots of time due to server is in high load
  4. Cron hit when order entity is updating and causes the deadlock
Clear Description Format is valid needs update bug report

Most helpful comment

Hi @magento-engcom-team
The issue is still reproducible time by time on the Magento 2.3.2.

image

Thank you!

All 8 comments

I can see 3 solutions here

  • Sending the mail using a (guaranteed single execution) message queue would be much better, or
  • updating just the single field instead of the entire order. There is just no need to process everything. Or,
  • remove the field from the order table, and create a separate email log table that can be linked to the order table. This way we can keep track of all order mails sent, their timings and there is no need to change the order itself anymore. This would also make a handy feature on its own

@ngoctruongbc thank you for your report.
Given this issue is reported against Enterprise edition and should be reported via the Support portal of your account or Partner portal if you are a partner reporting on behalf of a merchant, please let me know if it was reported to Support in order to avoid duplicates.

@ngoctruongbc, thank you for your report.
We were not able to reproduce this issue by following the steps you provided. If you'd like to update it, please reopen the issue.
We tested the issue on 2.1.9

Hi @magento-engcom-team
The issue is still reproducible time by time on the Magento 2.3.2.

image

Thank you!

Hi @engcom-Alfa. Thank you for working on this issue.
In order to make sure that issue has enough information and ready for development, please read and check the following instruction: :point_down:

  • [ ] 1. Verify that issue has all the required information. (Preconditions, Steps to reproduce, Expected result, Actual result).
    DetailsIf the issue has a valid description, the label Issue: Format is valid will be added to the issue automatically. Please, edit issue description if needed, until label Issue: Format is valid appears.
  • [ ] 2. Verify that issue has a meaningful description and provides enough information to reproduce the issue. If the report is valid, add Issue: Clear Description label to the issue by yourself.

  • [ ] 3. Add Component: XXXXX label(s) to the ticket, indicating the components it may be related to.

  • [ ] 4. Verify that the issue is reproducible on 2.4-develop branch

    Details- Add the comment @magento give me 2.4-develop instance to deploy test instance on Magento infrastructure.
    - If the issue is reproducible on 2.4-develop branch, please, add the label Reproduced on 2.4.x.
    - If the issue is not reproducible, add your comment that issue is not reproducible and close the issue and _stop verification process here_!

  • [ ] 5. Add label Issue: Confirmed once verification is complete.

  • [ ] 6. Make sure that automatic system confirms that report has been added to the backlog.

Hi @m2-assistant[bot] Here is your new Magento Instance: https://undefined
Admin access: https://undefined/undefined
Login: undefined, Password: undefined

Hi @JPNestNgocTruong @VitaliyBoyko.
Looks like this is the same issue as in #8933.
Isn't?
Thanks!

The root of the issue seems to be the same. Closing this one. Thank you!

Was this page helpful?
0 / 5 - 0 ratings