MySQL query error [1213]: Deadlock found when trying to get lock; try restarting transaction

[Earl]

Server error log

     XF\Db\DeadlockException: MySQL query error [1213]: Deadlock found when trying to get lock; try restarting transaction src/XF/Db/AbstractStatement.php:217

Stack trace

INSERT  INTO `import_log_vbulletin_1` (`content_type`, `old_id`, `new_id`) VALUES (?, ?, ?) ON DUPLICATE KEY UPDATE new_id = VALUES(new_id)
------------

#0 src/XF/Db/Mysqli/Statement.php(196): XF\Db\AbstractStatement->getException('MySQL query err...', 1213, '40001')
#1 src/XF/Db/Mysqli/Statement.php(77): XF\Db\Mysqli\Statement->getException('MySQL query err...', 1213, '40001')
#2 src/XF/Db/AbstractAdapter.php(94): XF\Db\Mysqli\Statement->execute()
#3 src/XF/Db/AbstractAdapter.php(221): XF\Db\AbstractAdapter->query('INSERT  INTO `i...', Array)
#4 src/XF/Import/Log.php(117): XF\Db\AbstractAdapter->insert('import_log_vbul...', Array, false, 'new_id = VALUES...')
#5 src/XF/Import/DataManager.php(116): XF\Import\Log->log('reaction_conten...', '6003', '25')
#6 src/XF/Import/Data/AbstractData.php(132): XF\Import\DataManager->log('reaction_conten...', 6003, 25)
#7 src/addons/XFI/Import/Importer/vBulletin.php(4013): XF\Import\Data\AbstractData->save(6003)
#8 src/XF/Import/Runner.php(231): XFI\Import\Importer\vBulletin->stepReputation(Object(XF\Import\StepState), Array, 8)
#9 src/XF/Import/ParallelRunner.php(212): XF\Import\Runner->runStep('reputation', Object(XF\Import\StepState), 8)
#10 src/XF/Cli/Command/ImportChildProcess.php(78): XF\Import\ParallelRunner->runChildProcess('reputation', 6000, 9000, Object(Closure))
#11 src/vendor/symfony/console/Command/Command.php(255): XF\Cli\Command\ImportChildProcess->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#12 src/vendor/symfony/console/Application.php(953): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#13 src/vendor/symfony/console/Application.php(248): Symfony\Component\Console\Application->doRunCommand(Object(XF\Cli\Command\ImportChildProcess), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#14 src/vendor/symfony/console/Application.php(148): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#15 src/XF/Cli/Runner.php(63): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#16 cmd.php(15): XF\Cli\Runner->run()
#17 {main}

Request state

array(1) {
  ["cli"] => string(88) "/usr/local/lsws/elakiri/public_html/cmd.php xf:import-child-process reputation 6000 9000"
}

Server Error log

     RuntimeException: Child process exited with code 1. See control panel error error logs for details. src/XF/Import/ParallelProcessManager.php:170

Stack Trace

#0 src/XF/Import/ParallelRunner.php(55): XF\Import\ParallelProcessManager->execute(Object(XF\Import\Manager), Object(Closure))
#1 src/XF/Import/Runner.php(128): XF\Import\ParallelRunner->runUntilCompleteInternal(Object(XF\Import\Manager), Object(Closure))
#2 src/XF/Cli/Command/Import.php(144): XF\Import\Runner->runUntilComplete(Object(XF\Import\Manager), Object(Closure))
#3 src/vendor/symfony/console/Command/Command.php(255): XF\Cli\Command\Import->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#4 src/vendor/symfony/console/Application.php(953): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#5 src/vendor/symfony/console/Application.php(248): Symfony\Component\Console\Application->doRunCommand(Object(XF\Cli\Command\Import), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#6 src/vendor/symfony/console/Application.php(148): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#7 src/XF/Cli/Runner.php(63): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#8 cmd.php(15): XF\Cli\Runner->run()
#9 {main}

Request state

array(1) {
  ["cli"] => string(31) "cmd.php xf:import --processes=7"
}

I got the error when importing vbulletin attachments (3.8)

 

[Chris D]

Deadlocks happen, and possibly more likely when it comes to multiple processes. You should be able to continue but if the deadlocks happen frequently you may need to reduce the number of processes.

 

[trapped_soul]

I have 17 pages of these that happened overnight, any idea what I need to do please? Or why it's happening?

 

[skicomau]

Deadlocks happen, and possibly more likely when it comes to multiple processes. You should be able to continue but if the deadlocks happen frequently you may need to reduce the number of processes.

@Chris D

Chris, what does this mean exactly "multiple processes" can you clarify please.

I have recently updated to XF2.2.5 from 1.5.9 -- all is running fine however I am getting a couple of hundred of these 1213 deadlock errors per day.

They are all triggered by attachment URL requests on very popular threads, and they are all identical to the the following; (other than the user who triggered it and the attachment URL requested which varies - often it will be mulitiple errors at an identical moment in time by same user triggered by the request of multiple attachment URL's from the same post).

[HEADING=2]Stack trace[/HEADING] -- XFDB=noForceAllWrite INSERT INTO xf_session (session_id, session_data, expiry_date) VALUES (?, ?, ?) ON DUPLICATE KEY UPDATE session_data = VALUES(session_data), expiry_date = VALUES(expiry_date) ------------ #0 src/XF/Db/Mysqli/Statement.php(196): XF\Db\AbstractStatement->getException('MySQL query err...', 1213, '40001') #1 src/XF/Db/Mysqli/Statement.php(77): XF\Db\Mysqli\Statement->getException('MySQL query err...', 1213, '40001') #2 src/XF/Db/AbstractAdapter.php(94): XF\Db\Mysqli\Statement->execute() #3 src/XF/Session/DbStorage.php(57): XF\Db\AbstractAdapter->query(' -- XFDB=noF...', Array) #4 src/XF/Session/Session.php(215): XF\Session\DbStorage->writeSession('hAGjGw0t29dGCf1...', Array, 14400, true) #5 src/XF/Pub/App.php(460): XF\Session\Session->save() #6 src/XF/App.php(2340): XF\Pub\App->complete(Object(XF\Http\Response)) #7 src/XF.php(488): XF\App->run() #8 index.php(20): XF::runApp('XF\\Pub\\App') #9 {main} [HEADING=2]Request state[/HEADING] array(4) { ["url"] => string(43) "/xf/attachments/20210610_132143-jpg.197771/" ["referrer"] => string(74) "https://www.ski.com.au/xf/threads/7-14th-june-curtain-raiser.89766/page-13" ["_GET"] => array(1) { ["/xf/attachments/20210610_132143-jpg_197771/"] => string(0) "" } ["_POST"] => array(0) { } }

My database is an AWS Aurora Read/Write & Read/Only cluster - rarely more than 10% load


.

 

[Chris D]

My comments were related specifically to the import process which can be executed with multiple processes.

Your issues seem to be happening during normal operation which is certainly unexpected. Deadlocks do happen but if you’re having more than one - or even just one - per day routinely then it may indicate there is something wrong.

I don’t specifically recall reports of anything similar. I have no experience with AWS Aurora personally. I know that @Mike probably hasn’t either but he is generally more knowledgeable on database replication so will ping him and defer to his expertise there.

But just so we’re clear, do you have the multiple database instances configured in your XF config using the replication adapter system?

Master/slave support in DB adapter
XF2 introduces master/slave replication via a new DB adapter which allows separate read and write connections to be made. By default, select statements will be sent to the read server and all other statements will be sent to the write server.

You can see a typical example of configuration below:

$config['db']['adapterClass'] = 'XF\Db\Mysqli\ReplicationAdapter';
$config['db']['write'] = [
'host' => '192.168.10.1',
// ... username, password, dbname etc.
];
$config['db']['read'] = [
'host' => '192.168.10.2',
// ... username, password, dbname etc.
];

As well as inferring the correct connection to make from the type of query, you can also control the behavior by prefixing a query with a comment in the form of -- XFDB=modifier.

Where the modifier is one of:

• fromWrite - forces a specific read query to come from the write server even if it normally wouldn't
• forceAllWrite - forces this query and all subsequent queries to the write server
• noForceAllWrite - if this query would normally force all subsequent queries to the write server, this option disables that (useful for a write you know won't be read back immediately or if it is, can tolerate lag)

 

[skicomau]

My comments were related specifically to the import process which can be executed with multiple processes.

Your issues seem to be happening during normal operation which is certainly unexpected. Deadlocks do happen but if you’re having more than one - or even just one - per day routinely then it may indicate there is something wrong.

I don’t specifically recall reports of anything similar. I have no experience with AWS Aurora personally. I know that @Mike probably hasn’t either but he is generally more knowledgeable on database replication so will ping him and defer to his expertise there.

But just so we’re clear, do you have the multiple database instances configured in your XF config using the replication adapter system?

No I don't have that, will implement asap and advise.

Sometime back, I tried a config hack published somewhere on here for master/slave on 1.5 and it would not work.

(FYI - AWS Aurora instances spin up as Master / Slave pairs by default and do not like it if you attempt to destroy the reader and run on the single R/W, so having that official XF adapter means I can finally make the most of the resource I'm paying for )

 

[skicomau]

...and implemented.

Selects are now split evenly across the pair in the cluster



Will report back in after 24hr to report the status on the server errors. Suspect this will be the fix.

 

[Mike]

It's worth mentioning that by default, the session table is MyISAM, so thus transactions don't apply. So to a degree, converting it to InnoDB is non-standard waters, though there isn't anything inherently wrong with it. (There are reasons it's MyISAM, but on well configured servers, they're potentially less significant. Saying that, the schema may well be slightly different if we intended InnoDB.)

If you keep getting deadlocks, at the least we'd need to see the output of SHOW ENGINE InnoDB STATUS; for the deadlock details.

However saying all that, I'd probably just recommend enabling a cache layer (Memcached or Redis) and sticking sessions there. That would eliminate this issue and probably have somewhat better performance.

 

[skicomau]

yes, so...

errors have dropped by half - which means still running at around 100~150 per day.

If you keep getting deadlocks, at the least we'd need to see the output of SHOW ENGINE InnoDB STATUS; for the deadlock details.

You'll have to narrow this request down for the forced occasional and amateur database sys admin that I am. How do I run this query for deadlock details specifically? - I plug it in as a query to the table (using Navicat) and it returns a bunch of status details but all are of the moment the query is run and none of that meta appears to provide any insight.

 

[skicomau]

I think I found how to get what you are after

@Mike @Chris D

Excerpt from full Show innodb status response;

------------------------
LATEST DETECTED DEADLOCK
------------------------
2021-06-23 21:06:37 2b544dc7d700
*** (1) TRANSACTION:
TRANSACTION 6072490375, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 376, 1 row lock(s)
MySQL thread id 9297626, OS thread handle 0x2b54bdd03700, query id 242540471 172.26.9.75 skiXenforo update
-- XFDB=noForceAllWrite
            INSERT INTO xf_session
                (session_id, session_data, expiry_date)
            VALUES
                (?, ?, ?)
            ON DUPLICATE KEY UPDATE
                session_data = VALUES(session_data),
                expiry_date = VALUES(expiry_date)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 255897 page no 222 n bits 23 index `PRIMARY` of table `ski_xenforo`.`xf_session` trx id 6072490375 lock_mode X locks rec but not gap waiting
Record lock, heap no 23 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len=30; bufptr=0x2b542279a883; hex= 726b6938736a33694a6b484b6d4c614a66516b3361554a3175597a586a76; asc rki8sj3iJkHKmLaJfQk3aUJ1uYzXjv; (total 32 bytes);
 1: len=6; bufptr=0x2b542279a8a3; hex= 000169f2d89c; asc   i   ;;
 2: len=7; bufptr=0x2b542279a8a9; hex= 530002206c1d08; asc S   l  ;;
 3: len=30; bufptr=0x2b542279a8b0; hex= 613a393a7b733a333a225f6970223b733a343a2278938226223b733a363a; asc a:9:{s:3:"_ip";s:4:"x  &";s:6:; (total 515 bytes);
 4: len=4; bufptr=0x2b542279aab3; hex= 60d3da9d; asc `   ;;

*** (2) TRANSACTION:
TRANSACTION 6072490368, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 376, 2 row lock(s)
MySQL thread id 9297624, OS thread handle 0x2b53c7f49700, query id 242540465 172.26.9.75 skiXenforo update
-- XFDB=noForceAllWrite
            INSERT INTO xf_session
                (session_id, session_data, expiry_date)
            VALUES
                (?, ?, ?)
            ON DUPLICATE KEY UPDATE
                session_data = VALUES(session_data),
                expiry_date = VALUES(expiry_date)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 255897 page no 222 n bits 23 index `PRIMARY` of table `ski_xenforo`.`xf_session` trx id 6072490368 lock_mode X locks rec but not gap
Record lock, heap no 23 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len=30; bufptr=0x2b542279a883; hex= 726b6938736a33694a6b484b6d4c614a66516b3361554a3175597a586a76; asc rki8sj3iJkHKmLaJfQk3aUJ1uYzXjv; (total 32 bytes);
 1: len=6; bufptr=0x2b542279a8a3; hex= 000169f2d89c; asc   i   ;;
 2: len=7; bufptr=0x2b542279a8a9; hex= 530002206c1d08; asc S   l  ;;
 3: len=30; bufptr=0x2b542279a8b0; hex= 613a393a7b733a333a225f6970223b733a343a2278938226223b733a363a; asc a:9:{s:3:"_ip";s:4:"x  &";s:6:; (total 515 bytes);
 4: len=4; bufptr=0x2b542279aab3; hex= 60d3da9d; asc `   ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 255897 page no 222 n bits 23 index `PRIMARY` of table `ski_xenforo`.`xf_session` trx id 6072490368 lock_mode X locks rec but not gap waiting
Record lock, heap no 23 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len=30; bufptr=0x2b542279a883; hex= 726b6938736a33694a6b484b6d4c614a66516b3361554a3175597a586a76; asc rki8sj3iJkHKmLaJfQk3aUJ1uYzXjv; (total 32 bytes);
 1: len=6; bufptr=0x2b542279a8a3; hex= 000169f2d89c; asc   i   ;;
 2: len=7; bufptr=0x2b542279a8a9; hex= 530002206c1d08; asc S   l  ;;
 3: len=30; bufptr=0x2b542279a8b0; hex= 613a393a7b733a333a225f6970223b733a343a2278938226223b733a363a; asc a:9:{s:3:"_ip";s:4:"x  &";s:6:; (total 515 bytes);
 4: len=4; bufptr=0x2b542279aab3; hex= 60d3da9d; asc `   ;;

------------
TRANSACTIONS
------------

 

[Mike]

At this point, I'd probably have to recommend moving your sessions to a cache layer (https://xenforo.com/docs/xf2/cache/). As your session table isn't the designed/expected table type (presumably enforced by RDS), you're running into issues that aren't really expected by the code -- it may be that a different pattern to the session management queries (and potentially a slightly different DB structure) would be ideal in your scenario. However, moving them to a cache layer is likely to bring better performance anyway as there isn't really any need for disk backing/replication for explicitly temporary data like sessions.

 

[skicomau]

At this point, I'd probably have to recommend moving your sessions to a cache layer (https://xenforo.com/docs/xf2/cache/). As your session table isn't the designed/expected table type (presumably enforced by RDS), you're running into issues that aren't really expected by the code -- it may be that a different pattern to the session management queries (and potentially a slightly different DB structure) would be ideal in your scenario. However, moving them to a cache layer is likely to bring better performance anyway as there isn't really any need for disk backing/replication for explicitly temporary data like sessions.

Thanks

Memcached looks the way to go for me. I don't really need the sophistication of Redis and whilst the non-volatile memory is a nice to have, it's not like AWS servers get restarted everyday and the database remains the source of truth anyway.

Implementation of memcache is currently above my paygrade so I'll give it a go on my dev setup and see if I can make it happen without bringing on a server apocalypse.