Cannot reproduce Moving posts out of large threads: if slow and clicked multiple times, entire thread hard deleted.

Isil`Zha

Isil`Zha

Active member
This is a pretty serious bug. If a user with the ability to move posts moves one out of a large thread, it is likely going to be a little slow. There is no feedback that it is working on it to the end-user, and they may try to hit move again. The post will end up moved, but all posts in the entire thread are hard deleted and have to be recovered from a backup.

We have a thread that currently has 26,000 posts. One post was moved to another thread in another forum. However, the person doing the move hit the move button multiple times, due to the move being slow, and no feedback that it was being performed. It also didn't prevent them from repeatedly attempting to move the post. Eventually the single post moved, but all 26,000 posts and the thread were hard deleted, and we had to restore the thread from the previous night's backup.

First server error where the issue occurred.

Code: 
#0 /var/www/sites/forums.spacebattles.com/html/library/Zend/Db/Statement.php(319): SV_SlowQueryLogger_Profiler->queryEnd(73)
#1 /var/www/sites/forums.spacebattles.com/html/library/Zend/Db/Adapter/Abstract.php(479): Zend_Db_Statement->execute(Array)
#2 /var/www/sites/forums.spacebattles.com/html/library/SV/MysqlReplication/Masterslave.php(190): Zend_Db_Adapter_Abstract->query('DELETE FROM `xf...', Array)
#3 /var/www/sites/forums.spacebattles.com/html/library/SV/MysqlReplication/Masterslave.php(230): SV_MysqlReplication_Masterslave->_masterQuery('DELETE FROM `xf...', Array)
#4 /var/www/sites/forums.spacebattles.com/html/library/Zend/Db/Adapter/Abstract.php(661): SV_MysqlReplication_Masterslave->query('DELETE FROM `xf...')
#5 /var/www/sites/forums.spacebattles.com/html/library/XenForo/Model/Like.php(380): Zend_Db_Adapter_Abstract->delete('xf_liked_conten...', '(content_type =...')
#6 /var/www/sites/forums.spacebattles.com/html/library/XenForo/DataWriter/Discussion.php(1031): XenForo_Model_Like->deleteContentLikes('post', Array, true)
#7 /var/www/sites/forums.spacebattles.com/html/library/XenForo/DataWriter/Discussion.php(774): XenForo_DataWriter_Discussion->_deleteDiscussionMessages()
#8 /var/www/sites/forums.spacebattles.com/html/library/XenForo/DataWriter.php(1793): XenForo_DataWriter_Discussion->_postDelete()
#9 /var/www/sites/forums.spacebattles.com/html/library/XenForo/Model/Post.php(1633): XenForo_DataWriter->delete()
#10 /var/www/sites/forums.spacebattles.com/html/library/XenForo/Model/Post.php(1389): XenForo_Model_Post->_moveOrCopyPosts('move', Array, Array, Array, Array)
#11 /var/www/sites/forums.spacebattles.com/html/library/XenForo/Model/InlineMod/Post.php(471): XenForo_Model_Post->movePosts(Array, Array, Array, Array)
#12 /var/www/sites/forums.spacebattles.com/html/library/XenForo/Model/InlineMod/Post.php(361): XenForo_Model_InlineMod_Post->_moveOrCopyPosts('move', Array, Array, Array, Array, NULL)
#13 /var/www/sites/forums.spacebattles.com/html/library/XenForo/ControllerPublic/InlineMod/Post.php(232): XenForo_Model_InlineMod_Post->movePosts(Array, Array, NULL)
#14 /var/www/sites/forums.spacebattles.com/html/library/SV/MultiPrefix/XenForo/ControllerPublic/InlineMod/Post.php(13): XenForo_ControllerPublic_InlineMod_Post->_moveOrCopyPostsAction('canMovePosts', 'movePosts', 'XenForo_ViewPub...', 'inline_mod_post...')
#15 /var/www/sites/forums.spacebattles.com/html/library/XenForo/ControllerPublic/InlineMod/Post.php(141): SV_MultiPrefix_XenForo_ControllerPublic_InlineMod_Post->_moveOrCopyPostsAction('canMovePosts', 'movePosts', 'XenForo_ViewPub...', 'inline_mod_post...')
#16 /var/www/sites/forums.spacebattles.com/html/library/XenForo/FrontController.php(351): XenForo_ControllerPublic_InlineMod_Post->actionMove()
#17 /var/www/sites/forums.spacebattles.com/html/library/XenForo/FrontController.php(134): XenForo_FrontController->dispatch(Object(XenForo_RouteMatch))
#18 /var/www/sites/forums.spacebattles.com/html/index.php(13): XenForo_FrontController->run()
#19 {main}

Request State

array(4) {
  ["host"] => string(22) "web02.spacebattles.com"
  ["url"] => string(52) "https://forums.spacebattles.com/inline-mod/post/move"
  ["_GET"] => array(0) {
  }
  ["_POST"] => array(11) {
    ["thread_type"] => string(3) "new"
    ["node_id"] => string(2) "98"
    ["prefix_id"] => array(1) {
      [0] => string(2) "15"
    }
    ["title"] => string(21) "Sir Godot's RWBY snip"
    ["send_author_alert"] => string(1) "1"
    ["author_alert_reason"] => string(59) "We need to have a talk about what is and is not safe for SB"
    ["save"] => string(10) "Move Posts"
    ["posts"] => array(1) {
      [0] => string(8) "34149358"
    }
    ["_xfConfirm"] => string(1) "1"
    ["redirect"] => string(130) "https://forums.spacebattles.com/threads/rwby-idea-and-discussion-thread-2-we-crashed-the-hype-train.420749/page-1046#post-34149358"
    ["_xfToken"] => string(8) "********"
  }
}
 
Not sure if this situation was considered given that this single thread is larger than many/most entire boards out there but hopefully a solution/fix can be come up with because it won't be the only time this happens for us. With ~50 staff and approaching 30 million posts it is bound to happen again.
 
XenForo_Model_Post::_moveOrCopyPosts only deletes the source thread if XenForo_DataWriter_Discussion_Thread::rebuildDiscussion (which calls recalculatePostPositionsInThread) returns something falsey.

While we do have some custom code in the recalculatePostPositionsInThread call chain, it is this;
Code: 
  public function recalculatePostPositionsInThread($threadId)
  {
    $ret = parent::recalculatePostPositionsInThread($threadId);
    $this->_getThreadmarksModel()->rebuildThreadMarkCache($threadId);
    return $ret;
  }

The MultiPrefix code just allows the target thread to have multiple prefixes by tweaking the preSave in the target thread.

SV/MysqlReplication routes provable non-transactions read-only queries to slaves.
SV_SlowQueryLogger_Profiler just records if the query takes longer than ~10 seconds, and doesn't interfere with the code flow.
(And patched the error class to report the hostname of the box which generated the error).

Moving posts in smaller threads works fine.

I'm fairly baffled at how this happened.
 
Last edited:
I couldn't reproduce this and indeed, I don't see why it would happen. It should only happen if this query doesn't return any results:
Code: 
$postResults = $this->_getDb()->query('
   SELECT post_id, user_id, username, post_date, message_state, position
   FROM xf_post
   WHERE thread_id = ?
   ORDER BY post_date, post_id
', $threadId);
I can't see why that would ever return nothing if posts exist in the thread.

It wouldn't be unreasonable to change this to a SELECT FOR UPDATE, but I'm not seeing why this would return nothing for a thread where most of these rows aren't being touched.
 
Would it be possible to do any testing of this in a staging environment (or something that is restorable) to see if we can get some amount of reproduction?
 
Mike said:
I couldn't reproduce this and indeed, I don't see why it would happen. It should only happen if this query doesn't return any results:
Click to expand...
I've had issues before where max_statement_time/max_execution_time could cause weird failures, but that SQL feature isn't being used.

Mike said:
Would it be possible to do any testing of this in a staging environment (or something that is restorable) to see if we can get some amount of reproduction?
Click to expand...
I restored the thread* into SB's testing environment but I'm able to safely move posts out of that 26000 post thread. I'm planning to rebuild the testing environment off live in the next day or so, and then will re-import the thread.

*Script used to generate an SQL dump from an old backup is attached. This generates a ~100mb SQL file for that thread
 

Attachments

Last edited:
Xon said:
SV_SlowQueryLogger_Profiler just records if the query takes longer than ~10 seconds, and doesn't interfere with the code flow.
(And patched the error class to report the hostname of the box which generated the error).
Click to expand...
Stupid slow query logger.

It was trampling the results as XF uses an ambient database connection when logging errors AND the profileer's queryEnd is called before results are fetched :(
 
Top Bottom