Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[5.x]: Deadlock found when trying to get lock on entries_authors table #15768

Open
yannkost opened this issue Sep 20, 2024 · 10 comments
Open

[5.x]: Deadlock found when trying to get lock on entries_authors table #15768

yannkost opened this issue Sep 20, 2024 · 10 comments
Labels

Comments

@yannkost
Copy link

What happened?

Description

We have an import job for a website that sometimes fails due to a deadlock issue. (This happens like 1 times out of 3).

2024-09-19 11:06:00 [queue.INFO] [nystudio107\seomatic\services\MetaContainers::invalidateContainerCacheByPath] Meta container cache cleared:  / 1 {"memory":172092664} 
2024-09-19 11:06:00 [queue.INFO] [nystudio107\seomatic\services\MetaBundles::updateMetaBundle] Meta bundle updated: section id: 6 from siteId: 1 {"memory":172132856} 
2024-09-19 11:06:00 [queue.WARNING] [craft\db\mysql\Schema::rollBackSavepoint] Tried to roll back a savepoint, but it does not exist: SQLSTATE[42000]: Syntax error or access violation: 1305 SAVEPOINT LEVEL3 does not exist
The SQL being executed was: ROLLBACK TO SAVEPOINT LEVEL3 {"memory":172866048} 
2024-09-19 11:06:00 [queue.WARNING] [craft\db\mysql\Schema::rollBackSavepoint] Tried to roll back a savepoint, but it does not exist: SQLSTATE[42000]: Syntax error or access violation: 1305 SAVEPOINT LEVEL2 does not exist
The SQL being executed was: ROLLBACK TO SAVEPOINT LEVEL2 {"memory":172852288} 
2024-09-19 11:06:00 [queue.WARNING] [craft\db\mysql\Schema::rollBackSavepoint] Tried to roll back a savepoint, but it does not exist: SQLSTATE[42000]: Syntax error or access violation: 1305 SAVEPOINT LEVEL1 does not exist
The SQL being executed was: ROLLBACK TO SAVEPOINT LEVEL1 {"memory":172846720} 
2024-09-19 11:06:00 [queue.ERROR] [import_log] An error occurred during the variations creation procedure. Terminating job. SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction
The SQL being executed was: INSERT INTO `entries_authors` (`entryId`, `authorId`, `sortOrder`) VALUES (20157, 1, 1) {"memory":172809296} 
2024-09-19 11:06:00 [queue.ERROR] [application] SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction
The SQL being executed was: INSERT INTO `entries_authors` (`entryId`, `authorId`, `sortOrder`) VALUES (20157, 1, 1) {"memory":172809512} 
2024-09-19 11:06:00 [queue.ERROR] [craft\queue\QueueLogBehavior::afterError]  [17372] Create Variations from bikes (attempt: 3, pid: 2522969) - Error (time: 15.876s): SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction
The SQL being executed was: INSERT INTO `entries_authors` (`entryId`, `authorId`, `sortOrder`) VALUES (20157, 1, 1) {"memory":169541600} 
2024-09-19 11:06:00 [queue.ERROR] [yii\db\Exception] PDOException: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction in /home/dahivabi/public_html/yoo/dev/vendor/yiisoft/yii2/db/Command.php:1320
Stack trace:
#0 /home/dahivabi/public_html/yoo/dev/vendor/yiisoft/yii2/db/Command.php(1320): PDOStatement->execute()
#1 /home/dahivabi/public_html/yoo/dev/vendor/yiisoft/yii2/db/Command.php(1120): yii\db\Command->internalExecute('INSERT INTO `en...')
#2 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/helpers/Db.php(1037): yii\db\Command->execute()
#3 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/elements/Entry.php(2613): craft\helpers\Db::batchInsert('{{%entries_auth...', Array, Array)
#4 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/elements/Entry.php(2517): craft\elements\Entry->_saveAuthors()
#5 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(3790): craft\elements\Entry->afterSave(true)
#6 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(1221): craft\services\Elements->craft\services\{closure}()
#7 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(3595): craft\services\Elements->ensureBulkOp(Object(Closure))
#8 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(1890): craft\services\Elements->_saveElementInternal(Object(craft\elements\Entry), false, false, NULL, Array, false, false, true)
#9 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(1221): craft\services\Elements->craft\services\{closure}()
#10 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(1877): craft\services\Elements->ensureBulkOp(Object(Closure))
#11 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Revisions.php(164): craft\services\Elements->duplicateElement(Object(craft\elements\Entry), Array)
#12 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/elements/Entry.php(2663): craft\services\Revisions->createRevision(Object(craft\elements\Entry), 1, NULL)
#13 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(3835): craft\elements\Entry->afterPropagate(false)
#14 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(1221): craft\services\Elements->craft\services\{closure}()
#15 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(3595): craft\services\Elements->ensureBulkOp(Object(Closure))
#16 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/services/Elements.php(1307): craft\services\Elements->_saveElementInternal(Object(craft\elements\Entry), true, false, NULL, Array, false, false, false)
#17 /home/dahivabi/public_html/yoo/dev/vendor/yoo/project-extension/src/services/ProjectExtensionService.php(59): craft\services\Elements->saveElement(Object(craft\elements\Entry))
#18 /home/dahivabi/public_html/yoo/dev/vendor/yoo/project-extension/src/jobs/Variations.php(144): yoo\projectextension\services\ProjectExtensionService::validateAndSafe(Object(craft\elements\Entry), 'Bike')
#19 /home/dahivabi/public_html/yoo/dev/vendor/yiisoft/yii2-queue/src/Queue.php(243): yoo\projectextension\jobs\Variations->execute(Object(craft\queue\Queue))
#20 /home/dahivabi/public_html/yoo/dev/vendor/yiisoft/yii2-queue/src/cli/Queue.php(147): yii\queue\Queue->handleMessage(17372, 'O:36:"yoo\\proje...', 300, 3)
#21 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/queue/Queue.php(191): yii\queue\cli\Queue->handleMessage(17372, 'O:36:"yoo\\proje...', 300, 3)
#22 /home/dahivabi/public_html/yoo/dev/vendor/craftcms/cms/src/queue/Queue.php(166): craft\queue\Queue->executeJob()```



### Steps to reproduce

1.Start a queue job that is inserting/updating a big number of entries (+500). Note: The same entries can be updated multiple times in the same queue. (We have to iterate 3 times over the entries because of the complexity of the different updates. The deadlock can happen at any of the 3 iteration steps, also the first one.)

### Expected behavior

The queue should run without getting a deadlock.

### Actual behavior

On random moments the queue fails due to a deadlock on the  entries_authors table.




### Craft CMS version

5.4.4

### PHP version

8.2

### Operating system and version

_No response_

### Database type and version

_No response_

### Image driver and version

_No response_

### Installed plugins and versions

- Seomatic
- Retour
- Formie
- Timber
@yannkost yannkost added the bug label Sep 20, 2024
@angrybrad
Copy link
Member

@yannkost Are you using the default web-based queue runner, or do you have an alternative setup (CLI/cron/daemon)?

If the latter, do you have one queue runner set up or multiple?

@yannkost
Copy link
Author

@angrybrad I do have the default queue runner that comes with the cms.

@angrybrad
Copy link
Member

@yannkost are the web servers in a load-balanced environment?

@yannkost
Copy link
Author

@angrybrad I can't tell as I don't know the setup of the hosting.

@yannkost
Copy link
Author

@angrybrad But it sometimes also happens on localhost, but more rarely.

@MGxpwr
Copy link

MGxpwr commented Oct 18, 2024

@angrybrad We ran in to the same issue. In our case it is a load-balanced webserver pointing to a single database.

  • Craft 5.4.7.1
  • PHP 8.2.24
  • MySQL MySQL 8.0.36

yii\db\Exception
SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction
The SQL being executed was: INSERT INTO entries_authors (entryId, authorId, sortOrder) VALUES (23207, 19681, 1)

@gopeter
Copy link
Contributor

gopeter commented Oct 22, 2024

Hi @angrybrad, just in case you need more examples. We are also running into deadlocks and we are running on a load balanced environment with 2 web servers and 2 workers, where we're using one daemon per worker.

@angrybrad
Copy link
Member

@yannkost

You say this happens locally for you (even if it is more rarely).

From the stack trace, I’d audit these two bits of custom code to ensure that whatever database resources they are grabbing are released as quickly as possible and to see if adding mutexes around critical database queries would prevent multiple queries from accessing the same bits of information simultaneously on your logic.

Added multiple queue runners (like using the default web-based ones) in a load-balanced environment can exacerbate the deadlock issue if the database is the point of resource contention.

...
#17 /home/dahivabi/public_html/yoo/dev/vendor/yoo/project-extension/src/services/ProjectExtensionService.php(59): craft\services\Elements->saveElement(Object(craft\elements\Entry))
#18 /home/dahivabi/public_html/yoo/dev/vendor/yoo/project-extension/src/jobs/Variations.php(144): yoo\projectextension\services\ProjectExtensionService::validateAndSafe(Object(craft\elements\Entry), 'Bike')
...

@MGxpwr Assuming you’re using the default web-based queue runner, this applies:

Added multiple queue runners (like using the default web-based ones) in a load-balanced environment can exacerbate the deadlock issue if the database is the point of resource contention.

Try getting it down to a single, dedicated queue runner and see if the behavior changes. https://craftcms.com/docs/5.x/system/queue.html#queue-runners

@gopeter

Same - try getting it down to a single, dedicated queue worker and see if the behavior changes

@joshmcoffman
Copy link

joshmcoffman commented Oct 31, 2024

@angrybrad We ran in to the same issue. In our case it is a load-balanced webserver pointing to a single database.

  • Craft 5.4.7.1
  • PHP 8.2.24
  • MySQL MySQL 8.0.36

I'm seeing this locally too @angrybrad . I've disabled all third party plugins too. I only have Craft's Amazon S3 2.2.1 and CKEditor 4.3.1.

  • Craft 5.4.9
  • PHP 8.3.12
  • MySQL 8.0.39
  • Queue is set to database. Config disables run queue automatically. Queue isn't even running right now.
  • Stacktrace only shows Craft vendor files

All I'm trying to do is go to Entries -> All Entries. I hit "New Entry" in upper right and pick our blog section. And I get the stacktrace I included at the bottom (not every time, maybe 2nd to 5th try)

This flow does a post with the section and siteId to /index.php?p=cms%2Factions%2Fentries%2Fcreate&site=en_us&v=1730410887394

Then it redirects to /cms/entries/blogEntry/new?site=en_us with the PDOException for deadlock found...

So I believe the issue is the flow of creating a new entry from All Entries. Nothing with the request stands out when comparing the POSTs but the one from All Entries can lead to exceptions.

It is NOT an issue if I go to Entries -> Blog and then just hit "New Entry". There is no deadlock exception and the URL becomes something like this: /entries/blogEntry/4326244?site=en_us&draftId=23831&fresh=1

But... Entries -> All Entries -> New Entry (pick a section) leads to this (usually within 5 tries):

Next yii\db\Exception: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction
The SQL being executed was: INSERT INTO `craft_entries_authors` (`entryId`, `authorId`, `sortOrder`) VALUES (4326232, 5271, 1)

in vendor/yiisoft/yii2/db/Schema.php:676

Stack trace:
#0 vendor/yiisoft/yii2/db/Command.php(1325): yii\db\Schema->convertException()
#1 vendor/yiisoft/yii2/db/Command.php(1120): yii\db\Command->internalExecute()
#2 vendor/craftcms/cms/src/helpers/Db.php(1037): yii\db\Command->execute()
#3 vendor/craftcms/cms/src/elements/Entry.php(2615): craft\helpers\Db::batchInsert()
#4 vendor/craftcms/cms/src/elements/Entry.php(2519): craft\elements\Entry->_saveAuthors()
#5 vendor/craftcms/cms/src/services/Elements.php(3786): craft\elements\Entry->afterSave()
#6 vendor/craftcms/cms/src/services/Elements.php(1222): craft\services\Elements->craft\services\{closure}()
#7 vendor/craftcms/cms/src/services/Elements.php(3591): craft\services\Elements->ensureBulkOp()
#8 vendor/craftcms/cms/src/services/Elements.php(1308): craft\services\Elements->_saveElementInternal()
#9 vendor/craftcms/cms/src/services/Drafts.php(261): craft\services\Elements->saveElement()
#10 vendor/craftcms/cms/src/controllers/EntriesController.php(184): craft\services\Drafts->saveElementAsDraft()
#11 [internal function]: craft\controllers\EntriesController->actionCreate()
#12 vendor/yiisoft/yii2/base/InlineAction.php(57): call_user_func_array()
#13 vendor/yiisoft/yii2/base/Controller.php(178): yii\base\InlineAction->runWithParams()
#14 vendor/yiisoft/yii2/base/Module.php(552): yii\base\Controller->runAction()
#15 vendor/craftcms/cms/src/web/Application.php(350): yii\base\Module->runAction()
#16 vendor/yiisoft/yii2/web/Application.php(103): craft\web\Application->runAction()
#17 vendor/craftcms/cms/src/web/Application.php(318): yii\web\Application->handleRequest()
#18 vendor/yiisoft/yii2/base/Application.php(384): craft\web\Application->handleRequest()
#19 web/index.php(22): yii\base\Application->run()
#20 {main}
Additional Information:
Array
(
    [0] => 40001
    [1] => 1213
    [2] => Deadlock found when trying to get lock; try restarting transaction
)
 {"memory":11321624,"exception":"[object] (yii\\db\\Exception(code: 40001): SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction
The SQL being executed was: INSERT INTO `craft_entries_authors` (`entryId`, `authorId`, `sortOrder`) VALUES (4326232, 5271, 1) at vendor/yiisoft/yii2/db/Schema.php:676)
[previous exception] [object] (PDOException(code: 40001): SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction at vendor/yiisoft/yii2/db/Command.php:1320)"}

Here is the deadlock info from MySQL SHOW ENGINE INNODB STATUS for one of the exceptions:


LATEST DETECTED DEADLOCK

2024-10-31 15:07:35 132277298267712
*** (1) TRANSACTION:
TRANSACTION 87122794, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 19 lock struct(s), heap size 1128, 10 row lock(s), undo log entries 3
MySQL thread id 4312, OS thread handle 132280741787200, query id 10774156 localhost 127.0.0.1 root update
INSERT INTO craft_entries_authors (entryId, authorId, sortOrder) VALUES (4326292, 5271, 1)

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 118920 page no 67 n bits 552 index PRIMARY of table staging_localhost.craft_entries_authors trx id 87122794 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;

*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 118920 page no 67 n bits 552 index PRIMARY of table staging_localhost.craft_entries_authors trx id 87122794 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) TRANSACTION:
TRANSACTION 87122795, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 19 lock struct(s), heap size 1128, 10 row lock(s), undo log entries 3
MySQL thread id 4313, OS thread handle 132280362202688, query id 10774157 localhost 127.0.0.1 root update
INSERT INTO craft_entries_authors (entryId, authorId, sortOrder) VALUES (4326293, 5271, 1)

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 118920 page no 67 n bits 552 index PRIMARY of table staging_localhost.craft_entries_authors trx id 87122795 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 118920 page no 67 n bits 552 index PRIMARY of table staging_localhost.craft_entries_authors trx id 87122795 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
0: len 8; hex 73757072656d756d; asc supremum;;

*** WE ROLL BACK TRANSACTION (2)

@angrybrad
Copy link
Member

@joshmcoffman Any chance that's on an environment we could get Craft control panel and SSH access to? If so, could you send to [email protected] and reference this issue?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

5 participants