XF 1.2 Consistent Deadlock!

[NeoCHI]

My forum is consistently getting deadlock server errors, multiple times a day usually multiple times a minute.

Here's what the error info shows:

Zend_Db_Statement_Mysqli_Exception: Mysqli statement execute error : Deadlock found when trying to get lock; try restarting transaction - library/Zend/Db/Statement/Mysqli.

Here's a couple examples:

Example 1:

Stack Trace:

#0 /home/xx/public_html/library/Zend/Db/Statement.php(297): Zend_Db_Statement_Mysqli->_execute(Array)
#1 /home/xx/public_html/library/Zend/Db/Adapter/Abstract.php(479): Zend_Db_Statement->execute(Array)
#2 /home/xx/public_html/library/XenForo/Model/Deferred.php(103): Zend_Db_Adapter_Abstract->query('?????INSERT INT...', Array)
#3 /home/xx/public_html/library/XenForo/Application.php(1246): XenForo_Model_Deferred->defer('MailQueue', Array, 'MailQueue', false, NULL)
#4 /home/xx/public_html/library/XenForo/Model/MailQueue.php(7): XenForo_Application::defer('MailQueue', Array, 'MailQueue')
#5 /home/xx/public_html/library/XenForo/Mail.php(219): XenForo_Model_MailQueue->insertMailQueue(Object(Zend_Mail))
#6 /home/xx/public_html/library/XenForo/Model/ThreadWatch.php(249): XenForo_Mail->queue('clint.monchamp@...', 'It's me')
#7 /home/xx/public_html/library/BBM/Protection/Model/ThreadWatch.php(16): XenForo_Model_ThreadWatch->sendNotificationToWatchUsersOnReply(Array, NULL, Array)
#8 /home/xx/public_html/library/XenForo/DataWriter/DiscussionMessage/Post.php(144): BBM_Protection_Model_ThreadWatch->sendNotificationToWatchUsersOnReply(Array, NULL, Array)
#9 /home/xx/public_html/library/Tinhte/XenTag/XenForo/DataWriter/DiscussionMessage/Post.php(113): XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
#10 /home/xx/public_html/library/WidgetFramework/XenForo/DataWriter/DiscussionMessage/Post.php(7): Tinhte_XenTag_XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
#11 /home/xx/public_html/library/bdTagMe/XenForo/DataWriter/DiscussionMessage/Post.php(8): WidgetFramework_XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
#12 /home/xx/public_html/library/XenForo/DataWriter.php(1411): bdTagMe_XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
#13 /home/xx/public_html/library/Dark/TaigaChat/DataWriter/DiscussionMessage/Post.php(7): XenForo_DataWriter->save()
#14 /home/xx/public_html/library/XenForo/ControllerPublic/Thread.php(548): Dark_TaigaChat_DataWriter_DiscussionMessage_Post->save()
#15 /home/xx/public_html/library/Tac/StopHumanSpam/ControllerPublic/Thread.php(170): XenForo_ControllerPublic_Thread->actionAddReply()
#16 /home/xx/public_html/library/Tac/StopHumanSpam/ControllerPublic/Thread.php(85): Tac_StopHumanSpam_ControllerPublic_Thread->addReplyResponse(false)
#17 /home/xx/public_html/library/XenForo/FrontController.php(337): Tac_StopHumanSpam_ControllerPublic_Thread->actionAddReply()
#18 /home/xx/public_html/library/XenForo/FrontController.php(134): XenForo_FrontController->dispatch(Object(XenForo_RouteMatch))
#19 /home/xx/public_html/index.php(13): XenForo_FrontController->run()
#20 {main}

Request State

array(3) {
["url"] => string(116) "http://xx.com/threads/aurra-boba-han-lando-chewy-appo-dooku-obi-pad-nute-dsl-tarkin-jar-jar.95152/add-reply"
["_GET"] => array(0) {
}
["_POST"] => array(9) {
["message_html"] => string(60) "<p>How bad is the improper, if you don't mind me asking?</p>"
["_xfRelativeResolver"] => string(114) "http://xx.com/threads/aurra-boba-han-lando-chewy-appo-dooku-obi-pad-nute-dsl-tarkin-jar-jar.95152/page-29"
["attachment_hash"] => string(32) "4971b002d0327338d9be22b1c1957191"
["last_date"] => string(10) "1404454879"
["last_known_date"] => string(10) "1404454879"
["_xfToken"] => string(8) "********"
["_xfRequestUri"] => string(92) "/threads/aurra-boba-han-lando-chewy-appo-dooku-obi-pad-nute-dsl-tarkin-jar-jar.95152/page-29"
["_xfNoRedirect"] => string(1) "1"
["_xfResponseType"] => string(4) "json"
}
}

Example 2:

Stack Trace:

#0 /home/xx/public_html/library/Zend/Db/Statement.php(297): Zend_Db_Statement_Mysqli->_execute(Array)
#1 /home/xx/public_html/library/Zend/Db/Adapter/Abstract.php(479): Zend_Db_Statement->execute(Array)
#2 /home/xx/public_html/library/Zend/Db/Adapter/Abstract.php(661): Zend_Db_Adapter_Abstract->query('DELETE FROM `xf...')
#3 /home/xx/public_html/library/XenForo/Model/Deferred.php(147): Zend_Db_Adapter_Abstract->delete('xf_deferred', 'deferred_id = 6...')
#4 /home/xx/public_html/library/XenForo/Model/Deferred.php(181): XenForo_Model_Deferred->deleteDeferredById(61393)
#5 /home/xx/public_html/library/XenForo/Model/Deferred.php(320): XenForo_Model_Deferred->runDeferred(Array, 9.99999785423, '', false)
#6 /home/xx/public_html/library/XenForo/Model/Deferred.php(273): XenForo_Model_Deferred->_runInternal(Array, NULL, '', false)
#7 /home/xx/public_html/deferred.php(15): XenForo_Model_Deferred->run(false)
#8 {main}

Request State:

array(3) {
["url"] => string(35) "http://xx.com/deferred.php"
["_GET"] => array(0) {
}
["_POST"] => array(4) {
["_xfRequestUri"] => string(15) "/account/alerts"
["_xfNoRedirect"] => string(1) "1"
["_xfToken"] => string(8) "********"
["_xfResponseType"] => string(4) "json"
}
}

Please need help!

 

[Mike]

Well, I would probably have to recommend upgrading to the latest version if possible. I recall making some tweaks regarding how transactions were used in the deferred system to try to resolve/reduce potential for deadlocks.

 

[NeoCHI]

Well, I would probably have to recommend upgrading to the latest version if possible. I recall making some tweaks regarding how transactions were used in the deferred system to try to resolve/reduce potential for deadlocks.

What exactly does deferred mean?

Also, what about example 1? It wasn't caused by "deferred". How will I solve those?

 

[Jon W]

What exactly does deferred mean?

1.2 adds a new "deferred" system for running any code that can be broken up into pieces and may take a long time (multiple seconds or more) to run. Deferred tasks can be triggered automatically by the code as necessary and they will either be run automatically in the background (by page views) or by displaying the current running state to the administrator (in the case of some cache rebuilds). This effectively unifies the cache rebuild systems with cron and other potentially long running processes (such as the bulk user change system discussed in the past).

Also, what about example 1? It wasn't caused by "deferred". How will I solve those?

Example 1 is also an instance of a deferred deadlock error.

 

[NeoCHI]

I've just updated to 1.3.3 but I'm still getting multiple deadlocks a day. Here's two examples (very similar to before):

Example 1:
Stack trace

#0 /home/xx/public_html/library/Zend/Db/Statement.php(297): Zend_Db_Statement_Mysqli->_execute(Array)
#1 /home/xx/public_html/library/Zend/Db/Adapter/Abstract.php(479): Zend_Db_Statement->execute(Array)
#2 /home/xx/public_html/library/XenForo/Model/Deferred.php(111): Zend_Db_Adapter_Abstract->query('\r\n\t\t\tINSERT INT...', Array)
#3 /home/xx/public_html/library/XenForo/Application.php(1367): XenForo_Model_Deferred->defer('MailQueue', Array, 'MailQueue', false, NULL)
#4 /home/xx/public_html/library/XenForo/Model/MailQueue.php(7): XenForo_Application::defer('MailQueue', Array, 'MailQueue')
#5 /home/xx/public_html/library/XenForo/Mail.php(225): XenForo_Model_MailQueue->insertMailQueue(Object(Zend_Mail))
#6 /home/xx/public_html/library/XenForo/Model/ThreadWatch.php(249): XenForo_Mail->queue('tennvols95@gmai...', 'Howling Command...')
#7 /home/xx/public_html/library/BBM/Protection/Model/ThreadWatch.php(16): XenForo_Model_ThreadWatch->sendNotificationToWatchUsersOnReply(Array, NULL, Array)
#8 /home/xx/public_html/library/XenForo/DataWriter/DiscussionMessage/Post.php(164): BBM_Protection_Model_ThreadWatch->sendNotificationToWatchUsersOnReply(Array, NULL, Array)
#9 /home/xx/public_html/library/Tinhte/XenTag/XenForo/DataWriter/DiscussionMessage/Post.php(113): XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
#10 /home/xx/public_html/library/WidgetFramework/XenForo/DataWriter/DiscussionMessage/Post.php(7): Tinhte_XenTag_XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
#11 /home/xx/public_html/library/bdTagMe/XenForo/DataWriter/DiscussionMessage/Post.php(13): WidgetFramework_XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
#12 /home/xx/public_html/library/XenForo/DataWriter.php(1423): bdTagMe_XenForo_DataWriter_DiscussionMessage_Post->_postSaveAfterTransaction()
#13 /home/xx/public_html/library/Dark/TaigaChat/DataWriter/DiscussionMessage/Post.php(7): XenForo_DataWriter->save()
#14 /home/xx/public_html/library/XenForo/ControllerPublic/Thread.php(549): Dark_TaigaChat_DataWriter_DiscussionMessage_Post->save()
#15 /home/xx/public_html/library/Tac/StopHumanSpam/ControllerPublic/Thread.php(170): XenForo_ControllerPublic_Thread->actionAddReply()
#16 /home/xx/public_html/library/Tac/StopHumanSpam/ControllerPublic/Thread.php(85): Tac_StopHumanSpam_ControllerPublic_Thread->addReplyResponse(false)
#17 /home/xx/public_html/library/XenForo/FrontController.php(347): Tac_StopHumanSpam_ControllerPublic_Thread->actionAddReply()
#18 /home/xx/public_html/library/XenForo/FrontController.php(134): XenForo_FrontController->dispatch(Object(XenForo_RouteMatch))
#19 /home/xx/public_html/index.php(13): XenForo_FrontController->run()
#20 {main}

Request state

array(3) {
["url"] => string(69) "http://www.xx.com/threads/qgj-for-downtrade.129527/add-reply"
["_GET"] => array(0) {
}
["_POST"] => array(9) {
["message_html"] => string(27) "<p>sure!!!! 781-327-447</p>"
["_xfRelativeResolver"] => string(60) "http://www.xx.com/threads/qgj-for-downtrade.129527/"
["attachment_hash"] => string(32) "038ad464dfd020a1e045e18910b84870"
["last_date"] => string(10) "1404958562"
["last_known_date"] => string(10) "1404958562"
["_xfToken"] => string(8) "********"
["_xfRequestUri"] => string(34) "/threads/qgj-for-downtrade.129527/"
["_xfNoRedirect"] => string(1) "1"
["_xfResponseType"] => string(4) "json"
}
}

Example 2:
Stack trace

#0 /home/xx/public_html/library/Zend/Db/Statement.php(297): Zend_Db_Statement_Mysqli->_execute(Array)
#1 /home/xx/public_html/library/Zend/Db/Adapter/Abstract.php(479): Zend_Db_Statement->execute(Array)
#2 /home/xx/public_html/library/Zend/Db/Adapter/Abstract.php(661): Zend_Db_Adapter_Abstract->query('DELETE FROM `xf...')
#3 /home/xx/public_html/library/XenForo/Model/Deferred.php(168): Zend_Db_Adapter_Abstract->delete('xf_deferred', 'deferred_id = 3...')
#4 /home/xx/public_html/library/XenForo/Model/Deferred.php(232): XenForo_Model_Deferred->deleteDeferredById(38813)
#5 /home/xx/public_html/library/XenForo/Model/Deferred.php(390): XenForo_Model_Deferred->runDeferred(Array, 7.99999594688, '', false)
#6 /home/xx/public_html/library/XenForo/Model/Deferred.php(335): XenForo_Model_Deferred->_runInternal(Array, NULL, '', false)
#7 /home/xx/public_html/deferred.php(23): XenForo_Model_Deferred->run(false)
#8 {main}

Request state

array(3) {
["url"] => string(35) "http://xx.com/deferred.php"
["_GET"] => array(0) {
}
["_POST"] => array(4) {
["_xfRequestUri"] => string(77) "/threads/looking-for-boba-trh-vader-cc-aurra-lots-of-5-to-trade.95152/page-36"
["_xfNoRedirect"] => string(1) "1"
["_xfToken"] => string(8) "********"
["_xfResponseType"] => string(4) "json"
}
}

 

[Mike]

You might be able to run this now, but it might not have the correct deadlock info, so next time you see a deadlock, please run this query:

SHOW ENGINE INNODB STATUS;

(You may need to run this as the root MySQL user. I'm assuming you have root if you have a forum busy enough to trigger deadlocks like this consistently. If you're on a shared server, these issues may be down to the server being heavily overloaded.)

 

[NeoCHI]

Do i just run that in phpmyadmin? and how long after the deadlock can I run it to see the results. Usually I only see the deadlocks in the server logs and it's atleast 10-20 minutes after.

 

[Mike]

You can run it in phpMyAdmin, but you do need to make sure it's run with a user with the "PROCESS" privilege in MySQL. (You can try running it; it should just error if you don't have the necessary privilege.)

10-20 minutes should be fine. It should keep a log of the last deadlock.

 

[kontrabass]

Mind if I piggyback on this thread? I got 526 "deadlock" errors in 4 minutes last night, all related to "deferred.php". Here's the results of show innodb status:

mysql> SHOW ENGINE INNODB STATUS;
..........
------------------------

LATEST DETECTED DEADLOCK

------------------------

140723 18:39:12TOO DEEP OR LONG SEARCH IN THE LOCK TABLE WAITS-FOR GRAPH, WE WILL ROLL BACK FOLLOWING TRANSACTION

I have however not upgraded to the latest XF version [/code]

 

[Mike]

That's likely unrelated to a true deadlock. See the note at the end: here: http://dev.mysql.com/doc/refman/5.0/en/innodb-lock-modes.html That would likely indicate that you had a large number of transactions pending, all waiting for the same thing. As these transactions are usually held for fractions of a second, I would guess that you had a massive load spike which caused the to effectively hang. That fits with getting multiple errors per second.