Page MenuHomePhabricator

updateSearchIndex.php sql error not all tables locked
Open, Needs TriagePublic

Description

Originally from https://www.mediawiki.org/wiki/Topic:Vbps68wp2h51ifg6

It appears that updateSearchIndex.php wasn't updated for the new revision schema refactoring and is now throwing an sql error

Wikimedia\Rdbms\DBQueryError from line 1603 of /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 rev_id,rev_page,rev_timestamp,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,comment_rev_comment.comment_text AS `rev_comment_text`,comment_rev_comment.comment_data AS `rev_comment_data`,comment_rev_comment.comment_id AS `rev_comment_cid`,actor_rev_user.actor_user AS `rev_user`,actor_rev_user.actor_name AS `rev_user_text`,temp_rev_user.revactor_actor AS `rev_actor`,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len,user_name FROM `revision` JOIN `revision_comment_temp` `temp_rev_comment` ON ((temp_rev_comment.revcomment_rev = rev_id)) JOIN `comment` `comment_rev_comment` ON ((comment_rev_comment.comment_id = temp_rev_comment.revcomment_comment_id)) JOIN `revision_actor_temp` `temp_rev_user` ON ((temp_rev_user.revactor_rev = rev_id)) JOIN `actor` `actor_rev_user` ON ((actor_rev_user.actor_id = temp_rev_user.revactor_actor)) JOIN `page` ON ((page_id = rev_page)) LEFT JOIN `user` ON ((actor_rev_user.actor_user != 0) AND (user_id = actor_rev_user.actor_user)) WHERE rev_page = '457' AND page_id = '457' AND (rev_id=page_latest) LIMIT 1 Function: MediaWiki\Revision\RevisionStore::fetchRevisionRowFromConds Error: 1100 Table 'temp_rev_comment' was not locked with LOCK TABLES (localhost)

Event Timeline

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptMay 15 2020, 7:38 AM
Aklapper changed the task status from Open to Stalled.May 15 2020, 9:43 AM
Aklapper raised the priority of this task from High to Needs Triage.

Hi @Farvardyn, thanks for taking the time to report this! Resetting priority and removing task subscribers.
Please see and follow https://www.mediawiki.org/wiki/How_to_report_a_bug and provide:

  • a clear list of exact steps to reproduce the situation, step by step, so that nobody needs to guess or interpret how you performed each step,
  • what happens after performing these steps to reproduce,
  • what you expected to happen instead,

In some situations it can also be helpful to know if you see the same behavior when you are not logged in, your web browser(s) and web browser version(s), your exact MediaWiki version (if it is not on a Wikimedia wiki) and PHP version, etc.

You can edit the task description by clicking Edit Task. Ideally, a good description should allow any other person to follow these steps (without having to interpret steps) and see the same results. Problems that others can reproduce can get fixed faster. We appreciate people who report issues, so thanks again!

Also, why exactly was this reported in Phabricator, in addition to https://www.mediawiki.org/wiki/Topic:Vbps68wp2h51ifg6 ?

I did run:
$ php searchUpdateindex.php (under maintenance folder)
and I got this in screen:

Updating searchindex between 20200514131503 and 20200515131503
   --- Waiting for lock ---
Wikimedia\Rdbms\DBQueryError from line 1603 of /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  rev_id,rev_page,rev_timestamp,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,comment_rev_comment.comment_text AS `rev_comment_text`,comment_rev_comment.comment_data AS `rev_comment_data`,comment_rev_comment.comment_id AS `rev_comment_cid`,actor_rev_user.actor_user AS `rev_user`,actor_rev_user.actor_name AS `rev_user_text`,temp_rev_user.revactor_actor AS `rev_actor`,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len,user_name  FROM `revision` JOIN `revision_comment_temp` `temp_rev_comment` ON ((temp_rev_comment.revcomment_rev = rev_id)) JOIN `comment` `comment_rev_comment` ON ((comment_rev_comment.comment_id = temp_rev_comment.revcomment_comment_id)) JOIN `revision_actor_temp` `temp_rev_user` ON ((temp_rev_user.revactor_rev = rev_id)) JOIN `actor` `actor_rev_user` ON ((actor_rev_user.actor_id = temp_rev_user.revactor_actor)) JOIN `page` ON ((page_id = rev_page)) LEFT JOIN `user` ON ((actor_rev_user.actor_user != 0) AND (user_id = actor_rev_user.actor_user))   WHERE rev_page = '457' AND page_id = '457' AND (rev_id=page_latest)  LIMIT 1
Function: MediaWiki\Revision\RevisionStore::fetchRevisionRowFromConds
Error: 1100 Table 'temp_rev_comment' was not locked with LOCK TABLES (localhost)

#0 /includes/libs/rdbms/database/Database.php(1574): Wikimedia\Rdbms\Database->getQueryExceptionAndLog('Table 'temp_rev...', 1100, 'SELECT  rev_id,...', 'MediaWiki\\Revis...')
#1 /includes/libs/rdbms/database/Database.php(1152): Wikimedia\Rdbms\Database->reportQueryError('Table 'temp_rev...', 1100, 'SELECT  rev_id,...', 'MediaWiki\\Revis...', false)
#2 /includes/libs/rdbms/database/Database.php(1807): Wikimedia\Rdbms\Database->query('SELECT  rev_id,...', 'MediaWiki\\Revis...')
#3 /includes/libs/rdbms/database/Database.php(1899): Wikimedia\Rdbms\Database->select(Array, Array, Array, 'MediaWiki\\Revis...', Array, Array)
#4 /includes/libs/rdbms/database/DBConnRef.php(68): Wikimedia\Rdbms\Database->selectRow(Array, Array, Array, 'MediaWiki\\Revis...', Array, Array)
#5 /includes/libs/rdbms/database/DBConnRef.php(333): Wikimedia\Rdbms\DBConnRef->__call('selectRow', Array)
#6 /includes/Revision/RevisionStore.php(2589): Wikimedia\Rdbms\DBConnRef->selectRow(Array, Array, Array, 'MediaWiki\\Revis...', Array, Array)
#7 /includes/Revision/RevisionStore.php(2536): MediaWiki\Revision\RevisionStore->fetchRevisionRowFromConds(Object(Wikimedia\Rdbms\MaintainableDBConnRef), Array, 0)
#8 /includes/Revision/RevisionStore.php(2416): MediaWiki\Revision\RevisionStore->loadRevisionFromConds(Object(Wikimedia\Rdbms\MaintainableDBConnRef), Array)
#9 /includes/Revision.php(262): MediaWiki\Revision\RevisionStore->loadRevisionFromPageId(Object(Wikimedia\Rdbms\MaintainableDBConnRef), '457', 0)
#10 /maintenance/Maintenance.php(1547): Revision::loadFromPageId(Object(Wikimedia\Rdbms\MaintainableDBConnRef), '457')
#11 /maintenance/updateSearchIndex.php(121): Maintenance->updateSearchIndexForPage(Object(Wikimedia\Rdbms\MaintainableDBConnRef), '457')
#12 /maintenance/Maintenance.php(1528): UpdateSearchIndex->searchIndexUpdateCallback(Object(Wikimedia\Rdbms\MaintainableDBConnRef), Object(stdClass))
#13 /maintenance/updateSearchIndex.php(115): Maintenance->updateSearchIndex(20, Array, Object(Wikimedia\Rdbms\MaintainableDBConnRef), Object(Wikimedia\Rdbms\ResultWrapper))
#14 /maintenance/updateSearchIndex.php(81): UpdateSearchIndex->doUpdateSearchIndex('20200514131503', '20200515131503', 20)
#15 /maintenance/doMaintenance.php(99): UpdateSearchIndex->execute()
#16 /maintenance/updateSearchIndex.php(126): require_once('...')
#17 {main}

I also had:

$wgShowDBErrorBacktrace = true;
$wgDebugLogFile = "debug-{$wgDBname}.log";

and got below in the file:

[SQLBagOStuff] MainObjectStash using store ReplicatedBagOStuff
[objectcache] MainWANObjectCache using store EmptyBagOStuff
[SQLBagOStuff] MainObjectStash using store ReplicatedBagOStuff
[objectcache] MainWANObjectCache using store EmptyBagOStuff
IP: 127.0.0.1
Start command line script updateSearchIndex.php
[localisation] LocalisationCache: using store LCStoreDB
[DBQuery] Wikimedia\Rdbms\DatabaseMysqlBase::open [0s] localhost: SET group_concat_max_len = 262144, sql_mode = ''
[DBReplication] Wikimedia\Rdbms\LBFactory::getChronologyProtector: request info {
    "IPAddress": "127.0.0.1",
    "UserAgent": false,
    "ChronologyProtection": false,
    "ChronologyPositionIndex": 0,
    "ChronologyClientId": false
}
[DBConnection] Wikimedia\Rdbms\LoadBalancer::lazyLoadReplicationPositions: executed chronology callback.
[DBConnection] Wikimedia\Rdbms\LoadBalancer::getLocalConnection: connected to database 0 at 'localhost'.
[DBQuery] Wikimedia\Rdbms\DatabaseMysqlBase::serverIsReadOnly [0s] localhost: SELECT @@GLOBAL.read_only AS Value
[DBQuery] LCStoreDB::get [0.001s] localhost: SELECT  lc_value  FROM `l10n_cache`    WHERE lc_lang = 'fa' AND lc_key = 'deps'  LIMIT 1  
[DBQuery] LCStoreDB::get [0.002s] localhost: SELECT  lc_value  FROM `l10n_cache`    WHERE lc_lang = 'fa' AND lc_key = 'list'  LIMIT 1  
[DBQuery] LCStoreDB::get [0s] localhost: SELECT  lc_value  FROM `l10n_cache`    WHERE lc_lang = 'fa' AND lc_key = 'preload'  LIMIT 1  
[DBQuery] LCStoreDB::get [0s] localhost: SELECT  lc_value  FROM `l10n_cache`    WHERE lc_lang = 'fa' AND lc_key = 'preload'  LIMIT 1  
[DBQuery] LCStoreDB::get [0s] localhost: SELECT  lc_value  FROM `l10n_cache`    WHERE lc_lang = 'fa' AND lc_key = 'fallbackSequence'  LIMIT 1  
[session] SessionManager using store SqlBagOStuff
[DBQuery] UpdateSearchIndex::doUpdateSearchIndex [0.001s] localhost: SELECT rc_cur_id FROM `recentchanges`
			JOIN `page` ON rc_cur_id=page_id AND rc_this_oldid=page_latest
			WHERE rc_type != 3 AND rc_timestamp BETWEEN '20200514132046' AND '20200515132046'
[DBQuery] Maintenance-searchIndexLock [0.001s] localhost: LOCK TABLES `searchindex` WRITE,`page` READ,`revision` READ,`text` READ,`interwiki` READ,`l10n_cache` READ,`user` READ,`page_restrictions` READ
[DBQuery] MediaWiki\Revision\RevisionStore::fetchRevisionRowFromConds [0s] localhost: SELECT  rev_id,rev_page,rev_timestamp,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,comment_rev_comment.comment_text AS `rev_comment_text`,comment_rev_comment.comment_data AS `rev_comment_data`,comment_rev_comment.comment_id AS `rev_comment_cid`,actor_rev_user.actor_user AS `rev_user`,actor_rev_user.actor_name AS `rev_user_text`,temp_rev_user.revactor_actor AS `rev_actor`,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len,user_name  FROM `revision` JOIN `revision_comment_temp` `temp_rev_comment` ON ((temp_rev_comment.revcomment_rev = rev_id)) JOIN `comment` `comment_rev_comment` ON ((comment_rev_comment.comment_id = temp_rev_comment.revcomment_comment_id)) JOIN `revision_actor_temp` `temp_rev_user` ON ((temp_rev_user.revactor_rev = rev_id)) JOIN `actor` `actor_rev_user` ON ((actor_rev_user.actor_id = temp_rev_user.revactor_actor)) JOIN `page` ON ((page_id = rev_page)) LEFT JOIN `user` ON ((actor_rev_user.actor_user != 0) AND (user_id = actor_rev_user.actor_user))   WHERE rev_page = '457' AND page_id = '457' AND (rev_id=page_latest)  LIMIT 1  
[DBQuery] MediaWiki\Revision\RevisionStore::fetchRevisionRowFromConds	localhost	1100	Table 'temp_rev_comment' was not locked with LOCK TABLES (localhost)	SELECT  rev_id,rev_page,rev_timestamp,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,comment_rev_comment.comment_text AS `rev_comment_text`,comment_rev_comment.comment_data AS `rev_comment_data`,comment_rev_comment.comment_id AS `rev_comment_cid`,actor_rev_user.actor_user AS `rev_user`,actor_rev_user.actor_name AS `rev_user_text`,temp_rev_user.revactor_actor AS `rev_actor`,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len,user_name  FROM `revision` JOIN `revision_comment_temp` `temp_rev_comment` ON ((temp_rev_comment.revcomment_rev = rev_id)) JOIN `comment` `comment_rev_comment` ON ((comment_rev_comment.comment_id = temp_rev_comment.revcomment_comment_id)) JOIN `revision_actor_temp` `temp_rev_user` ON ((temp_rev_user.revactor_rev = rev_id)) JOIN `actor` `actor_rev_user` ON ((actor_rev_user.actor_id = temp_rev_user.revactor_actor)) JOIN `page` ON ((page_id = rev_page)) LEFT JOIN `user` ON ((actor_rev_user.actor_user != 0) AND (user_id = actor_rev_user.actor_user))   WHERE rev_page = '457' AND page_id = '457' AND (rev_id=page_latest)  LIMIT 1  
#0 /includes/libs/rdbms/database/Database.php(1574): Wikimedia\Rdbms\Database->getQueryExceptionAndLog(string, integer, string, string)
#1 /includes/libs/rdbms/database/Database.php(1152): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
#2 /includes/libs/rdbms/database/Database.php(1807): Wikimedia\Rdbms\Database->query(string, string)
#3 /includes/libs/rdbms/database/Database.php(1899): Wikimedia\Rdbms\Database->select(array, array, array, string, array, array)
#4 /includes/libs/rdbms/database/DBConnRef.php(68): Wikimedia\Rdbms\Database->selectRow(array, array, array, string, array, array)
#5 /includes/libs/rdbms/database/DBConnRef.php(333): Wikimedia\Rdbms\DBConnRef->__call(string, array)
#6 /includes/Revision/RevisionStore.php(2589): Wikimedia\Rdbms\DBConnRef->selectRow(array, array, array, string, array, array)
#7 /includes/Revision/RevisionStore.php(2536): MediaWiki\Revision\RevisionStore->fetchRevisionRowFromConds(Wikimedia\Rdbms\MaintainableDBConnRef, array, integer)
#8 /includes/Revision/RevisionStore.php(2416): MediaWiki\Revision\RevisionStore->loadRevisionFromConds(Wikimedia\Rdbms\MaintainableDBConnRef, array)
#9 /includes/Revision.php(262): MediaWiki\Revision\RevisionStore->loadRevisionFromPageId(Wikimedia\Rdbms\MaintainableDBConnRef, string, integer)
#10 /maintenance/Maintenance.php(1547): Revision::loadFromPageId(Wikimedia\Rdbms\MaintainableDBConnRef, string)
#11 /maintenance/updateSearchIndex.php(121): Maintenance->updateSearchIndexForPage(Wikimedia\Rdbms\MaintainableDBConnRef, string)
#12 /maintenance/Maintenance.php(1528): UpdateSearchIndex->searchIndexUpdateCallback(Wikimedia\Rdbms\MaintainableDBConnRef, stdClass)
#13 /maintenance/updateSearchIndex.php(115): Maintenance->updateSearchIndex(integer, array, Wikimedia\Rdbms\MaintainableDBConnRef, Wikimedia\Rdbms\ResultWrapper)
#14 /maintenance/updateSearchIndex.php(81): UpdateSearchIndex->doUpdateSearchIndex(string, string, integer)
#15 /maintenance/doMaintenance.php(99): UpdateSearchIndex->execute()
#16 /maintenance/updateSearchIndex.php(126): require_once(string)
#17 {main}
[DBConnection] Wikimedia\Rdbms\LBFactory::destroy: closing connection to database 'localhost'.

The one reported on https://www.mediawiki.org/wiki/Topic:Vbps68wp2h51ifg6 is not by me. I reported that one is reported while ago by someone and is not fixed yet, so I reported it here. I probably have to add that I am using the latest fresh version and for sure I did run update.php too. So why developpers don't care to fix it as it is reported while ago by many other people?

Aklapper added a comment.EditedMay 15 2020, 1:45 PM

@Farvardyn: Thanks for the explanation! Which exact MediaWiki version is this about? See Special:Version on your wiki.
Also, please see the Etiquette as statements like "developers don't care" are not constructive, especially if nobody has ever reported this problem in the issue tracker before. If you would like to see issues fixed then you are very welcome to investigate and provide a patch - thanks in advance! Also see https://www.mediawiki.org/wiki/Bug_management/Development_prioritization for more information on expectations.

This is 1.34.0, where is changelog of 1.34.1 that we can check this is fixed?

Bawolff renamed this task from updateSearchIndex.php to updateSearchIndex.php sql error not all tables locked.May 15 2020, 3:39 PM
Bawolff updated the task description. (Show Details)May 15 2020, 3:42 PM

Also, why exactly was this reported in Phabricator, in addition to https://www.mediawiki.org/wiki/Topic:Vbps68wp2h51ifg6 ?

For reference, i told OP to report it here - i haven't fully investigated but it looks like the issue is schema change broke maintenance script that is not used by WMF - and not user error.

I updated to 1.34.1 and the problem still exists. I see the database has no 'temp_rev_comment' table. It seems there is a typo somewhere in codes. Please ping/call a developper to see this bug report.

Farvardyn added a comment.EditedMay 15 2020, 4:00 PM

I also searched files, and the only places contains temp_rev_comment are the followings. This is strange because these are just TestCase files, not core files, so why this error happens? Also there is no such file while the TestCase exists: /includes/Revision/RevisionQueryInfo.php

/tests/phpunit/includes/CommentStoreTest.php
/tests/phpunit/includes/Revision/RevisionQueryInfoTest.php
/tests/phpunit/includes/RevisionTest.php

Aklapper changed the task status from Stalled to Open.May 16 2020, 3:56 PM

Any update yet.

same problem with:

  • MediaWiki 1.34.0
  • PHP 7.2.24-0ubuntu0.18.04.4 (fpm-fcgi)
  • MariaDB 10.1.44-MariaDB-0ubuntu0.18.04.1
  • ICU 60.2
  • Lua 5.1.5
  • Elasticsearch 6.5.4

Like opener of Topic:Vbps68wp2h51ifg6 we have a custom namespace too, but not sure if this happened in consequence of.
Can easily be reproduced by calling updateSearchIndex.php. The tables are locked by calling lockSearchindex() and afterwards this SELECT statement is causing the Error: 1100:

SELECT  rev_id,rev_page,rev_timestamp,rev_minor_edit,rev_deleted,rev_len,rev_parent_id,rev_sha1,comment_rev_comment.comment_text AS `rev_comment_text`,comment_rev_comment.comment_data AS `rev_comment_data`,comment_rev_comment.comment_id AS `rev_comment_cid`,actor_rev_user.actor_user AS `rev_user`,actor_rev_user.actor_name AS `rev_user_text`,temp_rev_user.revactor_actor AS `rev_actor`,page_namespace,page_title,page_id,page_latest,page_is_redirect,page_len,user_name  FROM `revision` JOIN `revision_comment_temp` `temp_rev_comment` ON ((temp_rev_comment.revcomment_rev = rev_id)) JOIN `comment` `comment_rev_comment` ON ((comment_rev_comment.comment_id = temp_rev_comment.revcomment_comment_id)) JOIN `revision_actor_temp` `temp_rev_user` ON ((temp_rev_user.revactor_rev = rev_id)) JOIN `actor` `actor_rev_user` ON ((actor_rev_user.actor_id = temp_rev_user.revactor_actor)) JOIN `page` ON ((page_id = rev_page)) LEFT JOIN `user` ON ((actor_rev_user.actor_user != 0) AND (user_id = actor_rev_user.actor_user))   WHERE rev_page = '330' AND page_id = '330' AND (rev_id=page_latest)  LIMIT 1

Restart and running update.php --force is not changing this. Anything I can do to help clarify?

Farvardyn added a comment.EditedMay 20 2020, 11:55 AM

Are you sure it is because of custom namespace? Can you temporarily disable it and test again? I believe custom namespace is irrelevant.

Does lockSearchindex() contain the name of that table of question?

@ClageLG

ClageLG added a comment.EditedMay 20 2020, 12:15 PM

How to temporarily disable a namespace? Just commenting out of LocalSettings.php is changing nothing. As mentioned before, I am not sure if it happened in consequence. It was just a common detail of our wiki and the wiki of Sokote zaman at Topic:Vbps68wp2h51ifg6.

The function lockSearchindex() is doing LOCK TABLES searchindex WRITE,page READ,revision READ,text READ,interwiki READ,l10n_cache READ,user READ,page_restrictions READ and not locking any of the temp_* tables. If I add temp_rev_comment to the list of tables to lock, I get Error: 1146 Table 'mediawiki.temp_rev_comment' doesn't exist. It is not like T214062.

Doing grep -r temp_rev_comment . in the wikis directory is showing this table name only in PHP unit tests RevisionTest.php, CommentStoreTest.php and RevisionQueryInfoTest.php. I think the table name is somewhere assembled.

Yes, I meant commenting custom namespace in LocalSettings.php so it is not the case. As I said earlier in this thread, yes this table name is used only in test cases and doesn't exist.