Page MenuHomePhabricator

InvalidDataException on support desk
Closed, ResolvedPublic

Description

Reported by @Florian at T75148#1535145 .

https://www.mediawiki.org/wiki/Project:Support_desk

Error:

2015-08-13 14:47:46 mw1252 mediawikiwiki exception ERROR: [8a10dd43] /wiki/Project:Support_desk   Flow\Exception\InvalidDataException from line 45 of /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Collection/PostCollection.php: No TopicListEntry founds for topic id s52bxzn9rgi3j9e0 {"exception":"[Exception Flow\\Exception\\InvalidDataException] (/srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Collection/PostCollection.php:45) No TopicListEntry founds for topic id s52bxzn9rgi3j9e0
[stacktrace]
#0 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Collection/AbstractCollection.php(240): Flow\\Collection\\PostCollection->getBoardWorkflowId()
#1 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/RevisionActionPermissions.php(76): Flow\\Collection\\AbstractCollection->getBoardWorkflow()
#2 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Templating.php(131): Flow\\RevisionActionPermissions->isAllowed(Flow\\Model\\PostRevision, string)
#3 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Formatter/TocTopicListFormatter.php(67): Flow\\Templating->getContent(Flow\\Model\\PostRevision, string)
#4 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Block/TopicList.php(289): Flow\\Formatter\\TocTopicListFormatter->formatApi(Flow\\Model\\Workflow, array, array, Flow\\Data\\Pager\\PagerPage)
#5 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Block/TopicList.php(231): Flow\\Block\\TopicListBlock->renderApi(array)
#6 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/View.php(192): Flow\\Block\\TopicListBlock->renderTocApi(array, array)
#7 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/View.php(69): Flow\\View->buildApiResponse(Flow\\WorkflowLoader, array, string, array)
#8 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Actions/Action.php(101): Flow\\View->show(Flow\\WorkflowLoader, string)
#9 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Actions/ViewAction.php(16): Flow\\Actions\\FlowAction->showForAction(string, OutputPage)
#10 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Actions/Action.php(46): Flow\\Actions\\ViewAction->showForAction(string)
#11 /srv/mediawiki/php-1.26wmf18/includes/MediaWiki.php(456): Flow\\Actions\\FlowAction->show()
#12 /srv/mediawiki/php-1.26wmf18/includes/MediaWiki.php(255): MediaWiki->performAction(Article, Title)
#13 /srv/mediawiki/php-1.26wmf18/includes/MediaWiki.php(677): MediaWiki->performRequest()
#14 /srv/mediawiki/php-1.26wmf18/includes/MediaWiki.php(474): MediaWiki->main()
#15 /srv/mediawiki/php-1.26wmf18/index.php(41): MediaWiki->run()
#16 /srv/mediawiki/w/index.php(3): include(string)
#17 {main}
"}

Reproducible by visiting https://www.mediawiki.org/wiki/Topic:S52bxzn9rgi3j9e0 :

2015-08-13 18:16:46 mw1077 mediawikiwiki exception ERROR: [49b0f985] /wiki/Topic:S52bxzn9rgi3j9e0   Flow\Exception\InvalidDataException from line 45 of /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Collection/PostCollection.php: No TopicListEntry founds for topic id s52bxzn9rgi3j9e0 {"exception":"[Exception Flow\\Exception\\InvalidDataException] (/srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Collection/PostCollection.php:45) No TopicListEntry founds for topic id s52bxzn9rgi3j9e0
[stacktrace]
#0 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Collection/AbstractCollection.php(240): Flow\\Collection\\PostCollection->getBoardWorkflowId()
#1 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/RevisionActionPermissions.php(76): Flow\\Collection\\AbstractCollection->getBoardWorkflow()
#2 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Block/Topic.php(822): Flow\\RevisionActionPermissions->isAllowed(Flow\\Model\\PostRevision, string)
#3 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Block/Topic.php(479): Flow\\Block\\TopicBlock->loadTopicTitle()
#4 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/View.php(176): Flow\\Block\\TopicBlock->renderApi(array)
#5 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/View.php(69): Flow\\View->buildApiResponse(Flow\\WorkflowLoader, array, string, array)
#6 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Actions/Action.php(101): Flow\\View->show(Flow\\WorkflowLoader, string)
#7 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Actions/ViewAction.php(16): Flow\\Actions\\FlowAction->showForAction(string, OutputPage)
#8 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Actions/Action.php(46): Flow\\Actions\\ViewAction->showForAction(string)
#9 /srv/mediawiki/php-1.26wmf18/includes/MediaWiki.php(456): Flow\\Actions\\FlowAction->show()
#10 /srv/mediawiki/php-1.26wmf18/includes/MediaWiki.php(255): MediaWiki->performAction(Article, Title)
#11 /srv/mediawiki/php-1.26wmf18/includes/MediaWiki.php(677): MediaWiki->performRequest()
#12 /srv/mediawiki/php-1.26wmf18/includes/MediaWiki.php(474): MediaWiki->main()
#13 /srv/mediawiki/php-1.26wmf18/index.php(41): MediaWiki->run()
#14 /srv/mediawiki/w/index.php(3): include(string)
#15 {main}
"}
mwscript eval.php --wiki=mediawikiwiki
> $topicId = Flow\Model\UUID::create( 's52bxzn9rgi3j9e0' );

> var_export( $topicId->getHex() );
'0525626c05ef3f2490e148'
mysql:research@x1-analytics-slave [flowdb]> SELECT * FROM flow_workflow WHERE LOWER(HEX(workflow_id)) = '0525626c05ef3f2490e148';
Empty set (0.13 sec)

mysql:research@x1-analytics-slave [flowdb]> SELECT * FROM flow_topic_list WHERE LOWER(HEX(topic_id)) = '0525626c05ef3f2490e148';
Empty set (0.13 sec)

mysql:research@x1-analytics-slave [flowdb]> SELECT LOWER(HEX(rev_id)), rev_type, LOWER(HEX(rev_type_id)), LOWER(HEX(rev_parent_id)) FROM flow_revision WHERE LOWER(HEX(rev_type_id)) = '0525626c05ef3f2490e148';
Empty set (0.27 sec)
matthew@matthew-l55: ~/Code/Wikimedia/vagrant-latest/mediawiki/extensions/Flow% grep s52bxzn9rgi3j9e0 Project:Support_desk.after_2015-08-12_hhvm.log
matthew@matthew-l55: ~/Code/Wikimedia/vagrant-latest/mediawiki/extensions/Flow%
mattflaschen@terbium:~$ mwscript eval.php --wiki=mediawikiwiki
> $workflow = Flow\Container::get( 'storage' )->getStorage( 'Workflow' )->get( 's52bxzn9rgi3j9e0' );

> var_export( $workflow );
Flow\Model\Workflow::__set_state(array(
   'id' => 
  Flow\Model\UUID::__set_state(array(
     'binaryValue' => NULL,
     'hexValue' => NULL,
     'alphadecimalValue' => 's52bxzn9rgi3j9e0',
     'timestamp' => NULL,
  )),
   'type' => 'topic',
   'wiki' => 'mediawikiwiki',
   'pageId' => 477763,
   'namespace' => 4,
   'titleText' => 'Support_desk',
   'lastUpdated' => '20150813051425',
   'title' => NULL,
   'ownerTitle' => NULL,
))
> var_export( $workflow->getId()->getTimestamp() );
'20141028211313'

It currently only affects the updated order:

https://www.mediawiki.org/wiki/Project:Support_desk?topiclist_sortby=newest
https://www.mediawiki.org/wiki/Project:Support_desk?topiclist_sortby=updated

Cross-checking by the timestamp (20141028211313, see above), indicates it is https://www.mediawiki.org/wiki/Thread:Project:Support_desk/provider_migrated_to_php_5.5,_wiki_doesn%27t_load , which as expected is not a redirect yet. Also, the thread ID is also not in the source store, which supports that it will re-import correctly:

mysql:research@s3-analytics-slave [mediawikiwiki]> SELECT thread_id, page_id, rev_id, page_namespace, page_title FROM revision JOIN page on rev_page = page_id JOIN thread ON thread_root = page_id WHERE rev_timestamp = '20141028211313';
+-----------+---------+---------+----------------+----------------------------------------------------------------------+
| thread_id | page_id | rev_id  | page_namespace | page_title                                                           |
+-----------+---------+---------+----------------+----------------------------------------------------------------------+
|     49916 |  316952 | 1243923 |             90 | Project:Support_desk/provider_migrated_to_php_5.5,_wiki_doesn't_load |
+-----------+---------+---------+----------------+----------------------------------------------------------------------+
1 row in set (0.02 sec)
matthew@matthew-l55: ~/Code/Wikimedia/vagrant-latest/mediawiki/extensions/Flow% grep 49916 Project:Support_desk.after_2015-08-12_hhvm.log
matthew@matthew-l55: ~/Code/Wikimedia/vagrant-latest/mediawiki/extensions/Flow%

Event Timeline

Mattflaschen-WMF claimed this task.
Mattflaschen-WMF raised the priority of this task from to Unbreak Now!.
Mattflaschen-WMF updated the task description. (Show Details)
Restricted Application added a project: Collaboration-Team-Triage. · View Herald TranscriptAug 13 2015, 6:06 PM
Restricted Application added a subscriber: Aklapper. · View Herald Transcript
Mattflaschen-WMF set Security to None.

View is working fine for me right now, logged in or anon (and apparently other people, since there have been posts since I wrapped up last night). I will check the exception.

Mattflaschen-WMF updated the task description. (Show Details)

Indeed the error is not present as anon, but logged in does crash for me :(

I'm able to read and post, though, by accessing the page history and opening individual threads

It's also not in the source store (see description). So what is it in? The cache, maybe, but it shouldn't have been committed to only the cache but not the DB.

May it be related to the LQT->Flow conversion (T92303)? I now see the archive still has active LQT topics (some of them are redirects), while on other converted pages the LQT archive is empty.

That's because the support desk conversion is in progress.

So in summary. AFAICT:

  1. It's not in the database.
  2. It's in the time range to be an LQT import (20141028211313).
  3. It's not in the log of imported topics.
  4. Nothing links to it as it should if there were a completed topic.
  5. It says it was updated today (20150813051425).
  6. It's currently only in memcached for the updated order.

Nothing elucidating in Kibana.

I'm going to go ahead and action=purge. If it is a real imported topic, it should be re-imported since it's not in the source store.

Did the purge. Still reproducible by visiting the topic directly (I think just until cache expires), but not on the page AFAICT.

Woohooo, it loads fine for me now, thanks!

Works for me, too. @Mattflaschen: Maybe an unfinished delete action? (I'm not sure, if that could result in such a problem)

So, I confirmed it's still considered "not imported yet" . I think I know what happened:

The transaction never got committed by the importer (likely Ctrl-Ced due to the memory problems), but due to the split of memcache.local_buffered and memcache.buffered the indexes were committed immediately: https://git.wikimedia.org/blob/mediawiki%2Fextensions%2FFlow.git/215f4a015855667ee0ed6310715d17e6e9a90cdd/includes%2FData%2FBagOStuff%2FBufferedBagOStuff.php#L416

I need to do a followup to https://git.wikimedia.org/commit/mediawiki%2Fextensions%2FFlow.git/d9e250d1339afb064d9b4c92031559067ac65eaf .

See also T108601: Fix memory leak in LQT->Flow conversion script.

Change 231449 had a related patch set uploaded (by Mattflaschen):
Change how memcache.local_buffered/buffered are handled

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

Change 231449 merged by jenkins-bot:
Change how memcache.local_buffered/buffered are handled

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

Change 231450 had a related patch set uploaded (by Mattflaschen):
Change how memcache.local_buffered/buffered are handled

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

Change 231450 merged by jenkins-bot:
Change how memcache.local_buffered/buffered are handled

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

It turns out this was caused by a NoParsoidException, not a Ctrl-C.

./public_html/2015_08_12_LQT_Flow_Support_desk_hhvm_resume.log:[2015-08-13 05:14:50] exception 'Flow\Exception\NoParsoidException' with message 'Failed contacting Parsoid for title "Topic:S52bxzn9rgi3j9e0": There was a problem during the HTTP request: 503 Service Unavailable' in /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Parsoid/Utils.php:124

I didn't have to do anything special for this topic, and as noted above it seems to have resumed fine, so maybe Parsoid actually was down:

mattflaschen@terbium:~$ grep -A19 -iE '49916' public_html/2015_08_12_LQT_Flow_Support_desk_hhvm_resume.log
[2015-08-13 05:14:50] Failed importing topic: topiclqt-api:local:thread_id:49916
[2015-08-13 05:14:50] exception 'Flow\Exception\NoParsoidException' with message 'Failed contacting Parsoid for title "Topic:S52bxzn9rgi3j9e0": There was a problem during the HTTP request: 503 Service Unavailable' in /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Parsoid/Utils.php:124
Stack trace:
#0 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Parsoid/Utils.php(42): Flow\Parsoid\Utils::parsoid()
#1 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Model/AbstractRevision.php(472): Flow\Parsoid\Utils::convert()
#2 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Model/PostRevision.php(174): Flow\Model\AbstractRevision->setContent()
#3 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Import/Importer.php(864): Flow\Model\PostRevision->reply()
#4 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Import/Importer.php(924): Closure$Flow\Import\TalkpageImportOperation::importPost()
#5 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Import/Importer.php(869): Flow\Import\TalkpageImportOperation->importObjectWithHistory()
#6 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Import/Importer.php(687): Flow\Import\TalkpageImportOperation->importPost()
#7 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Import/Importer.php(606): Flow\Import\TalkpageImportOperation->importTopic()
#8 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Import/Importer.php(128): Flow\Import\TalkpageImportOperation->import()
#9 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Import/Converter.php(188): Flow\Import\Importer->import()
#10 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Import/Converter.php(139): Flow\Import\Converter->doConversion()
#11 /srv/mediawiki/php-1.26wmf18/extensions/Flow/includes/Import/Converter.php(108): Flow\Import\Converter->convert()
#12 /srv/mediawiki/php-1.26wmf18/extensions/Flow/maintenance/convertLqtPageOnLocalWiki.php(77): Flow\Import\Converter->convertAll()
#13 /srv/mediawiki/php-1.26wmf18/maintenance/doMaintenance.php(103): ConvertLqtPageOnLocalWiki->execute()
#14 /srv/mediawiki/php-1.26wmf18/extensions/Flow/maintenance/convertLqtPageOnLocalWiki.php(84): include()
#15 /srv/mediawiki/multiversion/MWScript.php(97): include()
#16 {main}

I should have checked this log earlier, but I still think I understand why the cache got in an inconsistent state.

DannyH closed this task as Resolved.Aug 19 2015, 6:01 PM
DannyH added a subscriber: DannyH.