Page MenuHomePhabricator
Create Task
Maniphest T172025

Flow isAllowed gets actual revision text before it is needed
Open, LowPublic
Actions

Description

Description by @ArielGlenn:

It seems that somehow Flow\RevisionActionPermissions->isAllowed() winds up getting actual revision text if you follow the code far enough down the rabbit hole.

  • $last = $cache->getLastRevisionFor( $revision ); leads to
  • $lastRevision = $revision->getCollection()->getLastRevision(); which eventually leads to
  • AbstractCollections::getAllRevisions() which calls
  • Flow\Data'ObjectLocator::getStorage()->find which after a few layers gets around to
  • Flow\Data\Storage\RevisionStorage::mergeExternalContent() which, once you get through mergeMulti, you find is going to do
  • ExternalStore::batchfetchFromURLs() and there you have it.

We only need the metadata in order to make permission decisions, revision content ought to be lazyloaded, or at the very least there ought to be the option to lazyload it.

Details

SubjectRepoBranchLines +/-
Allow loading revisions without contentmediawiki/extensions/Flowmaster+403 -85
Customize query in gerrit

Related Objects
Search...

Event Timeline

• Mattflaschen-WMF created this task.Jul 29 2017, 12:02 AM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJul 29 2017, 12:02 AM
ArielGlenn updated the task description. (Show Details)Jul 29 2017, 7:42 AM
ArielGlenn removed a subscriber: Ariel.
• jmatazzoni moved this task from Untriaged to In Development on the Collaboration-Team-Triage (Collab-Team-This-Quarter) board.Aug 1 2017, 5:40 PM
• Mattflaschen-WMF mentioned this in T172484: Flow stores redundant entries in External Store.Aug 4 2017, 5:45 AM
gerritbot added a comment.Aug 4 2017, 7:35 AM

Change 370154 had a related patch set uploaded (by Mattflaschen; owner: Mattflaschen):
[mediawiki/extensions/Flow@master] WIP: Allow loading revisions without content

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

gerritbot added a project: Patch-For-Review.Aug 4 2017, 7:35 AM
• Mattflaschen-WMF moved this task from In Development to Needs Review on the Collaboration-Team-Triage (Collab-Team-This-Quarter) board.Aug 28 2017, 10:28 AM
ArielGlenn added a comment.Sep 1 2017, 2:06 PM

I've done some testing and still not sure my testing is correct. Code is slightly modified from yours, as I have modified Exporter.php to allow for stubs (see https://gerrit.wikimedia.org/r/#/c/355080/9/includes/Dump/Exporter.php).

Anyways, the good news is that I don't see ExternalStoreDB->batchFetchBlobs called somewhere when we check isAllowed. The bad news is that it still seems to be called... here's a shortened version of the stack trace with lots of args removed.

* ExternalStoreDB->batchFetchBlobs(cluster24, Array ([131042] => Array ([0] => ))) called at
     [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/includes/externalstore/ExternalStoreDB.php:76]
* ExternalStoreDB->batchFetchFromURLs(Array ([0] => DB://cluster24/131042)) called at
     [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/includes/externalstore/ExternalStore.php:115]
* ExternalStore::batchFetchFromURLs(Array ([0] => DB://cluster24/131042))
* call_user_func(Array ([0] => ExternalStore,[1] => batchFetchFromURLs), Array ([0] => DB://cluster24/131042)) called at
     [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Data/Utils/Merger.php:79]
* Flow\Data\Utils\Merger::mergeMulti(Array ([0] => Array ([rl7ihzzajdlw441w] => Array ([tree_rev_descendant_id]  etc called from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Data/Storage/RevisionStorage.php:367]
* Flow\Data\Storage\RevisionStorage::mergeExternalContent(Array ([0] => Array ([rl7ihzzajdlw441w] etc called from	
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Data/Storage/RevisionStorage.php:190]
* Flow\Data\Storage\RevisionStorage->findMulti(Array ([0] => Array ([rev_type_id] => Flow\Model\UUID Object etc called from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Data/Index/FeatureIndex.php:481]
* Flow\Data\Index\FeatureIndex->backingStoreFindMulti(Array ([0] => Array ([rev_type_id] => Flow\Model\UUID Object etc called from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Data/Index/FeatureIndex.php:300]
* Flow\Data\Index\FeatureIndex->findMulti(Array ([0] => Array ([rev_type_id] => Flow\Model\UUID Object etc	called from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Data/ObjectLocator.php:89]
* Flow\Data\ObjectLocator->findMulti(Array ([0] => Array ([rev_type_id] etc called	from
     [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Data/ManagerGroup.php:129]
* Flow\Data\ManagerGroup->findMulti(PostRevision, Array ([0] => Array ([rev_type_id] etc called from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Repository/RootPostLoader.php:110]
* Flow\Repository\RootPostLoader->getMulti(Array ([0] => Flow\Model\UUID Object etc called	from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Repository/RootPostLoader.php:87]
* Flow\Repository\RootPostLoader->get(Flow\Model\UUID Object ([] => etc called from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Search/Iterators/TopicIterator.php:115]
* Flow\Search\Iterators\TopicIterator->transform(stdClass Object ([workflow_id] etc called	from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Search/Iterators/AbstractIterator.php:154]
* Flow\Dump\Exporter->formatWorkflow(Flow\Model\Workflow Object ([] => Flow\Model\UUID Object etc called from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/includes/Dump/Exporter.php:182]
* Flow\Dump\Exporter->dump(BatchRowIterator Object ([] => Wikimedia\Rdbms\DatabaseMysqli Object etc called	from
 	  [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/maintenance/dumpBackup.php:89]
* FlowDumpBackup->dump(2, 1) called at [/home/datasets/testing/mediawiki/php-1.30.0-wmf.1/extensions/Flow/maintenance/dumpBackup.php:62]

formatRevision, the function I modified in Exporter.php, isn't implicated at all in this. I'll look at it some more to see if I missed something or messed up testing somehow.

• Mattflaschen-WMF added a comment.Sep 1 2017, 9:57 PM
In T172025#3573173, @ArielGlenn wrote:

I've done some testing and still not sure my testing is correct. Code is slightly modified from yours, as I have modified Exporter.php to allow for stubs (see https://gerrit.wikimedia.org/r/#/c/355080/9/includes/Dump/Exporter.php).

Anyways, the good news is that I don't see ExternalStoreDB->batchFetchBlobs called somewhere when we check isAllowed. The bad news is that it still seems to be called... here's a shortened version of the stack trace with lots of args removed

Yeah, I tested isAllowed before, not the dump path. I'll rebase your patch onto mine, so I can test them together, and set loadcontentnow=>false in this path too.

Jdforrester-WMF mentioned this in T175080: Flow fails to load content when running CirrusSearchLinksUpdate jobs.Sep 6 2017, 7:48 PM
ArielGlenn added a comment.Sep 12 2017, 1:06 PM

I tried to be clever and add 'loadcontentnow' => false to the getMulti call in RootPostLoader::getWithRoot but that looks to be too late in the game; at any rate, content is still loaded. Where ought I to add this?

• ggellerman added subscribers: Catrope, Arrbee.Nov 6 2017, 6:41 PM
ArielGlenn added a comment.Feb 12 2018, 10:45 AM

So. @Catrope has generously volunteered to whack away at this. Thanks! I have tried to unbitrot my stubs patches. They should be ok, running locally they DTRT except of course retrieving full revision content when they shouldn't. If you run into trouble, please holler.

To test, you want:

Here is the 'stubs' (metadata dump only) command you would run (adjust for your own paths and versions and so on), no python dumps scripts needed:
/usr/bin/php5 /srv/mediawiki/multiversion/MWScript.php extensions/Flow/maintenance/dumpBackup.php --wiki=mediawikiwiki --report=1000 --output=gzip:/home/catrope/mediawikiwik-flowstubshistory.xml.gz --stub --full

Matt's patch for content vs metadata retrieval that was merged is here: https://gerrit.wikimedia.org/r/#/c/376478/ but that only eliminates some of the preloading cases.
Once stub dumps can run without preloading content, we should check performance impact of the new patch before merge.

Catrope added a comment.EditedFeb 13 2018, 1:36 AM
In T172025#3962771, @ArielGlenn wrote:

So. @Catrope has generously volunteered to whack away at this. Thanks! I have tried to unbitrot my stubs patches. They should be ok, running locally they DTRT except of course retrieving full revision content when they shouldn't. If you run into trouble, please holler.

To test, you want:

The latest version of 355080 includes 362173, so I only needed the former.

/usr/bin/php5 /srv/mediawiki/multiversion/MWScript.php extensions/Flow/maintenance/dumpBackup.php --wiki=mediawikiwiki --report=1000 --output=gzip:/home/catrope/mediawikiwik-flowstubshistory.xml.gz --stub --full

I ran the Vagrant equivalent of this, which is mwscript extensions/Flow/maintenance/dumpBackup.php --wiki=wiki --report=1000 --output=gzip:/tmp/wiki-flowstubshistory.xml.gz --stub --full

Then I added debug_print_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS); die(); to Flow\Data\Storage\RevisionStorage::mergeExternalContent() right before the return statement where it calls ExternalStore::batchFetchFromURLs() (indirectly, via Merger::mergeMulti(); this is the only place where I saw it call into ExternalStore without writing). Rerunning the script gives me this backtrace:

vagrant@vagrant:/vagrant/mediawiki$ mwscript extensions/Flow/maintenance/dumpBackup.php --wiki=wiki --report=1000 --output=gzip:/tmp/wiki-flowstubshistory.xml.gz --stub --full
#0  Flow\Data\Storage\RevisionStorage::mergeExternalContent() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Storage/RevisionStorage.php:172]
#1  Flow\Data\Storage\RevisionStorage->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:465]
#2  Flow\Data\Index\FeatureIndex->backingStoreFindMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:280]
#3  Flow\Data\Index\FeatureIndex->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:89]
#4  Flow\Data\ObjectLocator->findMulti()
#5  call_user_func_array() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ManagerGroup.php:128]
#6  Flow\Data\ManagerGroup->call() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ManagerGroup.php:145]
#7  Flow\Data\ManagerGroup->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Repository/RootPostLoader.php:107]
#8  Flow\Repository\RootPostLoader->getMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Repository/RootPostLoader.php:87]
#9  Flow\Repository\RootPostLoader->get() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/TopicIterator.php:115]
#10 Flow\Search\Iterators\TopicIterator->transform() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/AbstractIterator.php:154]
#11 Flow\Search\Iterators\AbstractIterator->next() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/AbstractIterator.php:134]
#12 Flow\Search\Iterators\AbstractIterator->rewind() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:202]
#13 Flow\Dump\Exporter->formatWorkflow() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:182]
#14 Flow\Dump\Exporter->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:89]
#15 FlowDumpBackup->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:60]
#16 FlowDumpBackup->execute() called at [/vagrant/mediawiki/maintenance/doMaintenance.php:94]
#17 require_once(/vagrant/mediawiki/maintenance/doMaintenance.php) called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:133]
#18 require_once(/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php) called at [/var/www/w/MWScript.php:95]

(I added DEBUG_BACKTRACE_IGNORE_ARGS because without it, the backtrace is ~5MB.)

I'll try to figure out what this means and how to solve it next.

Catrope added a comment.Feb 13 2018, 1:45 AM

I ran it again without die();, and captured two other backtraces as well:

#0  Flow\Data\Storage\RevisionStorage::mergeExternalContent() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Storage/RevisionStorage.php:172]
#1  Flow\Data\Storage\RevisionStorage->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:465]
#2  Flow\Data\Index\FeatureIndex->backingStoreFindMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:280]
#3  Flow\Data\Index\FeatureIndex->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Compactor/ShallowCompactor.php:96]
#4  Flow\Data\Compactor\ShallowCompactor->expandCacheResult() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:328]
#5  Flow\Data\Index\FeatureIndex->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:89]
#6  Flow\Data\ObjectLocator->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:64]
#7  Flow\Data\ObjectLocator->find() called at [/vagrant/mediawiki/extensions/Flow/includes/Collection/AbstractCollection.php:142]
#8  Flow\Collection\AbstractCollection->getAllRevisions() called at [/vagrant/mediawiki/extensions/Flow/includes/Collection/LocalCacheAbstractCollection.php:32]
#9  Flow\Collection\LocalCacheAbstractCollection->getAllRevisions() called at [/vagrant/mediawiki/extensions/Flow/includes/Collection/LocalCacheAbstractCollection.php:120]
#10 Flow\Collection\LocalCacheAbstractCollection->getLastRevision() called at [/vagrant/mediawiki/extensions/Flow/includes/Collection/CollectionCache.php:44]
#11 Flow\Collection\CollectionCache->getLastRevisionFor() called at [/vagrant/mediawiki/extensions/Flow/includes/RevisionActionPermissions.php:93]
#12 Flow\RevisionActionPermissions->isAllowed() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:446]
#13 Flow\Dump\Exporter->isAllowed() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:254]
#14 Flow\Dump\Exporter->formatPost() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:270]
#15 Flow\Dump\Exporter->formatPost() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:221]
#16 Flow\Dump\Exporter->formatTopic() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:204]
#17 Flow\Dump\Exporter->formatWorkflow() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:182]
#18 Flow\Dump\Exporter->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:89]
#19 FlowDumpBackup->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:60]
#20 FlowDumpBackup->execute() called at [/vagrant/mediawiki/maintenance/doMaintenance.php:94]
#21 require_once(/vagrant/mediawiki/maintenance/doMaintenance.php) called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:133]
#22 require_once(/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php) called at [/var/www/w/MWScript.php:95]

#0  Flow\Data\Storage\RevisionStorage::mergeExternalContent() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Storage/RevisionStorage.php:172]
#1  Flow\Data\Storage\RevisionStorage->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:465]
#2  Flow\Data\Index\FeatureIndex->backingStoreFindMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:280]
#3  Flow\Data\Index\FeatureIndex->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:89]
#4  Flow\Data\ObjectLocator->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:64]
#5  Flow\Data\ObjectLocator->find() called at [/vagrant/mediawiki/extensions/Flow/includes/Collection/AbstractCollection.php:142]
#6  Flow\Collection\AbstractCollection->getAllRevisions() called at [/vagrant/mediawiki/extensions/Flow/includes/Collection/LocalCacheAbstractCollection.php:32]
#7  Flow\Collection\LocalCacheAbstractCollection->getAllRevisions() called at [/vagrant/mediawiki/extensions/Flow/includes/Collection/LocalCacheAbstractCollection.php:120]
#8  Flow\Collection\LocalCacheAbstractCollection->getLastRevision() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:227]
#9  Flow\Dump\Exporter->formatTopic() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:204]
#10 Flow\Dump\Exporter->formatWorkflow() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:182]
#11 Flow\Dump\Exporter->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:89]
#12 FlowDumpBackup->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:60]
#13 FlowDumpBackup->execute() called at [/vagrant/mediawiki/maintenance/doMaintenance.php:94]
#14 require_once(/vagrant/mediawiki/maintenance/doMaintenance.php) called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:133]
#15 require_once(/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php) called at [/var/www/w/MWScript.php:95]

with the latter one happening twice, but that's probably because of what my test data looks like.

ArielGlenn added a comment.Feb 28 2018, 10:52 PM

From chat on irc: @Catrope tells me it will likely be about two weeks before he's able to have a look at this again.

Catrope added a comment.Mar 5 2018, 8:46 PM

Matt informed me that he has a patch that aims to fix this: https://gerrit.wikimedia.org/r/#/c/370154/ . I cherry-picked Ariel's patch (https://gerrit.wikimedia.org/r/#/c/355080/) on top of that locally, and downloaded Ariel's core patch (https://gerrit.wikimedia.org/r/#/c/355085/). Some of these patches are based on quite outdated versions of core/Flow, so I'll rebase them soon, but I wanted to try them out first.

With that, I ran the dump script and got the following (distinct) backtraces for code trying to access ExternalStore:

vagrant@vagrant:~$ mwscript extensions/Flow/maintenance/dumpBackup.php --wiki=wiki --report=1000 --output=gzip:/tmp/wiki-flowstubshistory.xml.gz --stub --full
#0  Flow\Data\Storage\RevisionStorage::mergeExternalContent() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Storage/RevisionStorage.php:190]
#1  Flow\Data\Storage\RevisionStorage->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:481]
#2  Flow\Data\Index\FeatureIndex->backingStoreFindMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:300]
#3  Flow\Data\Index\FeatureIndex->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:89]
#4  Flow\Data\ObjectLocator->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:199]
#5  Flow\Data\ObjectLocator->getMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:174]
#6  Flow\Data\ObjectLocator->get() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/AbstractIterator.php:187]
#7  Flow\Search\Iterators\AbstractIterator->transform() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/AbstractIterator.php:154]
#8  Flow\Search\Iterators\AbstractIterator->next() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/AbstractIterator.php:134]
#9  Flow\Search\Iterators\AbstractIterator->rewind() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:198]
#10 Flow\Dump\Exporter->formatWorkflow() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:182]
#11 Flow\Dump\Exporter->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:89]
#12 FlowDumpBackup->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:60]
#13 FlowDumpBackup->execute() called at [/vagrant/mediawiki/maintenance/doMaintenance.php:94]
#14 require_once(/vagrant/mediawiki/maintenance/doMaintenance.php) called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:133]
#15 require_once(/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php) called at [/var/www/w/MWScript.php:95]

#0  Flow\Data\Storage\RevisionStorage::mergeExternalContent() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Storage/RevisionStorage.php:190]
#1  Flow\Data\Storage\RevisionStorage->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:481]
#2  Flow\Data\Index\FeatureIndex->backingStoreFindMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:300]
#3  Flow\Data\Index\FeatureIndex->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:89]
#4  Flow\Data\ObjectLocator->findMulti()
#5  call_user_func_array() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ManagerGroup.php:128]
#6  Flow\Data\ManagerGroup->call() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ManagerGroup.php:145]
#7  Flow\Data\ManagerGroup->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Repository/RootPostLoader.php:107]
#8  Flow\Repository\RootPostLoader->getMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Repository/RootPostLoader.php:87]
#9  Flow\Repository\RootPostLoader->get() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/TopicIterator.php:115]
#10 Flow\Search\Iterators\TopicIterator->transform() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/AbstractIterator.php:154]
#11 Flow\Search\Iterators\AbstractIterator->next() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/AbstractIterator.php:134]
#12 Flow\Search\Iterators\AbstractIterator->rewind() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:202]
#13 Flow\Dump\Exporter->formatWorkflow() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:182]
#14 Flow\Dump\Exporter->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:89]
#15 FlowDumpBackup->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:60]
#16 FlowDumpBackup->execute() called at [/vagrant/mediawiki/maintenance/doMaintenance.php:94]
#17 require_once(/vagrant/mediawiki/maintenance/doMaintenance.php) called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:133]
#18 require_once(/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php) called at [/var/www/w/MWScript.php:95]

#0  Flow\Data\Storage\RevisionStorage::mergeExternalContent() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Storage/RevisionStorage.php:190]
#1  Flow\Data\Storage\RevisionStorage->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:481]
#2  Flow\Data\Index\FeatureIndex->backingStoreFindMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/Index/FeatureIndex.php:300]
#3  Flow\Data\Index\FeatureIndex->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ObjectLocator.php:89]
#4  Flow\Data\ObjectLocator->findMulti()
#5  call_user_func_array() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ManagerGroup.php:128]
#6  Flow\Data\ManagerGroup->call() called at [/vagrant/mediawiki/extensions/Flow/includes/Data/ManagerGroup.php:145]
#7  Flow\Data\ManagerGroup->findMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Repository/RootPostLoader.php:107]
#8  Flow\Repository\RootPostLoader->getMulti() called at [/vagrant/mediawiki/extensions/Flow/includes/Repository/RootPostLoader.php:87]
#9  Flow\Repository\RootPostLoader->get() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/TopicIterator.php:115]
#10 Flow\Search\Iterators\TopicIterator->transform() called at [/vagrant/mediawiki/extensions/Flow/includes/Search/Iterators/AbstractIterator.php:154]
#11 Flow\Search\Iterators\AbstractIterator->next() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:202]
#12 Flow\Dump\Exporter->formatWorkflow() called at [/vagrant/mediawiki/extensions/Flow/includes/Dump/Exporter.php:182]
#13 Flow\Dump\Exporter->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:89]
#14 FlowDumpBackup->dump() called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:60]
#15 FlowDumpBackup->execute() called at [/vagrant/mediawiki/maintenance/doMaintenance.php:94]
#16 require_once(/vagrant/mediawiki/maintenance/doMaintenance.php) called at [/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php:133]
#17 require_once(/vagrant/mediawiki/extensions/Flow/maintenance/dumpBackup.php) called at [/var/www/w/MWScript.php:95]
Catrope added a comment.Mar 6 2018, 12:09 AM

Interesting behavior I found while testing this: if you have memcached set up, then the 3rd run doesn't hit ExternalStore at all. The 2nd run does, via Flow\Data\Compactor\ShallowCompactor->expandCacheResult().

I now have an experimental local change that reduces the number of ES accesses on an empty cache from 5 to 2.

Catrope added a comment.Mar 6 2018, 12:50 AM

I got Matt's patch working with some minor tweaks. I'll amend it and then work on rebasing it.

Catrope added a comment.Mar 6 2018, 7:00 AM

I have finished amending and rebasing Matt's patch (https://gerrit.wikimedia.org/r/#/c/370154/), and as far as I can tell it's working. My debug statements flagging external storage fetches are no longer being hit.

I've also rebased @ArielGlenn's patch (https://gerrit.wikimedia.org/r/#/c/355080/) on top of Matt's patch, so that to test you only need to download that one (and the MW core one that it depends on). Right now Jenkins complains on Ariel's Flow patch because the MW patch is not mergeable, but I didn't have time to try to rebase that one today.

ArielGlenn added a comment.Mar 12 2018, 5:01 PM

I tried testing on a locally patched Flow + mw-core on snapshot01 beta, and I got an attempt to load from ext store but it's inconclusive, especially because it generated an exception at the crucial point instead of actually retrieving the content. I need to look at it further, might be a problem with the testing setup. I will get back to this tomorrow and let you know one way or the other.

Catrope added a comment.Mar 12 2018, 8:22 PM
In T172025#4043845, @ArielGlenn wrote:

I tried testing on a locally patched Flow + mw-core on snapshot01 beta, and I got an attempt to load from ext store but it's inconclusive, especially because it generated an exception at the crucial point instead of actually retrieving the content. I need to look at it further, might be a problem with the testing setup. I will get back to this tomorrow and let you know one way or the other.

Thanks. If you do see it loading content from ES, a backtrace would be most helpful if you can get one. (See T172025#3965821 for how I did that, although you may instead want/need to trigger the backtrace inside the ES code itself, I was just being lazy.)

ArielGlenn added a comment.Mar 13 2018, 1:41 PM

Welp. I have tried a few times, and while I am not at all confident about the es setup on beta, I am confident that this is a legit attempt to retrieve something from es when it oughtn't.

#0 /srv/mediawiki/php-master/extensions/Flow/includes/Model/AbstractRevision.php(413): Flow\Data\Storage\RevisionStorage::loadExternalContentIntoRevision(Flow\Model\Header, string)
#1 /srv/mediawiki/php-master/extensions/Flow/includes/Model/AbstractRevision.php(249): Flow\Model\AbstractRevision->getLoadedContent()
#2 /srv/mediawiki/php-master/extensions/Flow/includes/Dump/Exporter.php(380): Flow\Model\AbstractRevision::toStorageRow(Flow\Model\Header)
#3 /srv/mediawiki/php-master/extensions/Flow/includes/Dump/Exporter.php(368): Flow\Dump\Exporter->formatRevision(Flow\Model\Header)
#4 /srv/mediawiki/php-master/extensions/Flow/includes/Dump/Exporter.php(247): Flow\Dump\Exporter->formatRevisions(Flow\Model\Header)
#5 /srv/mediawiki/php-master/extensions/Flow/includes/Dump/Exporter.php(200): Flow\Dump\Exporter->formatHeader(Flow\Model\Header)
#6 /srv/mediawiki/php-master/extensions/Flow/includes/Dump/Exporter.php(182): Flow\Dump\Exporter->formatWorkflow(Flow\Model\Workflow, Flow\Search\Iterators\HeaderIterator, Flow\Search\Iterators\TopicIterator)
#7 /srv/mediawiki/php-master/extensions/Flow/maintenance/dumpBackup.php(89): Flow\Dump\Exporter->dump(BatchRowIterator)
#8 /srv/mediawiki/php-master/extensions/Flow/maintenance/dumpBackup.php(62): FlowDumpBackup->dump(integer, integer)
#9 /srv/mediawiki/php-master/maintenance/doMaintenance.php(94): FlowDumpBackup->execute()
#10 /srv/mediawiki/php-master/extensions/Flow/maintenance/dumpBackup.php(133): require_once(string)
#11 /srv/mediawiki/multiversion/MWScript.php(100): require_once(string)

So it looks like $revision->toStorageRow is doing more than it should. In there, I see 'rev_content' => $obj->getLoadedContent(), which shouldn't really load content every time, or we will never just be able to get the metadata.

For the particular revision in beta enwiki, the url from external store which causes this to barf is nothing like a url, it looks like it might be the actual compressed text content, but I'm skipping over the foibles of the testing platform for now.

This is with Flow with Ic893f2567f16c11a293e0bd5ac49f46db5324854 and then I787a26ff6004a875b71ef38905904b7c489f22d4 cherry-picked on top of those, and mw core master with I9b3c54503dd9ad193af7765459613a7e73ffbb45 cherry-picked on top of that, and running on deployment-snapshot01:

sudo -u www-data MW_DEBUG_LOCAL="yes" /usr/bin/php7.0 multiversion/MWScript.php extensions/Flow/maintenance/dumpBackup.php --wiki=enwiki --current --report=1000 --output=bzip2:/tmp/flow-stuff.bz2 --stub

which has a few debugging statements I've added, logs go to /tmp/wiki.log.

ArielGlenn added a comment.Mar 23 2018, 9:47 AM

Roan is hoping to get back to this next week.

Catrope added a comment.Mar 23 2018, 10:36 PM

I was able to reproduce this once I realized that my setup was non-ES (and so I needed to put my backtrace in getLoadedContent instead of loadExternalContentIntoRevision). It looks like toStorageRow isn't up-to-date with the smartness that Matt added to fromStorageRow, so I'll try to update it.

Catrope added a comment.Mar 23 2018, 11:08 PM

I have updated https://gerrit.wikimedia.org/r/370154 with a hack to allow toStorageRow() calls to bypass content loading, and have rebased https://gerrit.wikimedia.org/r/355080/ onto that and amended it to use that hack in stub mode. Let me know if that works. If it does, I might ask Stephane for advice on how this could be made less hacky before merging it, because it's ugly, and the way the dumps code uses toStorageRow() is also hacky.

ArielGlenn added a comment.Apr 12 2018, 3:09 PM

Great news! It looks like the latest set of hacks actually works. PLEASE DO NOT MERGE MY PATCHSET YET, I need to run stubs all the way through and then content dumps and make sure it all works properly now that the revision content retrieval issue is fixed. That testing is now under way.

ArielGlenn added a comment.Apr 18 2018, 1:24 PM

Hey @Catrope,

I have been running the stubs dumps on snapshot1001 for mediawikiwiki, the wiki that takes several days to generate the flow history dumps. Unfortunately, stubs for the history content take several days as well. I have enabled debug logging and have a comparison log for current revs only vs historical revs.

Before getting to the main issue, let me point out that all of the flow caching of metadata it's supposed to do to make things nice for performance, fails, because all items to be added to the WANCache are dated to the time the the initial db connection was established. This means that e.g. for a four hour run for 'current rev' stubs there are 1.5 million 'Rejected set()' messages where attempts to add to the cache fail, and naturally the db must be used to retrieve all of that missing information. I think this comes down to DBO_TRX being unset for cli scripts, which, while reasonable in the abstract, is not helping us in Flow.

The main issue now seems to be that in every getMulti(WANCache:v:flowdb:flow_revision%3Adescendant_unloaded_content...), or after it, hard to tell, and specifically after the "Rejected set()" for that item, there's a lag of a few, usually about 4, seconds where nothing is going on that's being logged. No SELECTS, nothing else. What is Flow doing for those several seconds that it doesn't need to to when grabbing current revisions? That time is killing us. it's got to be part of the isAllowed() check somehow but I can't see it.

Our testbed host may be unavailable for awhile but if that happens I can put these logs somewhere that you can look at them, if that's any help. For the moment they are in /home/ariel/flowtesting/outputs, see debuglog.txt.gz for 'current rev stubs' (works well) and debuglog.txt for 'history rev stubs' (bad behavior, and still running).

Aklapper removed • Mattflaschen-WMF as the assignee of this task.Apr 18 2018, 1:51 PM

Removing @Mattflaschen-WMF as task assignee to avoid cookie-licking.
(Matt, if you still like/plan to work on this, feel very welcome to re-claim via your personal Phab account - thanks!)

ArielGlenn added a comment.May 17 2018, 10:33 PM

This month's run is even slower than usual. To be specific, it's taken over 8 days and is still not complete. While monkeying around looking for ways to get it done quicker, I found the following interesting thing, from the flow current dump (not the history dump):

<board id="rl7iby6wgksbpfno" title="Project_talk:Sandbox/Structured_Discussions_test">
<board id="u0kgwe453ib4ons4" title="Project_talk:Sandbox/Structured_Discussions_test">

Doesn't the title correspond to a page title? How then can this be listed with two board ids?

ArielGlenn added a comment.May 17 2018, 10:37 PM

I've hacked together a script to do this month's flow history run in small batches of 50 boards at a time; it ran in three hours. Admittedly, I ran this on a php7/stretch host; I'll try tomorrow without the batching and see if there's the same slowdown I saw on the other box with php5 on it.

Still no idea why suddenly this month's run is days and days slower.

ArielGlenn added a comment.May 18 2018, 3:11 PM

Going to move the above discussion to the parent task ('make flow run faster").

ArielGlenn changed the task status from Open to Stalled.Jun 6 2018, 10:01 AM
ArielGlenn lowered the priority of this task from High to Low.

We got lucky; under php7/stretch this job runs lightning fast for whatever reason. we can look at it again much much later.

Aklapper removed a project: Collaboration-Team-Triage (Collab-Team-This-Quarter).Oct 12 2019, 4:01 AM
Restricted Application added a project: Growth-Team. · View Herald TranscriptOct 12 2019, 4:01 AM
Aklapper changed the task status from Stalled to Open.May 22 2020, 3:58 PM
In T172025#4260419, @ArielGlenn wrote:

We got lucky; under php7/stretch this job runs lightning fast for whatever reason. we can look at it again much much later.

Assuming that two years later under PHP7 it could be time to look at it again, hence resetting task status.

MBinder_WMF added a project: Growth-Team-Filtering.Apr 15 2021, 6:56 PM
Pppery edited projects, added Patch-Needs-Improvement; removed Patch-For-Review.Apr 1 2023, 7:49 PM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits