Project

General

Profile

Actions

Bug #90069

closed

Get Deadlock Error on delete cache in redirect modul

Added by Marco Schmidt over 4 years ago. Updated about 1 year ago.

Status:
Closed
Priority:
Must have
Assignee:
-
Category:
Caching
Target version:
-
Start date:
2020-01-08
Due date:
% Done:

100%

Estimated time:
TYPO3 Version:
9
PHP Version:
Tags:
Complexity:
Is Regression:
Sprint Focus:

Description

I've got an error from time to time and cannot reproduce this.

Core: Exception handler (WEB): Uncaught TYPO3 Exception: An exception occurred while executing 'DELETE tags2, cache1 FROM cf_cache_pages_tags AS tags1 JOIN cf_cache_pages_tags AS tags2 ON tags1.identifier = tags2.identifier JOIN cf_cache_pages AS cache1 ON tags1.identifier = cache1.identifier WHERE tags1.tag = 'redirects'': Deadlock found when trying to get lock; try restarting transaction | Doctrine\DBAL\Exception\DeadlockException thrown in file /www/htdocs/xxxx/example.de/typo3_src-9.5.13/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/AbstractMySQLDriver.php in line 34.

If this is no bug in TYPO3 Core/Redirect Modul, what can I do? Or can I ignore this message?

Actions #1

Updated by Marco Schmidt over 4 years ago

  • Category set to Caching
Actions #2

Updated by Jonas Schwabe over 4 years ago

  • Category changed from Caching to Recycler

We have the same thing from time to time as well (currently ignoring this as it happens very infrequently):

2020-01-08 05:09:49 0x7fd1c5543700
*** (1) TRANSACTION:
TRANSACTION 84974964, ACTIVE 0 sec starting index read
mysql tables in use 3, locked 3
LOCK WAIT 5 lock struct(s), heap size 1136, 3 row lock(s)
MySQL thread id 6789539, OS thread handle 140538938734336, query id 850188977 XXX YYY Sending data
DELETE tags2, cache1 FROM cf_cache_pages_tags AS tags1 JOIN cf_cache_pages_tags AS tags2 ON tags1.identifier = tags2.identifier JOIN cf_cache_pages AS cache1 ON tags1.identifier = cache1.identifier WHERE tags1.tag = 'redirects'
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 10979 page no 4 n bits 336 index cache_id of table `YYY`.`cf_cache_pages` trx id 84974964 lock_mode X waiting
Record lock, heap no 223 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 9; hex 726564697265637473; asc redirects;;
 1: len 4; hex 5e1555f4; asc ^ U ;;
 2: len 4; hex 000014bd; asc     ;;

*** (2) TRANSACTION:
TRANSACTION 84974962, ACTIVE 0 sec starting index read
mysql tables in use 3, locked 3
9 lock struct(s), heap size 1136, 6 row lock(s)
MySQL thread id 6789540, OS thread handle 140538935523072, query id 850188975 XXX YYY Sending data
DELETE tags2, cache1 FROM cf_cache_pages_tags AS tags1 JOIN cf_cache_pages_tags AS tags2 ON tags1.identifier = tags2.identifier JOIN cf_cache_pages AS cache1 ON tags1.identifier = cache1.identifier WHERE tags1.tag = 'redirects'
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 10979 page no 4 n bits 336 index cache_id of table `YYY`.`cf_cache_pages` trx id 84974962 lock_mode X
Record lock, heap no 223 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 9; hex 726564697265637473; asc redirects;;
 1: len 4; hex 5e1555f4; asc ^ U ;;
 2: len 4; hex 000014bd; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 10982 page no 3 n bits 280 index PRIMARY of table `YYY`.`cf_cache_pages_tags` trx id 84974962 lock_mode X locks rec but not gap waiting
Record lock, heap no 191 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 000014bd; asc     ;;
 1: len 6; hex 000005107af5; asc     z ;;
 2: len 7; hex ec0000038f0110; asc        ;;
 3: len 9; hex 726564697265637473; asc redirects;;
 4: len 9; hex 726564697265637473; asc redirects;;

*** WE ROLL BACK TRANSACTION (1)

I think this is what is happening:
For some reason the redirects cache tag is being flushed when the redirect information needs to be cached again (e.g. cache has become stale or was deleted).
This flush is actually not necessary because there is always only one entire with this tag (as far as I can tell) which holds all the data necessary for routing redirects.

So when two requests hit the TYPO3 installation and the cache is not valid, both requests first flush the cache. Locking cf_cache_pages and cf_cache_pages_tags.
So simple solution would be to not flush at all but just write to the same key.

Actions #3

Updated by Jonas Schwabe over 4 years ago

  • Category changed from Recycler to Caching
Actions #4

Updated by Alexander Grein about 4 years ago

Same here, problem still exists in 9.5.14

Actions #5

Updated by Gerrit Code Review about 4 years ago

  • Status changed from New to Under Review

Patch set 1 for branch master of project Packages/TYPO3.CMS has been pushed to the review server.
It is available at https://review.typo3.org/c/Packages/TYPO3.CMS/+/63729

Actions #6

Updated by Gerrit Code Review about 4 years ago

Patch set 2 for branch master of project Packages/TYPO3.CMS has been pushed to the review server.
It is available at https://review.typo3.org/c/Packages/TYPO3.CMS/+/63729

Actions #7

Updated by Gerrit Code Review about 4 years ago

Patch set 1 for branch 9.5 of project Packages/TYPO3.CMS has been pushed to the review server.
It is available at https://review.typo3.org/c/Packages/TYPO3.CMS/+/63743

Actions #8

Updated by Susanne Moog about 4 years ago

  • Status changed from Under Review to Resolved
  • % Done changed from 0 to 100
Actions #9

Updated by Benni Mack about 4 years ago

  • Status changed from Resolved to Closed
Actions #10

Updated by Martin Weymayer about 3 years ago

  • Priority changed from Should have to Must have

problem still exists in 10.4.15

Actions #11

Updated by Robert von Hackwitz over 2 years ago

Same here. Problem still exists in 10.4.21

Actions #12

Updated by Mario Rimann over 2 years ago

We're also seeing such errors getting logged by TYPO3 in a 10.4.x Installation. Right now I see this with the following error in the log for an INSERT statement, but we've seen it also for DELETE queries for some cache tables the last weeks.

Exception: An exception occurred while executing 'INSERT INTO `cache_rootline_tags` (`identifier`, `tag`) 
VALUES (?, ?), (?, ?)' with params [\"1059__0_0\", \"pageId_1059\", \"1059__0_0\", \"pageId_1050\"]:\n\n
Deadlock found when trying to get lock
Actions #13

Updated by Eric Harrer about 1 year ago

In TYPO3 11.5.25 I have the same error when importing product data by a Symfony Command with EXT:interest, which internally uses the DataHandler.

In AbstractMySQLDriver.php line 51:

  An exception occurred while executing 'INSERT INTO `cache_rootline_tags` (`identifier`, `tag`) VALUES (?, ?), (?, ?)' with params ["108__0_0_1", "pageId_108", "108__0_0_1", "pageId_1"]:  

  Deadlock found when trying to get lock; try restarting transaction                                                                                                                         

In StatementError.php line 29:

  Deadlock found when trying to get lock; try restarting transaction  

In MysqliStatement.php line 164:

  Deadlock found when trying to get lock; try restarting transaction  

Actions

Also available in: Atom PDF