Page MenuHomePhabricator

DiscussionTools CI is failing
Closed, ResolvedPublic

Description

DiscussionTools PHPUnit integration tests are failing causing CI failures on that extension and on the ReportIncident extension:

21:22:02 There were 7 failures:
21:22:02 
21:22:02 1) MediaWiki\Extension\DiscussionTools\Tests\ThreadItemStoreTest::testInsertThreadItems with data set #0 ('cases/ThreadItemStore/1simple-example')
21:22:02 Failed asserting that two arrays are equal.
21:22:02 --- Expected
21:22:02 +++ Actual
21:22:02 @@ @@
21:22:02      'discussiontools_items' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_pages' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_revisions' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02          2 => Array (
21:22:02 -            'itr_id' => '5'
21:22:02 -            'itr_itemid_id' => '3'
21:22:02 -            'itr_revision_id' => '2'
21:22:02 -            'itr_items_id' => '3'
21:22:02 -            'itr_parent_id' => '4'
21:22:02 -            'itr_transcludedfrom' => null
21:22:02 -            'itr_level' => '2'
21:22:02 -            'itr_headinglevel' => null
21:22:02 -        )
21:22:02 -        3 => Array (
21:22:02              'itr_id' => '3'
21:22:02              'itr_itemid_id' => '1'
21:22:02              'itr_revision_id' => '3'
21:22:02 @@ @@
21:22:02              'itr_level' => '0'
21:22:02              'itr_headinglevel' => '2'
21:22:02          )
21:22:02 -        4 => Array (...)
21:22:02 -        5 => Array (...)
21:22:02 -        6 => Array (...)
21:22:02 +        3 => Array (
21:22:02 +            'itr_id' => '4'
21:22:02 +            'itr_itemid_id' => '2'
21:22:02 +            'itr_revision_id' => '3'
21:22:02 +            'itr_items_id' => '2'
21:22:02 +            'itr_parent_id' => '3'
21:22:02 +            'itr_transcludedfrom' => null
21:22:02 +            'itr_level' => '1'
21:22:02 +            'itr_headinglevel' => null
21:22:02 +        )
21:22:02      )
21:22:02      'discussiontools_item_ids' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02      )
21:22:02  )
21:22:02 
21:22:02 /workspace/src/extensions/DiscussionTools/tests/phpunit/ThreadItemStoreTest.php:88
21:22:02 phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97
21:22:02 === Logs generated by test case
21:22:02 [objectcache] [debug] MainWANObjectCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [localisation] [debug] LocalisationCache using store LCStoreNull []
21:22:02 [CentralAuth] [debug] Loading state for global user {user} from DB {"user":"X"}
21:22:02 [CentralAuth] [debug] Loading attached wiki list for global user X from DB []
21:22:02 [CentralAuth] [debug] Loading groups for global user {user} {"user":"X"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:centralauth-user:02129bb861061d1a052c592e2dc6b383): miss, new value computed []
21:22:02 [CentralAuth] [debug] Loading CentralAuthUser for user {user} from cache object {"user":"X"}
21:22:02 [CentralAuth] [debug] Loading state for global user {user} from DB {"user":"Y"}
21:22:02 [CentralAuth] [debug] Loading attached wiki list for global user Y from DB []
21:22:02 [CentralAuth] [debug] Loading groups for global user {user} {"user":"Y"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:centralauth-user:57cec4137b614c87cb4e24a3d003a3e0): miss, new value computed []
21:22:02 [CentralAuth] [debug] Loading CentralAuthUser for user {user} from cache object {"user":"Y"}
21:22:02 [CentralAuth] [debug] Loading state for global user {user} from DB {"user":"Z"}
21:22:02 [CentralAuth] [debug] Loading attached wiki list for global user Z from DB []
21:22:02 [CentralAuth] [debug] Loading groups for global user {user} {"user":"Z"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:centralauth-user:21c2e59531c8710156d34a3c30ac81d5): miss, new value computed []
21:22:02 [CentralAuth] [debug] Loading CentralAuthUser for user {user} from cache object {"user":"Z"}
21:22:02 [localisation] [debug] LocalisationCache::isExpired(en): cache missing, need to make one []
21:22:02 [wfDebug] [debug] ParserFactory: using default preprocessor {"private":false}
21:22:02 [ContentHandler] [info] Registered handler for wikitext: WikitextContentHandler []
21:22:02 [MessageCache] [debug] MessageCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [objectcache] [debug] MainObjectStash using store {class} {"class":"HashBagOStuff"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for pcache []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:content_models:wikidb-unittest_","lag":0,"age":0.7451488971710205,"walltime":0.0002961158752441406}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:content_models:wikidb-unittest_): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:slot_roles:wikidb-unittest_","lag":0,"age":0.7460830211639404,"walltime":0.00023221969604492188}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:slot_roles:wikidb-unittest_): miss, new value computed []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #62023 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #62023, processing time: 6.8902969360352E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":1}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202129","rev_id":1}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #51529 []
21:22:02 [wfDebug] [debug] BacklinkCache::queryLinks: got results from DB {"private":false}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore1): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore1:templatelinks","lag":0,"age":0.7603769302368164,"walltime":0.0006630420684814453}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore1:templatelinks): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid-pcache []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A118): miss, new value computed []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ban from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for crh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for iu from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ku from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for shi from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sr from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tg from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tly from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for uz from source []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"parsoid-pcache","key":"wikidb-unittest_:parsoid-pcache:idhash:1-0!useParsoid=1!en","cache_time":"20231016202129","rev_id":1}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #51529, processing time: 0.03697395324707 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #80404 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #80404, processing time: 0.00034022331237793 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #62216 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #62216, processing time: 3.3140182495117E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #50549 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #50549, processing time: 3.6001205444336E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #85417 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #85417, processing time: 0.00043702125549316 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #51529 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #51529, processing time: 0.00077199935913086 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #77400 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore1 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore1&action=history http://127.0.0.1:9413/wiki/ThreadItemStore1 http://127.0.0.1:9413/index.php?title=ThreadItemStore1&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #77400, processing time: 0.0001220703125 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #54733 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #54733, processing time: 5.2928924560547E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":2}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202129","rev_id":2}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:2): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #77001 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #77001, processing time: 0.013572931289673 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #82593 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #82593, processing time: 0.00031304359436035 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #81323 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #81323, processing time: 3.504753112793E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #78965 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #78965, processing time: 3.7193298339844E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #76887 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #76887, processing time: 0.0004119873046875 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #77001 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #77001, processing time: 0.00080299377441406 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #77184 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore1 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore1&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #77184, processing time: 9.1075897216797E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #76887 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #76887, processing time: 4.9114227294922E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #57529 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #57529, processing time: 6.3896179199219E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":3}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202129","rev_id":3}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:3): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #77184 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #77184, processing time: 0.012545824050903 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #76822 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #76822, processing time: 0.00029087066650391 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #79398 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #79398, processing time: 3.3855438232422E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #79316 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #79316, processing time: 3.6001205444336E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #83599 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #83599, processing time: 0.0003819465637207 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #77184 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #77184, processing time: 0.00069212913513184 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #62142 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore1 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore1&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #62142, processing time: 0.00011205673217773 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #83599 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #83599, processing time: 4.7922134399414E-5 []
21:22:02 ===
21:22:02 
21:22:02 2) MediaWiki\Extension\DiscussionTools\Tests\ThreadItemStoreTest::testInsertThreadItems with data set #1 ('cases/ThreadItemStore/2archiv...ection')
21:22:02 Failed asserting that two arrays are equal.
21:22:02 --- Expected
21:22:02 +++ Actual
21:22:02 @@ @@
21:22:02              'itp_items_id' => '1'
21:22:02              'itp_page_id' => '1'
21:22:02              'itp_oldest_revision_id' => '1'
21:22:02 -            'itp_newest_revision_id' => '1'
21:22:02 +            'itp_newest_revision_id' => '2'
21:22:02          )
21:22:02          1 => Array (
21:22:02              'itp_id' => '2'
21:22:02 @@ @@
21:22:02              'itp_items_id' => '2'
21:22:02              'itp_page_id' => '1'
21:22:02              'itp_oldest_revision_id' => '1'
21:22:02 -            'itp_newest_revision_id' => '1'
21:22:02 +            'itp_newest_revision_id' => '2'
21:22:02          )
21:22:02          2 => Array (...)
21:22:02          3 => Array (...)
21:22:02 @@ @@
21:22:02          2 => Array (
21:22:02              'itr_id' => '3'
21:22:02              'itr_itemid_id' => '1'
21:22:02 -            'itr_revision_id' => '3'
21:22:02 +            'itr_revision_id' => '2'
21:22:02              'itr_items_id' => '1'
21:22:02              'itr_parent_id' => null
21:22:02              'itr_transcludedfrom' => null
21:22:02 @@ @@
21:22:02          3 => Array (
21:22:02              'itr_id' => '4'
21:22:02              'itr_itemid_id' => '2'
21:22:02 -            'itr_revision_id' => '3'
21:22:02 +            'itr_revision_id' => '2'
21:22:02              'itr_items_id' => '2'
21:22:02              'itr_parent_id' => '3'
21:22:02              'itr_transcludedfrom' => null
21:22:02 @@ @@
21:22:02              'itr_level' => '1'
21:22:02              'itr_headinglevel' => null
21:22:02          )
21:22:02 +        4 => Array (...)
21:22:02 +        5 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_ids' => Array (...)
21:22:02  )
21:22:02 
21:22:02 /workspace/src/extensions/DiscussionTools/tests/phpunit/ThreadItemStoreTest.php:88
21:22:02 phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97
21:22:02 === Logs generated by test case
21:22:02 [objectcache] [debug] MainWANObjectCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [localisation] [debug] LocalisationCache using store LCStoreNull []
21:22:02 [localisation] [debug] LocalisationCache::isExpired(en): cache missing, need to make one []
21:22:02 [wfDebug] [debug] ParserFactory: using default preprocessor {"private":false}
21:22:02 [ContentHandler] [info] Registered handler for wikitext: WikitextContentHandler []
21:22:02 [MessageCache] [debug] MessageCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [objectcache] [debug] MainObjectStash using store {class} {"class":"HashBagOStuff"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for pcache []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:content_models:wikidb-unittest_","lag":0,"age":0.8761529922485352,"walltime":0.0002319812774658203}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:content_models:wikidb-unittest_): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:slot_roles:wikidb-unittest_","lag":0,"age":0.87717604637146,"walltime":0.00023889541625976562}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:slot_roles:wikidb-unittest_): miss, new value computed []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #81395 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #81395, processing time: 6.413459777832E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":1}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202129","rev_id":1}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #74917 []
21:22:02 [wfDebug] [debug] BacklinkCache::queryLinks: got results from DB {"private":false}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore2): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore2:templatelinks","lag":0,"age":0.8917860984802246,"walltime":0.0006489753723144531}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore2:templatelinks): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore2): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid-pcache []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A121): miss, new value computed []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ban from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for crh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for iu from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ku from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for shi from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sr from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tg from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tly from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for uz from source []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"parsoid-pcache","key":"wikidb-unittest_:parsoid-pcache:idhash:1-0!useParsoid=1!en","cache_time":"20231016202129","rev_id":1}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #74917, processing time: 0.098199844360352 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #83030 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #83030, processing time: 0.00036501884460449 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #39214 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #39214, processing time: 3.4093856811523E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #74918 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #74918, processing time: 3.814697265625E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #82677 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #82677, processing time: 0.00044608116149902 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #74917 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #74917, processing time: 0.00078678131103516 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #83083 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore2 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore2&action=history http://127.0.0.1:9413/wiki/ThreadItemStore2 http://127.0.0.1:9413/index.php?title=ThreadItemStore2&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #83083, processing time: 9.7990036010742E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #83026 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #83026, processing time: 6.2942504882812E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":3}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":2}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:2): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #83007 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore2): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #83007, processing time: 0.017160892486572 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #84520 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #84520, processing time: 0.0003049373626709 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #85848 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #85848, processing time: 3.2901763916016E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #78378 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #78378, processing time: 3.6001205444336E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #83937 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #83937, processing time: 0.00062108039855957 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #83007 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #83007, processing time: 0.0010030269622803 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #74175 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore2 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore2&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #74175, processing time: 8.702278137207E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #83937 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #83937, processing time: 4.7206878662109E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #84714 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #84714, processing time: 5.6982040405273E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:2-0!canonical!en","cache_time":"20231016202130","rev_id":3}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:3): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #46064 []
21:22:02 [wfDebug] [debug] BacklinkCache::queryLinks: got results from DB {"private":false}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore2/Archive): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore2\/Archive:templatelinks","lag":0,"age":0.0547940731048584,"walltime":0.0009899139404296875}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore2/Archive:templatelinks): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore2/Archive): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A123): miss, new value computed []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"parsoid-pcache","key":"wikidb-unittest_:parsoid-pcache:idhash:2-0!useParsoid=1!en","cache_time":"20231016202130","rev_id":3}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #46064, processing time: 0.042388916015625 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #62963 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #62963, processing time: 0.00053906440734863 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #75963 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #75963, processing time: 5.1975250244141E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #78629 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #78629, processing time: 5.5074691772461E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #84625 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #84625, processing time: 0.00061202049255371 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #46064 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #46064, processing time: 0.00088119506835938 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #71437 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore2/Archive http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore2/Archive&action=history http://127.0.0.1:9413/wiki/ThreadItemStore2/Archive http://127.0.0.1:9413/index.php?title=ThreadItemStore2/Archive&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #71437, processing time: 0.00014615058898926 []
21:22:02 ===
21:22:02 
21:22:02 3) MediaWiki\Extension\DiscussionTools\Tests\ThreadItemStoreTest::testInsertThreadItems with data set #3 ('cases/ThreadItemStore/4transc...ection')
21:22:02 Failed asserting that two arrays are equal.
21:22:02 --- Expected
21:22:02 +++ Actual
21:22:02 @@ @@
21:22:02          1 => Array (...)
21:22:02          2 => Array (
21:22:02              'itp_id' => '3'
21:22:02 -            'itp_items_id' => '3'
21:22:02 -            'itp_page_id' => '1'
21:22:02 -            'itp_oldest_revision_id' => '2'
21:22:02 -            'itp_newest_revision_id' => '2'
21:22:02 +            'itp_items_id' => '1'
21:22:02 +            'itp_page_id' => '2'
21:22:02 +            'itp_oldest_revision_id' => '3'
21:22:02 +            'itp_newest_revision_id' => '3'
21:22:02          )
21:22:02          3 => Array (
21:22:02              'itp_id' => '4'
21:22:02 -            'itp_items_id' => '1'
21:22:02 +            'itp_items_id' => '2'
21:22:02              'itp_page_id' => '2'
21:22:02              'itp_oldest_revision_id' => '3'
21:22:02              'itp_newest_revision_id' => '3'
21:22:02 @@ @@
21:22:02          )
21:22:02          4 => Array (
21:22:02              'itp_id' => '5'
21:22:02 -            'itp_items_id' => '2'
21:22:02 +            'itp_items_id' => '3'
21:22:02              'itp_page_id' => '2'
21:22:02              'itp_oldest_revision_id' => '3'
21:22:02              'itp_newest_revision_id' => '3'
21:22:02          )
21:22:02 -        5 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_revisions' => Array (
21:22:02          0 => Array (...)
21:22:02 @@ @@
21:22:02          3 => Array (...)
21:22:02          4 => Array (
21:22:02              'itr_id' => '5'
21:22:02 -            'itr_itemid_id' => '3'
21:22:02 -            'itr_revision_id' => '2'
21:22:02 -            'itr_items_id' => '3'
21:22:02 -            'itr_parent_id' => '4'
21:22:02 -            'itr_transcludedfrom' => null
21:22:02 -            'itr_level' => '2'
21:22:02 -            'itr_headinglevel' => null
21:22:02 -        )
21:22:02 -        5 => Array (
21:22:02 -            'itr_id' => '6'
21:22:02              'itr_itemid_id' => '1'
21:22:02              'itr_revision_id' => '3'
21:22:02              'itr_items_id' => '1'
21:22:02 @@ @@
21:22:02              'itr_level' => '0'
21:22:02              'itr_headinglevel' => '2'
21:22:02          )
21:22:02 +        5 => Array (
21:22:02 +            'itr_id' => '6'
21:22:02 +            'itr_itemid_id' => '2'
21:22:02 +            'itr_revision_id' => '3'
21:22:02 +            'itr_items_id' => '2'
21:22:02 +            'itr_parent_id' => '5'
21:22:02 +            'itr_transcludedfrom' => '1'
21:22:02 +            'itr_level' => '1'
21:22:02 +            'itr_headinglevel' => null
21:22:02 +        )
21:22:02          6 => Array (
21:22:02              'itr_id' => '7'
21:22:02 -            'itr_itemid_id' => '2'
21:22:02 +            'itr_itemid_id' => '3'
21:22:02              'itr_revision_id' => '3'
21:22:02 -            'itr_items_id' => '2'
21:22:02 +            'itr_items_id' => '3'
21:22:02              'itr_parent_id' => '6'
21:22:02              'itr_transcludedfrom' => '1'
21:22:02 -            'itr_level' => '1'
21:22:02 +            'itr_level' => '2'
21:22:02              'itr_headinglevel' => null
21:22:02          )
21:22:02 -        7 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_ids' => Array (...)
21:22:02  )
21:22:02 
21:22:02 /workspace/src/extensions/DiscussionTools/tests/phpunit/ThreadItemStoreTest.php:88
21:22:02 phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97
21:22:02 === Logs generated by test case
21:22:02 [objectcache] [debug] MainWANObjectCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [localisation] [debug] LocalisationCache using store LCStoreNull []
21:22:02 [localisation] [debug] LocalisationCache::isExpired(en): cache missing, need to make one []
21:22:02 [wfDebug] [debug] ParserFactory: using default preprocessor {"private":false}
21:22:02 [ContentHandler] [info] Registered handler for wikitext: WikitextContentHandler []
21:22:02 [MessageCache] [debug] MessageCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [objectcache] [debug] MainObjectStash using store {class} {"class":"HashBagOStuff"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for pcache []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:content_models:wikidb-unittest_","lag":0,"age":0.22696805000305176,"walltime":0.00021886825561523438}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:content_models:wikidb-unittest_): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:slot_roles:wikidb-unittest_","lag":0,"age":0.22783493995666504,"walltime":0.00020503997802734375}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:slot_roles:wikidb-unittest_): miss, new value computed []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #42832 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #42832, processing time: 8.8930130004883E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":1}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":1}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #83890 []
21:22:02 [wfDebug] [debug] BacklinkCache::queryLinks: got results from DB {"private":false}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore4/b): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore4/b:templatelinks): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore4/b): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid-pcache []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A126): miss, new value computed []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ban from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for crh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for iu from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ku from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for shi from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sr from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tg from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tly from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for uz from source []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"parsoid-pcache","key":"wikidb-unittest_:parsoid-pcache:idhash:1-0!useParsoid=1!en","cache_time":"20231016202130","rev_id":1}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #83890, processing time: 0.031677007675171 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #76094 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #76094, processing time: 8.4877014160156E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #74965 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #74965, processing time: 3.8862228393555E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #71645 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #71645, processing time: 0.00039410591125488 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #83890 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #83890, processing time: 0.00066399574279785 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #80583 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore4/b http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore4/b&action=history http://127.0.0.1:9413/wiki/ThreadItemStore4/b http://127.0.0.1:9413/index.php?title=ThreadItemStore4/b&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #80583, processing time: 9.4890594482422E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #76643 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #76643, processing time: 4.2915344238281E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":2}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":2}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:2): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #42171 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore4/b): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #42171, processing time: 0.011695146560669 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #85605 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #85605, processing time: 0.00027680397033691 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #85603 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #85603, processing time: 5.9843063354492E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #85255 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #85255, processing time: 3.2901763916016E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #74573 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #74573, processing time: 0.00036406517028809 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #42171 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #42171, processing time: 0.00060009956359863 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #85521 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore4/b http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore4/b&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #85521, processing time: 8.3208084106445E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #74573 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #74573, processing time: 4.2915344238281E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #85577 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #85577, processing time: 4.6968460083008E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":3}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:revision-row-1.29:wikidb-unittest_:1:2): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A127): miss, new value computed []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:2-0!canonical!en","cache_time":"20231016202130","rev_id":3}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:3): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #84729 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:Talk%3AThreadItemStore4/b): miss, new value computed []
21:22:02 [wfDebug] [debug] BacklinkCache::queryLinks: got results from DB {"private":false}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore4): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore4:templatelinks","lag":0,"age":0.31272196769714355,"walltime":0.0006220340728759766}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore4:templatelinks): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore4): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A128): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A127): process cache hit []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"parsoid-pcache","key":"wikidb-unittest_:parsoid-pcache:idhash:2-0!useParsoid=1!en","cache_time":"20231016202130","rev_id":3}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #84729, processing time: 0.028931856155396 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #85502 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #85502, processing time: 0.00027608871459961 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #82014 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #82014, processing time: 3.1948089599609E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #73274 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #73274, processing time: 3.504753112793E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #84407 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #84407, processing time: 0.00047612190246582 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #84729 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #84729, processing time: 0.00085902214050293 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #79265 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore4 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore4&action=history http://127.0.0.1:9413/wiki/ThreadItemStore4 http://127.0.0.1:9413/index.php?title=ThreadItemStore4&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #79265, processing time: 9.7990036010742E-5 []
21:22:02 ===
21:22:02 
21:22:02 4) MediaWiki\Extension\DiscussionTools\Tests\ThreadItemStoreTest::testInsertThreadItems with data set #4 ('cases/ThreadItemStore/5change...tation')
21:22:02 Failed asserting that two arrays are equal.
21:22:02 --- Expected
21:22:02 +++ Actual
21:22:02 @@ @@
21:22:02      'discussiontools_items' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_pages' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_revisions' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02          2 => Array (
21:22:02 -            'itr_id' => '5'
21:22:02 -            'itr_itemid_id' => '3'
21:22:02 -            'itr_revision_id' => '2'
21:22:02 -            'itr_items_id' => '3'
21:22:02 -            'itr_parent_id' => '4'
21:22:02 +            'itr_id' => '3'
21:22:02 +            'itr_itemid_id' => '1'
21:22:02 +            'itr_revision_id' => '4'
21:22:02 +            'itr_items_id' => '1'
21:22:02 +            'itr_parent_id' => null
21:22:02              'itr_transcludedfrom' => null
21:22:02 -            'itr_level' => '2'
21:22:02 -            'itr_headinglevel' => null
21:22:02 +            'itr_level' => '0'
21:22:02 +            'itr_headinglevel' => '2'
21:22:02          )
21:22:02          3 => Array (
21:22:02 -            'itr_id' => '7'
21:22:02 -            'itr_itemid_id' => '4'
21:22:02 -            'itr_revision_id' => '3'
21:22:02 -            'itr_items_id' => '4'
21:22:02 -            'itr_parent_id' => '6'
21:22:02 +            'itr_id' => '4'
21:22:02 +            'itr_itemid_id' => '2'
21:22:02 +            'itr_revision_id' => '4'
21:22:02 +            'itr_items_id' => '2'
21:22:02 +            'itr_parent_id' => '3'
21:22:02              'itr_transcludedfrom' => null
21:22:02 -            'itr_level' => '3'
21:22:02 +            'itr_level' => '1'
21:22:02              'itr_headinglevel' => null
21:22:02          )
21:22:02 -        4 => Array (...)
21:22:02 -        5 => Array (...)
21:22:02 -        6 => Array (...)
21:22:02 -        7 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_ids' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02 -        4 => Array (...)
21:22:02      )
21:22:02  )
21:22:02 
21:22:02 /workspace/src/extensions/DiscussionTools/tests/phpunit/ThreadItemStoreTest.php:88
21:22:02 phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97
21:22:02 === Logs generated by test case
21:22:02 [objectcache] [debug] MainWANObjectCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [localisation] [debug] LocalisationCache using store LCStoreNull []
21:22:02 [localisation] [debug] LocalisationCache::isExpired(en): cache missing, need to make one []
21:22:02 [wfDebug] [debug] ParserFactory: using default preprocessor {"private":false}
21:22:02 [ContentHandler] [info] Registered handler for wikitext: WikitextContentHandler []
21:22:02 [MessageCache] [debug] MessageCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [objectcache] [debug] MainObjectStash using store {class} {"class":"HashBagOStuff"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for pcache []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:content_models:wikidb-unittest_","lag":0,"age":0.371229887008667,"walltime":0.0002620220184326172}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:content_models:wikidb-unittest_): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:slot_roles:wikidb-unittest_","lag":0,"age":0.3722360134124756,"walltime":0.0002560615539550781}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:slot_roles:wikidb-unittest_): miss, new value computed []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #82044 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #82044, processing time: 6.103515625E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":1}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":1}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #44136 []
21:22:02 [wfDebug] [debug] BacklinkCache::queryLinks: got results from DB {"private":false}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore5): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore5:templatelinks","lag":0,"age":0.4512910842895508,"walltime":0.0006279945373535156}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore5:templatelinks): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore5): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid-pcache []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A129): miss, new value computed []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ban from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for crh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for iu from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ku from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for shi from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sr from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tg from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tly from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for uz from source []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"parsoid-pcache","key":"wikidb-unittest_:parsoid-pcache:idhash:1-0!useParsoid=1!en","cache_time":"20231016202130","rev_id":1}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #44136, processing time: 0.033777952194214 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #81777 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #81777, processing time: 0.00030088424682617 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #74106 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #74106, processing time: 0.00011706352233887 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #82967 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #82967, processing time: 4.1961669921875E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #80238 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #80238, processing time: 0.00050806999206543 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #44136 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #44136, processing time: 0.00081992149353027 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #81926 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore5 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore5&action=history http://127.0.0.1:9413/wiki/ThreadItemStore5 http://127.0.0.1:9413/index.php?title=ThreadItemStore5&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #81926, processing time: 9.3936920166016E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #81585 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #81585, processing time: 4.3869018554688E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":2}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":2}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:2): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #80291 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore5): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #80291, processing time: 0.016330003738403 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #85541 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #85541, processing time: 0.00026893615722656 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #81349 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #81349, processing time: 3.0040740966797E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #62751 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #62751, processing time: 3.504753112793E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #77144 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #77144, processing time: 0.0004878044128418 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #80291 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #80291, processing time: 0.00090694427490234 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #81887 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore5 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore5&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #81887, processing time: 9.0122222900391E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #77144 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #77144, processing time: 4.6014785766602E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #79966 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #79966, processing time: 4.4107437133789E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":3}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":3}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:3): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #81887 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore5): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #81887, processing time: 0.014792919158936 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #76119 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #76119, processing time: 0.00028109550476074 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #76752 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #76752, processing time: 3.3140182495117E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84815 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84815, processing time: 3.6001205444336E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #79327 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #79327, processing time: 0.00034785270690918 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #81887 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #81887, processing time: 0.0005950927734375 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #73971 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore5 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore5&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #73971, processing time: 8.8930130004883E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #79327 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #79327, processing time: 4.7922134399414E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #84836 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #84836, processing time: 5.0067901611328E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":4}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:4): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:4): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #84815 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore5): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:4): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #84815, processing time: 0.012615919113159 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #82728 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #82728, processing time: 6.6995620727539E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #73978 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #73978, processing time: 3.9100646972656E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #82721 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #82721, processing time: 0.00042414665222168 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #84815 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #84815, processing time: 0.00069785118103027 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #82667 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore5 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore5&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #82667, processing time: 8.702278137207E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #82721 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #82721, processing time: 7.7009201049805E-5 []
21:22:02 ===
21:22:02 
21:22:02 5) MediaWiki\Extension\DiscussionTools\Tests\ThreadItemStoreTest::testInsertThreadItems with data set #5 ('cases/ThreadItemStore/6change...-level')
21:22:02 Failed asserting that two arrays are equal.
21:22:02 --- Expected
21:22:02 +++ Actual
21:22:02 @@ @@
21:22:02      'discussiontools_items' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_pages' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_revisions' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02          2 => Array (
21:22:02 -            'itr_id' => '5'
21:22:02 -            'itr_itemid_id' => '3'
21:22:02 -            'itr_revision_id' => '2'
21:22:02 -            'itr_items_id' => '3'
21:22:02 +            'itr_id' => '3'
21:22:02 +            'itr_itemid_id' => '1'
21:22:02 +            'itr_revision_id' => '3'
21:22:02 +            'itr_items_id' => '1'
21:22:02              'itr_parent_id' => null
21:22:02              'itr_transcludedfrom' => null
21:22:02              'itr_level' => '0'
21:22:02 @@ @@
21:22:02              'itr_headinglevel' => '2'
21:22:02          )
21:22:02          3 => Array (
21:22:02 -            'itr_id' => '6'
21:22:02 -            'itr_itemid_id' => '4'
21:22:02 -            'itr_revision_id' => '2'
21:22:02 -            'itr_items_id' => '4'
21:22:02 -            'itr_parent_id' => '5'
21:22:02 +            'itr_id' => '4'
21:22:02 +            'itr_itemid_id' => '2'
21:22:02 +            'itr_revision_id' => '3'
21:22:02 +            'itr_items_id' => '2'
21:22:02 +            'itr_parent_id' => '3'
21:22:02              'itr_transcludedfrom' => null
21:22:02              'itr_level' => '1'
21:22:02              'itr_headinglevel' => null
21:22:02          )
21:22:02 -        4 => Array (...)
21:22:02 -        5 => Array (...)
21:22:02 -        6 => Array (...)
21:22:02 -        7 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_ids' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02 -        4 => Array (...)
21:22:02      )
21:22:02  )
21:22:02 
21:22:02 /workspace/src/extensions/DiscussionTools/tests/phpunit/ThreadItemStoreTest.php:88
21:22:02 phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97
21:22:02 === Logs generated by test case
21:22:02 [objectcache] [debug] MainWANObjectCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [localisation] [debug] LocalisationCache using store LCStoreNull []
21:22:02 [localisation] [debug] LocalisationCache::isExpired(en): cache missing, need to make one []
21:22:02 [wfDebug] [debug] ParserFactory: using default preprocessor {"private":false}
21:22:02 [ContentHandler] [info] Registered handler for wikitext: WikitextContentHandler []
21:22:02 [MessageCache] [debug] MessageCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [objectcache] [debug] MainObjectStash using store {class} {"class":"HashBagOStuff"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for pcache []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:content_models:wikidb-unittest_","lag":0,"age":0.5971660614013672,"walltime":0.00028204917907714844}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:content_models:wikidb-unittest_): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:slot_roles:wikidb-unittest_","lag":0,"age":0.5983729362487793,"walltime":0.0002689361572265625}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:slot_roles:wikidb-unittest_): miss, new value computed []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #73186 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #73186, processing time: 8.0108642578125E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":1}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":1}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #70563 []
21:22:02 [wfDebug] [debug] BacklinkCache::queryLinks: got results from DB {"private":false}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore6): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore6:templatelinks","lag":0,"age":0.6142849922180176,"walltime":0.0009140968322753906}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore6:templatelinks): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore6): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid-pcache []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A133): miss, new value computed []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ban from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for crh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for iu from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ku from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for shi from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sr from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tg from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tly from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for uz from source []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"parsoid-pcache","key":"wikidb-unittest_:parsoid-pcache:idhash:1-0!useParsoid=1!en","cache_time":"20231016202130","rev_id":1}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #70563, processing time: 0.044166088104248 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #40127 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #40127, processing time: 0.00041007995605469 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #52258 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #52258, processing time: 3.6001205444336E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84479 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84479, processing time: 3.7908554077148E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #74886 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #74886, processing time: 0.00056600570678711 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #70563 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #70563, processing time: 0.00086688995361328 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #62359 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore6 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore6&action=history http://127.0.0.1:9413/wiki/ThreadItemStore6 http://127.0.0.1:9413/index.php?title=ThreadItemStore6&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #62359, processing time: 0.00010085105895996 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #49878 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #49878, processing time: 4.887580871582E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":2}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":2}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:2): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #83151 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore6): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #83151, processing time: 0.01882791519165 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #83755 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #83755, processing time: 0.00031709671020508 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #83780 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #83780, processing time: 3.3855438232422E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #74497 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #74497, processing time: 3.6001205444336E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #84999 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #84999, processing time: 0.00054001808166504 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #83151 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #83151, processing time: 0.0011870861053467 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #71545 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore6 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore6&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #71545, processing time: 0.00011801719665527 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #84999 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #84999, processing time: 6.7949295043945E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #73323 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #73323, processing time: 6.8902969360352E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":3}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":3}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:3): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #71545 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore6): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #71545, processing time: 0.016626119613647 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #74107 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #74107, processing time: 7.0095062255859E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #83612 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #83612, processing time: 3.6954879760742E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #79773 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #79773, processing time: 0.0015420913696289 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #71545 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #71545, processing time: 0.0010039806365967 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #84230 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore6 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore6&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #84230, processing time: 9.608268737793E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #79773 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #79773, processing time: 4.887580871582E-5 []
21:22:02 ===
21:22:02 
21:22:02 6) MediaWiki\Extension\DiscussionTools\Tests\ThreadItemStoreTest::testInsertThreadItems with data set #6 ('cases/ThreadItemStore/7identi...estamp')
21:22:02 Failed asserting that two arrays are equal.
21:22:02 --- Expected
21:22:02 +++ Actual
21:22:02 @@ @@
21:22:02          1 => Array (...)
21:22:02          2 => Array (...)
21:22:02          3 => Array (...)
21:22:02 -        4 => Array (...)
21:22:02 -        5 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_pages' => Array (
21:22:02          0 => Array (...)
21:22:02 @@ @@
21:22:02          1 => Array (...)
21:22:02          2 => Array (...)
21:22:02          3 => Array (...)
21:22:02 -        4 => Array (...)
21:22:02 -        5 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_revisions' => Array (
21:22:02          0 => Array (...)
21:22:02 @@ @@
21:22:02          2 => Array (...)
21:22:02          3 => Array (...)
21:22:02          4 => Array (
21:22:02 -            'itr_id' => '7'
21:22:02 -            'itr_itemid_id' => '5'
21:22:02 -            'itr_revision_id' => '2'
21:22:02 -            'itr_items_id' => '5'
21:22:02 -            'itr_parent_id' => '6'
21:22:02 -            'itr_transcludedfrom' => null
21:22:02 -            'itr_level' => '2'
21:22:02 -            'itr_headinglevel' => null
21:22:02 -        )
21:22:02 -        5 => Array (
21:22:02              'itr_id' => '5'
21:22:02              'itr_itemid_id' => '1'
21:22:02              'itr_revision_id' => '3'
21:22:02 @@ @@
21:22:02              'itr_level' => '0'
21:22:02              'itr_headinglevel' => '2'
21:22:02          )
21:22:02 -        6 => Array (
21:22:02 +        5 => Array (
21:22:02              'itr_id' => '6'
21:22:02              'itr_itemid_id' => '2'
21:22:02              'itr_revision_id' => '3'
21:22:02 @@ @@
21:22:02              'itr_level' => '1'
21:22:02              'itr_headinglevel' => null
21:22:02          )
21:22:02 -        7 => Array (
21:22:02 -            'itr_id' => '8'
21:22:02 +        6 => Array (
21:22:02 +            'itr_id' => '7'
21:22:02              'itr_itemid_id' => '3'
21:22:02              'itr_revision_id' => '3'
21:22:02              'itr_items_id' => '3'
21:22:02 @@ @@
21:22:02              'itr_level' => '0'
21:22:02              'itr_headinglevel' => '2'
21:22:02          )
21:22:02 -        8 => Array (...)
21:22:02 -        9 => Array (...)
21:22:02 -        10 => Array (...)
21:22:02 +        7 => Array (
21:22:02 +            'itr_id' => '8'
21:22:02 +            'itr_itemid_id' => '4'
21:22:02 +            'itr_revision_id' => '3'
21:22:02 +            'itr_items_id' => '4'
21:22:02 +            'itr_parent_id' => '7'
21:22:02 +            'itr_transcludedfrom' => null
21:22:02 +            'itr_level' => '1'
21:22:02 +            'itr_headinglevel' => null
21:22:02 +        )
21:22:02      )
21:22:02      'discussiontools_item_ids' => Array (
21:22:02          0 => Array (...)
21:22:02 @@ @@
21:22:02          1 => Array (...)
21:22:02          2 => Array (...)
21:22:02          3 => Array (...)
21:22:02 -        4 => Array (...)
21:22:02 -        5 => Array (...)
21:22:02      )
21:22:02  )
21:22:02 
21:22:02 /workspace/src/extensions/DiscussionTools/tests/phpunit/ThreadItemStoreTest.php:88
21:22:02 phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97
21:22:02 === Logs generated by test case
21:22:02 [objectcache] [debug] MainWANObjectCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [localisation] [debug] LocalisationCache using store LCStoreNull []
21:22:02 [localisation] [debug] LocalisationCache::isExpired(en): cache missing, need to make one []
21:22:02 [wfDebug] [debug] ParserFactory: using default preprocessor {"private":false}
21:22:02 [ContentHandler] [info] Registered handler for wikitext: WikitextContentHandler []
21:22:02 [MessageCache] [debug] MessageCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [objectcache] [debug] MainObjectStash using store {class} {"class":"HashBagOStuff"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for pcache []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:content_models:wikidb-unittest_","lag":0,"age":0.7601680755615234,"walltime":0.00038886070251464844}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:content_models:wikidb-unittest_): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:slot_roles:wikidb-unittest_","lag":0,"age":0.7616438865661621,"walltime":0.0005319118499755859}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:slot_roles:wikidb-unittest_): miss, new value computed []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #73785 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #73785, processing time: 7.2002410888672E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":1}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":1}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #83075 []
21:22:02 [wfDebug] [debug] BacklinkCache::queryLinks: got results from DB {"private":false}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore7): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore7:templatelinks","lag":0,"age":0.7786738872528076,"walltime":0.0006940364837646484}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore7:templatelinks): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore7): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid-pcache []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A136): miss, new value computed []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ban from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for crh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for iu from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ku from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for shi from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sr from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tg from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tly from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for uz from source []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"parsoid-pcache","key":"wikidb-unittest_:parsoid-pcache:idhash:1-0!useParsoid=1!en","cache_time":"20231016202130","rev_id":1}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #83075, processing time: 0.056710004806519 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #85973 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #85973, processing time: 0.00033187866210938 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #57989 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #57989, processing time: 4.4107437133789E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84255 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84255, processing time: 4.0054321289062E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #74229 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #74229, processing time: 0.0004420280456543 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #83075 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #83075, processing time: 0.00066685676574707 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #83084 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore7 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore7&action=history http://127.0.0.1:9413/wiki/ThreadItemStore7 http://127.0.0.1:9413/index.php?title=ThreadItemStore7&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #83084, processing time: 0.00010299682617188 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #84251 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #84251, processing time: 5.5074691772461E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":2}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":2}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:2): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #83058 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore7): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #83058, processing time: 0.015071868896484 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #43430 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #43430, processing time: 0.00032496452331543 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #80042 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #80042, processing time: 3.2901763916016E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #78690 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #78690, processing time: 4.0054321289062E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #84059 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #84059, processing time: 0.00033807754516602 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #83058 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #83058, processing time: 0.00062298774719238 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #84395 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore7 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore7&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #84395, processing time: 8.7976455688477E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #84059 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #84059, processing time: 4.7922134399414E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #78827 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #78827, processing time: 5.2928924560547E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":3}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":3}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:3): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #84395 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore7): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #84395, processing time: 0.017591953277588 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #84245 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #84245, processing time: 0.0003209114074707 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #82615 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #82615, processing time: 3.504753112793E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84034 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84034, processing time: 3.8862228393555E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #84031 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #84031, processing time: 0.00040984153747559 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #84395 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #84395, processing time: 0.00073504447937012 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #82707 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore7 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore7&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #82707, processing time: 8.9883804321289E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #84031 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #84031, processing time: 4.7922134399414E-5 []
21:22:02 ===
21:22:02 
21:22:02 7) MediaWiki\Extension\DiscussionTools\Tests\ThreadItemStoreTest::testInsertThreadItems with data set #7 ('cases/ThreadItemStore/8indist...e-page')
21:22:02 Failed asserting that two arrays are equal.
21:22:02 --- Expected
21:22:02 +++ Actual
21:22:02 @@ @@
21:22:02      'discussiontools_items' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_pages' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_revisions' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02          2 => Array (
21:22:02 -            'itr_id' => '5'
21:22:02 -            'itr_itemid_id' => '3'
21:22:02 -            'itr_revision_id' => '2'
21:22:02 -            'itr_items_id' => '3'
21:22:02 -            'itr_parent_id' => '4'
21:22:02 +            'itr_id' => '3'
21:22:02 +            'itr_itemid_id' => '1'
21:22:02 +            'itr_revision_id' => '6'
21:22:02 +            'itr_items_id' => '1'
21:22:02 +            'itr_parent_id' => null
21:22:02              'itr_transcludedfrom' => null
21:22:02 -            'itr_level' => '2'
21:22:02 -            'itr_headinglevel' => null
21:22:02 +            'itr_level' => '0'
21:22:02 +            'itr_headinglevel' => '2'
21:22:02          )
21:22:02          3 => Array (
21:22:02 -            'itr_id' => '7'
21:22:02 -            'itr_itemid_id' => '4'
21:22:02 -            'itr_revision_id' => '4'
21:22:02 -            'itr_items_id' => '3'
21:22:02 -            'itr_parent_id' => '6'
21:22:02 +            'itr_id' => '4'
21:22:02 +            'itr_itemid_id' => '2'
21:22:02 +            'itr_revision_id' => '6'
21:22:02 +            'itr_items_id' => '2'
21:22:02 +            'itr_parent_id' => '3'
21:22:02              'itr_transcludedfrom' => null
21:22:02 -            'itr_level' => '3'
21:22:02 +            'itr_level' => '1'
21:22:02              'itr_headinglevel' => null
21:22:02          )
21:22:02 -        4 => Array (...)
21:22:02 -        5 => Array (...)
21:22:02 -        6 => Array (...)
21:22:02 -        7 => Array (...)
21:22:02      )
21:22:02      'discussiontools_item_ids' => Array (
21:22:02          0 => Array (...)
21:22:02          1 => Array (...)
21:22:02 -        2 => Array (...)
21:22:02 -        3 => Array (...)
21:22:02 -        4 => Array (...)
21:22:02      )
21:22:02  )
21:22:02 
21:22:02 /workspace/src/extensions/DiscussionTools/tests/phpunit/ThreadItemStoreTest.php:88
21:22:02 phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97
21:22:02 === Logs generated by test case
21:22:02 [objectcache] [debug] MainWANObjectCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [localisation] [debug] LocalisationCache using store LCStoreNull []
21:22:02 [localisation] [debug] LocalisationCache::isExpired(en): cache missing, need to make one []
21:22:02 [wfDebug] [debug] ParserFactory: using default preprocessor {"private":false}
21:22:02 [ContentHandler] [info] Registered handler for wikitext: WikitextContentHandler []
21:22:02 [MessageCache] [debug] MessageCache using store {class} {"class":"HashBagOStuff"}
21:22:02 [objectcache] [debug] MainObjectStash using store {class} {"class":"HashBagOStuff"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for pcache []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:content_models:wikidb-unittest_","lag":0,"age":0.9266750812530518,"walltime":0.0003039836883544922}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:content_models:wikidb-unittest_): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"global:NameTableSqlStore:slot_roles:wikidb-unittest_","lag":0,"age":0.9277620315551758,"walltime":0.0002808570861816406}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:NameTableSqlStore:slot_roles:wikidb-unittest_): miss, new value computed []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #81270 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #81270, processing time: 6.7949295043945E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":2}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202130","rev_id":1}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:1): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #82621 []
21:22:02 [wfDebug] [debug] BacklinkCache::queryLinks: got results from DB {"private":false}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore8): miss, new value computed []
21:22:02 [objectcache] [warning] Rejected set() for {cachekey} due to pending writes. {"cachekey":"wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore8:templatelinks","lag":0,"age":0.945396900177002,"walltime":0.0009329319000244141}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:numbacklinks:ns1%3AThreadItemStore8:templatelinks): miss, new value computed []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore8): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid-pcache []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [ParserCache] [debug] Creating ParserCache instance for parsoid []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid"}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [ParserCache] [debug] ParserOutput metadata cache miss {"name":"parsoid-pcache"}
21:22:02 [objectcache] [debug] fetchOrRegenerate(global:SqlBlobStore-blob:wikidb-unittest_:tt%3A139): miss, new value computed []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ban from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for crh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for iu from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for ku from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sh from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for shi from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for sr from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tg from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for tly from source []
21:22:02 [localisation] [debug] LocalisationCache::loadCoreData: got localisation for uz from source []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"parsoid-pcache","key":"wikidb-unittest_:parsoid-pcache:idhash:1-0!useParsoid=1!en","cache_time":"20231016202131","rev_id":1}
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:1): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #82621, processing time: 0.054660081863403 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #74367 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #74367, processing time: 0.0003211498260498 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #65208 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #65208, processing time: 3.504753112793E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84676 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #84676, processing time: 3.6954879760742E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #83584 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #83584, processing time: 0.00042319297790527 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #82621 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #82621, processing time: 0.00070714950561523 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #71864 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore8 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore8&action=history http://127.0.0.1:9413/wiki/ThreadItemStore8 http://127.0.0.1:9413/index.php?title=ThreadItemStore8&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #71864, processing time: 0.00010013580322266 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #79100 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #79100, processing time: 5.5074691772461E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":1}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202131","rev_id":2}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:2): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #81766 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore8): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:2): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #81766, processing time: 0.093348026275635 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #78485 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #78485, processing time: 0.00057601928710938 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #78171 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #78171, processing time: 7.5817108154297E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #85954 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #85954, processing time: 8.2015991210938E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #76382 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #76382, processing time: 0.00072813034057617 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #81766 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #81766, processing time: 0.00096702575683594 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #62220 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore8 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore8&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #62220, processing time: 0.00013899803161621 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #76382 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #76382, processing time: 7.6055526733398E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #77797 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #77797, processing time: 8.702278137207E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202131","rev_id":3}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:3): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #62220 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore8): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:3): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #62220, processing time: 0.020296096801758 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #82849 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #82849, processing time: 0.00018215179443359 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #44126 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #44126, processing time: 0.00011777877807617 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #83046 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #83046, processing time: 0.001154899597168 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #62220 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #62220, processing time: 0.0017180442810059 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #82902 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore8 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore8&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #82902, processing time: 0.0001978874206543 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #83046 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #83046, processing time: 0.00012898445129395 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #85754 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #85754, processing time: 0.00011610984802246 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202131","rev_id":4}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:4): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:4): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #44126 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore8): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:4): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #44126, processing time: 0.02333402633667 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #86028 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #86028, processing time: 0.00010108947753906 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #61333 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #61333, processing time: 5.8889389038086E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #80118 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #80118, processing time: 0.00059700012207031 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #44126 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #44126, processing time: 0.0010590553283691 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #43161 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore8 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore8&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #43161, processing time: 0.00015687942504883 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #80118 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #80118, processing time: 7.2002410888672E-5 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #82462 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #82462, processing time: 0.00015616416931152 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [UserOptionsManager] [debug] Loading options from database {"user_id":3}
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202131","rev_id":5}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:5): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:5): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #61333 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore8): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:5): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #61333, processing time: 0.026840925216675 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #83887 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #83887, processing time: 0.00011801719665527 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #75736 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #75736, processing time: 7.2956085205078E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #73642 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #73642, processing time: 0.00058412551879883 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #61333 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #61333, processing time: 0.0010800361633301 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #74077 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore8 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore8&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #74077, processing time: 0.0001530647277832 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #73642 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #73642, processing time: 0.00011014938354492 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.revision-create"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.revision-create' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.revision-create. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #45244 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks::sendRevisionCreateEvent #45244, processing time: 7.2002410888672E-5 []
21:22:02 [OldRevisionImporter] [debug] ImportableOldRevisionImporter::import: running updates []
21:22:02 [ParserCache] [debug] Saved in parser cache {"name":"pcache","key":"wikidb-unittest_:pcache:idhash:1-0!canonical!en","cache_time":"20231016202131","rev_id":6}
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:page-content-model:6): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:6): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started RefreshSecondaryDataUpdate #75736 []
21:22:02 [objectcache] [debug] fetchOrRegenerate(wikidb-unittest_:linktargetstore-id:1%3AThreadItemStore8): miss, new value computed []
21:22:02 [objectcache] [debug] getWithSetCallback(wikidb-unittest_:page-content-model:6): process cache hit []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended RefreshSecondaryDataUpdate #75736, processing time: 0.012572050094604 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #75103 []
21:22:02 [EventStreamConfig] [debug] Selecting stream configs for target streams: {streams} {"streams":"mediawiki.page-properties-change"}
21:22:02 [EventStreamConfig] [warning] Stream 'mediawiki.page-properties-change' does not match any `stream` in stream config []
21:22:02 [EventBus] [debug] Using non-producing EventBus instance for stream mediawiki.page-properties-change. This stream is either undeclared, or is explicitly disabled. []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended AutoCommitUpdate_MediaWiki\Deferred\LinksUpdate\LinksUpdate::doUpdate #75103, processing time: 0.00028896331787109 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #55637 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Extension\EventBus\EventBusHooks->onLinksUpdateComplete #55637, processing time: 3.504753112793E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #83554 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_MediaWiki\Storage\DerivedPageDataUpdater->doUpdates #83554, processing time: 3.3855438232422E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SiteStatsUpdate #40178 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SiteStatsUpdate #40178, processing time: 0.00036382675170898 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started SearchUpdate #75736 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended SearchUpdate #75736, processing time: 0.00060296058654785 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started CdnCacheUpdate #80432 []
21:22:02 [squid] [info] CdnCacheUpdate::purge: http://127.0.0.1:9413/wiki/Talk:ThreadItemStore8 http://127.0.0.1:9413/index.php?title=Talk:ThreadItemStore8&action=history {"private":false}
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended CdnCacheUpdate #80432, processing time: 8.702278137207E-5 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: started MWCallableUpdate_WikiPage::onArticleEdit #40178 []
21:22:02 [DeferredUpdates] [debug] DeferredUpdates::run: ended MWCallableUpdate_WikiPage::onArticleEdit #40178, processing time: 4.7922134399414E-5 []
21:22:02 ===
21:22:02 
21:22:02 FAILURES!
21:22:02 Tests: 2969, Assertions: 27188, Failures: 7, Skipped: 54.

Links
Example DNM change on the DiscussionTools repo - https://gerrit.wikimedia.org/r/c/mediawiki/extensions/DiscussionTools/+/966266

Example failure on the ReportIncident extension - https://integration.wikimedia.org/ci/job/quibble-vendor-mysql-php74-noselenium-docker/131977/console

Event Timeline

Dreamy_Jazz renamed this task from DiscussionTools CI failures blocking MediaWiki gate to DiscussionTools CI failures blocking CheckUser merges.Oct 16 2023, 8:31 PM
Dreamy_Jazz triaged this task as Unbreak Now! priority.
Dreamy_Jazz renamed this task from DiscussionTools CI failures blocking CheckUser merges to DiscussionTools CI failures blocking ReportIncident merges.Oct 16 2023, 8:34 PM
Dreamy_Jazz renamed this task from DiscussionTools CI failures blocking ReportIncident merges to DiscussionTools CI is failing.
Dreamy_Jazz lowered the priority of this task from Unbreak Now! to High.
Dreamy_Jazz updated the task description. (Show Details)
Dreamy_Jazz updated the task description. (Show Details)

ThreadItemStoreTest::testInsertThreadItems is a large integration test for the DiscussionTools permalinks feature (sorry about that), covering everything from creating page revisions, through MediaWiki parser and DiscussionTools discussion parsing code, to saving the metadata generated from it all. It is failing because some of the expected metadata is missing, which could be caused by a problem at any of these steps. I can't reproduce locally :/

I added some debug code locally, and I'm seeing calls to $parsoidOutputAccess->getParserOutput returning the parser results for the wrong revisions – the tests create pages with several revisions and parse them, but the parse result is always the one for the first revision created.

It's caused by localCache in ParserOutputAccess: https://gerrit.wikimedia.org/g/mediawiki/core/+/a678bcf0c6ef622227f9ff40ad548e3552275c99/includes/page/ParserOutputAccess.php#221

The cache key used here does not include the revision ID (only page ID), and nothing verifies that the page has not been edited since the local cache entry was saved.

The $isOld is supposed to protect against that -- if the page has been edited it should be old.

Change 966525 had a related patch set uploaded (by Bartosz Dziewoński; author: Bartosz Dziewoński):

[mediawiki/core@master] ParserOutputAccess: Fix local cache when page is edited within the process

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

^the theory behind the above patch is that DT is doing a parse->edit->reparse sequence *within the same request* (at least during testing), and that's breaking the caching here, which assumes that at least one of those steps occurs in a separate request and therefore starts with a clean $localCache again due to the non-persistent nature of PHP request processing.

Change 966525 merged by jenkins-bot:

[mediawiki/core@master] ParserOutputAccess: Fix local cache when page is edited within the process

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

Adding as a train blocker. @matmarex and I /think/ that the implications of this bug should be limited to testing, and that actual production use of DT will always have a separate request somewhere in the parse->edit->reparse cycle *but* the CI failure in DT will probably block /other/ backports to the train and so this patch is worth backporting.

Change 966241 had a related patch set uploaded (by Jdrewniak; author: Bartosz Dziewoński):

[mediawiki/core@wmf/1.42.0-wmf.1] ParserOutputAccess: Fix local cache when page is edited within the process

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

Change 966241 merged by jenkins-bot:

[mediawiki/core@wmf/1.42.0-wmf.1] ParserOutputAccess: Fix local cache when page is edited within the process

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

Mentioned in SAL (#wikimedia-operations) [2023-10-17T13:55:09Z] <jdrewniak@deploy2002> Started scap: Backport for [[gerrit:966241|ParserOutputAccess: Fix local cache when page is edited within the process (T349033)]]

Mentioned in SAL (#wikimedia-operations) [2023-10-17T13:56:29Z] <jdrewniak@deploy2002> jdrewniak: Backport for [[gerrit:966241|ParserOutputAccess: Fix local cache when page is edited within the process (T349033)]] synced to the testservers (https://wikitech.wikimedia.org/wiki/Mwdebug)

Mentioned in SAL (#wikimedia-operations) [2023-10-17T14:11:06Z] <jdrewniak@deploy2002> Finished scap: Backport for [[gerrit:966241|ParserOutputAccess: Fix local cache when page is edited within the process (T349033)]] (duration: 15m 56s)

Thanks for backporting it!

Change 972019 had a related patch set uploaded (by Subramanya Sastry; author: Bartosz Dziewoński):

[mediawiki/core@REL1_41] ParserOutputAccess: Fix local cache when page is edited within the process

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

Change 972019 merged by jenkins-bot:

[mediawiki/core@REL1_41] ParserOutputAccess: Fix local cache when page is edited within the process

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