Page MenuHomePhabricator

'undo' action on SD boards - Fatal exception of type "Wikimedia\Rdbms\DBQueryError"
Closed, ResolvedPublic

Description

Attempting undo action on betalabs ruwiki brings Database error page.

logstash betalabs displays the following :

January 30th 2018, 15:35:42.000	unique_id:WnEBTgpEE4AAABB@fKwAAAAF reqId:WnEBTgpEE4AAABB@fKwAAAAF server:ru.wikipedia.beta.wmflabs.org db_server:10.68.18.35:3306 wiki:ruwiki channel:DBQuery type:mediawiki error:You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'FORCE INDEX (rc_timestamp) WHERE rc_title = 'Teq8026dm5whantb' AND rc_timestamp' at line 1 (10.68.18.35:3306) http_method:GET @version:1

Details

Related Gerrit Patches:

Event Timeline

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJan 30 2018, 11:49 PM
Etonkovidova renamed this task from [betalabs] [[WnEBTgpEE4AAABB@fKwAAAAF] 2018-01-30 23:35:42: Fatal exception of type "Wikimedia\Rdbms\DBQueryError" to [betalabs] [WnEBTgpEE4AAABB@fKwAAAAF] 2018-01-30 23:35:42: Fatal exception of type "Wikimedia\Rdbms\DBQueryError".Jan 30 2018, 11:50 PM
Mattflaschen-WMF triaged this task as High priority.Jan 31 2018, 1:01 AM

I think this is the same thing as T182636: [betalabs] Fatal exception when clicking on deleted topics in View history (Flow\Model\AbstractRevision::getRecentChange)

The FORCE INDEX (rc_timestamp) part is failing in betalabs but working fine locally and in production. Can someone compare the recentchanges indexes between those environments? I don't have access to do it.

Catrope added a subscriber: Catrope.Feb 6 2018, 7:25 PM

The rc_timestamp index exists on both the master and the replica server in beta, in both the enwiki and ruwiki databases.

Etonkovidova added a comment.EditedFeb 6 2018, 9:26 PM

@SBisson, @Catrope - the same error for undo actions on testwiki (wmf.20) SD board.

[Wnob6ApAMFAAAHd@FuUAAACT] /w/index.php?title=User_talk:Etonkovidova&action=undo-edit-header&header_startId=u1k9p0j8ozaraaxr&header_endId=u3ct9o0gog1d4pri   Wikimedia\Rdbms\DBQueryError from line 1187 of /srv/mediawiki/php-1.31.0-wmf.20/includes/libs/rdbms/database/Database.php: A database query error has occurred. Did you forget to run your application's database schema updater after upgrading? 

Query: SELECT  rc_id,rc_timestamp,rc_user,rc_user_text,rc_namespace,rc_title,rc_minor,rc_bot,rc_new,rc_cur_id,rc_this_oldid,rc_last_oldid,rc_type,rc_source,rc_patrolled,rc_ip,rc_old_len,rc_new_len,rc_deleted,rc_logid,rc_log_type,rc_log_action,rc_params,COALESCE( comment_rc_comment.comment_text, rc_comment ) AS `rc_comment_text`,comment_rc_comment.comment_data AS `rc_comment_data`,comment_rc_comment.comment_id AS `rc_comment_cid`  FROM `recentchanges` LEFT JOIN `comment` `comment_rc_comment` ON ((comment_rc_comment.comment_id = rc_comment_id)) FORCE INDEX (rc_timestamp)  WHERE rc_title = 'Etonkovidova' AND rc_timestamp = '20180206211713' AND rc_namespace = '3'  
Function: Flow\Model\AbstractRevision::getRecentChange
Error: 1064 You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'FORCE INDEX (rc_timestamp)  WHERE rc_title = 'Etonkovidova' AND rc_timestamp = '' at line 1 (10.64.32.136)
Etonkovidova renamed this task from [betalabs] [WnEBTgpEE4AAABB@fKwAAAAF] 2018-01-30 23:35:42: Fatal exception of type "Wikimedia\Rdbms\DBQueryError" to 'undo' action on SD boards - Fatal exception of type "Wikimedia\Rdbms\DBQueryError".Feb 6 2018, 9:32 PM
Etonkovidova updated the task description. (Show Details)
Jdforrester-WMF added a subscriber: Jdforrester-WMF.

Speculating that this is likely caused by the MCR/RevisionStore rewrite?

Full error:

2018-02-08 00:47:02 [WnueBQpAICkAAA-ZvmgAAAAL] mw1320 testwiki 1.31.0-wmf.20 exception ERROR: [WnueBQpAICkAAA-ZvmgAAAAL] /w/index.php?title=Topic:U3m5gyhqh8i8doaw&action=undo-edit-post&topic_startId=u3m5gykc0ml4ov9k&topic_endId=u77cb6noedngq50o   Wikimedia\Rdbms\DBQueryError from line 1187 of /srv/mediawiki/php-1.31.0-wmf.20/includes/libs/rdbms/database/Database.php: A database query error has occurred. Did you forget to run your application's database schema updater after upgrading? 
Query: SELECT  rc_id,rc_timestamp,rc_user,rc_user_text,rc_namespace,rc_title,rc_minor,rc_bot,rc_new,rc_cur_id,rc_this_oldid,rc_last_oldid,rc_type,rc_source,rc_patrolled,rc_ip,rc_old_len,rc_new_len,rc_deleted,rc_logid,rc_log_type,rc_log_action,rc_params,COALESCE( comment_rc_comment.comment_text, rc_comment ) AS `rc_comment_text`,comment_rc_comment.comment_data AS `rc_comment_data`,comment_rc_comment.comment_id AS `rc_comment_cid`  FROM `recentchanges` LEFT JOIN `comment` `comment_rc_comment` ON ((comment_rc_comment.comment_id = rc_comment_id)) FORCE INDEX (rc_timestamp)  WHERE rc_title = 'U3m5gyhqh8i8doaw' AND rc_timestamp = '20180208004114' AND rc_namespace = '2600'  
Function: Flow\Model\AbstractRevision::getRecentChange
Error: 1064 You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'FORCE INDEX (rc_timestamp)  WHERE rc_title = 'U3m5gyhqh8i8doaw' AND rc_timestamp' at line 1 (10.64.16.191)
 {"exception_id":"WnueBQpAICkAAA-ZvmgAAAAL","exception_url":"/w/index.php?title=Topic:U3m5gyhqh8i8doaw&action=undo-edit-post&topic_startId=u3m5gykc0ml4ov9k&topic_endId=u77cb6noedngq50o","caught_by":"mwe_handler"} 
[Exception Wikimedia\Rdbms\DBQueryError] (/srv/mediawiki/php-1.31.0-wmf.20/includes/libs/rdbms/database/Database.php:1187) A database query error has occurred. Did you forget to run your application's database schema updater after upgrading? 
Query: SELECT  rc_id,rc_timestamp,rc_user,rc_user_text,rc_namespace,rc_title,rc_minor,rc_bot,rc_new,rc_cur_id,rc_this_oldid,rc_last_oldid,rc_type,rc_source,rc_patrolled,rc_ip,rc_old_len,rc_new_len,rc_deleted,rc_logid,rc_log_type,rc_log_action,rc_params,COALESCE( comment_rc_comment.comment_text, rc_comment ) AS `rc_comment_text`,comment_rc_comment.comment_data AS `rc_comment_data`,comment_rc_comment.comment_id AS `rc_comment_cid`  FROM `recentchanges` LEFT JOIN `comment` `comment_rc_comment` ON ((comment_rc_comment.comment_id = rc_comment_id)) FORCE INDEX (rc_timestamp)  WHERE rc_title = 'U3m5gyhqh8i8doaw' AND rc_timestamp = '20180208004114' AND rc_namespace = '2600'  
Function: Flow\Model\AbstractRevision::getRecentChange
Error: 1064 You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'FORCE INDEX (rc_timestamp)  WHERE rc_title = 'U3m5gyhqh8i8doaw' AND rc_timestamp' at line 1 (10.64.16.191)

  #0 /srv/mediawiki/php-1.31.0-wmf.20/includes/libs/rdbms/database/Database.php(998): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
  #1 /srv/mediawiki/php-1.31.0-wmf.20/includes/libs/rdbms/database/Database.php(1382): Wikimedia\Rdbms\Database->query(string, string)
  #2 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/Model/AbstractRevision.php(861): Wikimedia\Rdbms\Database->select(array, array, array, string, array, array)
  #3 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/Formatter/RevisionViewFormatter.php(133): Flow\Model\AbstractRevision->getRecentChange()
  #4 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/Formatter/RevisionViewFormatter.php(44): Flow\Formatter\RevisionViewFormatter->buildLinks(Flow\Formatter\FormatterRow, Flow\View)
  #5 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/Formatter/RevisionUndoViewFormatter.php(49): Flow\Formatter\RevisionViewFormatter->formatApi(Flow\Formatter\FormatterRow, Flow\View)
  #6 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/Block/Topic.php(714): Flow\Formatter\RevisionUndoViewFormatter->formatApi(Flow\Formatter\FormatterRow, Flow\Formatter\FormatterRow, Flow\Formatter\FormatterRow, Flow\View)
  #7 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/Block/Topic.php(527): Flow\Block\TopicBlock->renderUndoApi(array)
  #8 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/View.php(217): Flow\Block\TopicBlock->renderApi(array)
  #9 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/View.php(69): Flow\View->buildApiResponse(Flow\WorkflowLoader, array, string, array)
  #10 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/Actions/Action.php(112): Flow\View->show(Flow\WorkflowLoader, string)
  #11 /srv/mediawiki/php-1.31.0-wmf.20/extensions/Flow/includes/Actions/Action.php(50): Flow\Actions\FlowAction->showForAction(string)
  #12 /srv/mediawiki/php-1.31.0-wmf.20/includes/MediaWiki.php(500): Flow\Actions\FlowAction->show()
  #13 /srv/mediawiki/php-1.31.0-wmf.20/includes/MediaWiki.php(294): MediaWiki->performAction(Article, Title)
  #14 /srv/mediawiki/php-1.31.0-wmf.20/includes/MediaWiki.php(858): MediaWiki->performRequest()
  #15 /srv/mediawiki/php-1.31.0-wmf.20/includes/MediaWiki.php(524): MediaWiki->main()
  #16 /srv/mediawiki/php-1.31.0-wmf.20/index.php(42): MediaWiki->run()
  #17 /srv/mediawiki/w/index.php(3): include(string)
  #18 {main}

Note that this isn't a missing index or anything, there truly is a syntax error in the SQL: SELECT stuff FROM recentchanges LEFT JOIN comment comment_rc_comment ON (stuff) FORCE INDEX (rc_timestamp) is incorrect, it should be SELECT stuff FROM recentchanges FORCE INDEX (rc_timestamp) LEFT JOIN ....

The code that causes this query uses RecentChange::getQueryInfo() to build the query. The output of that on testwiki is:

> var_dump(RecentChange::getQueryInfo())
array(3) {
  ["tables"]=>
  array(2) {
    [0]=>
    string(13) "recentchanges"
    ["comment_rc_comment"]=>
    string(7) "comment"
  }
  ["fields"]=>
  array(26) {
    ....
  }
  ["joins"]=>
  array(1) {
    ["comment_rc_comment"]=>
    array(2) {
      [0]=>
      string(9) "LEFT JOIN"
      [1]=>
      string(45) "comment_rc_comment.comment_id = rc_comment_id"
    }
  }
}

The join wasn't there until recently. The options that we pass into the query are ['USE INDEX' => 'rc_timestamp'] which is wrong now that there are multiple tables. It has to be a per-table nested array now. Patch incoming.

Change 408958 had a related patch set uploaded (by Catrope; owner: Catrope):
[mediawiki/extensions/Flow@master] AbstractRevision: Specify table in USE INDEX to fix DB error

https://gerrit.wikimedia.org/r/408958

Change 408958 merged by jenkins-bot:
[mediawiki/extensions/Flow@master] AbstractRevision: Specify table in USE INDEX to fix DB error

https://gerrit.wikimedia.org/r/408958

Fixed in master - see https://en.wikipedia.beta.wmflabs.org/w/index.php?title=Topic:U77o0uiommsw9clr&action=history for a successfully undone edit. Can’t tell from here whether it’s the same as that DB fatal spike, but it seems unlikely (undos on StructuredDiscussions are not that frequent).

Change 408966 had a related patch set uploaded (by Jforrester; owner: Catrope):
[mediawiki/extensions/Flow@wmf/1.31.0-wmf.20] AbstractRevision: Specify table in USE INDEX to fix DB error

https://gerrit.wikimedia.org/r/408966

Change 408966 merged by jenkins-bot:
[mediawiki/extensions/Flow@wmf/1.31.0-wmf.20] AbstractRevision: Specify table in USE INDEX to fix DB error

https://gerrit.wikimedia.org/r/408966

Mentioned in SAL (#wikimedia-operations) [2018-02-08T19:24:12Z] <catrope@tin> Synchronized php-1.31.0-wmf.20/extensions/Flow/includes/Model/AbstractRevision.php: T186077 (duration: 01m 11s)