T434024#12196170 is an issue with the Ceph filesystem which certainly caused a slowdown. That one started on July 24/25 and has tentatively been fixed on Friday August 7th 20:00 UTC by https://gerrit.wikimedia.org/r/c/operations/puppet/+/1322878 . I haven't looked at the performance of the civicrm job but that change at least got rid of timeouts though it is still slower than it used to be ( T434024#12196806 ). But I'll follow up on that other task. It is entirely possible there is another issue in the underlying infrastructure.

The quibble-with-gated-extensions-vendor-mysql-php83 job has a fixed set of extensions. The ReadingLists extension was added on Wednesday August 5th at 20:30 UTC (T403560 / https://gerrit.wikimedia.org/r/c/integration/config/+/1184176). But that is several days after July 24/25. I guess that rules it out, but there is certainly some time added to the job because of ReadingLists addition (I haven't looked how much time it adds).

I would have suggested to bisect mediawiki/core to find the culprit but you already found it and confirmed LinkBatch::doIsAlwaysKnownQuery() is the source of the slowdown (great finding):

if I comment out https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1314789/13/includes/Page/LinkBatch.php#207 the runtime goes from 50 seconds to under one second (and memory usage decreased from 3 gb to 50 mb.

Change #1324303 had a related patch set uploaded (by Urbanecm; author: Urbanecm):

[mediawiki/core@master] Page: Defer per-title isAlwaysKnown work out of LinkBatch preload

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

Wonderful news :). I made LinkAlwaysKnownLookup considerably less eager than it is now. Now, LinkBatch only runs the batched computation part (for now, this means running the hook, but T433232 proposes moving eg. file lookups to the batched portion). This should get us much closer to pre-T408666 performance.

What I'm not sure about is the increase in size. I'm fairly certain this happens because of the $logger->warning( ... ) calls (PHPUnit needs to keep the full tracebacks and log entries, and calls to Title::isKnown are fairly common, most of them don't use the batching capability, as it is fairly new). Worst case, we can remove the logger entry altogether.

@Peter @hashar Would you be able to help with measuring the impact of my patch? Happy to keep digging if it is not enough.

@Peter you did a Quibble run on your local machine which reproduced the large delay. May you retry it with https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1324303 applied? (quibble --change 1324303 ...) should download and apply it).

@Urbanecm_WMF do you know whether your patch might have affected production performance somehow? Given it was rolled with wmf.13 and we are deploy wmf.15 this week.

In T434470#12202642, @hashar wrote:

@Urbanecm_WMF do you know whether your patch might have affected production performance somehow? Given it was rolled with wmf.13 and we are deploy wmf.15 this week.

I don't see how, but... proving there's no performance impact is kind of challenging :). In any case, the patch I made should get any negative impact close enough to the status quo.

If I'm interpreting the Jenkins run logs correctly, it has worked, but eyes appreciated.

From a current CI run:`
https://integration.wikimedia.org/ci/job/quibble-with-gated-extensions-vendor-mysql-php83/51617/consoleFull (group 3)

 # Duration Test
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1 1:55.430 MediaWiki\Extension\Translate\Synchronization\UpdateMessageJobTest::testNoTransver
 2 1:52.202 MediaWiki\Extension\Translate\Synchronization\UpdateMessageJobTest::testNullEditCanFuzzy
 3 1:39.035 MediaWiki\Extension\Translate\Synchronization\UpdateMessageJobTest::testExplicitFuzzy
 4 1:08.496 MediaWiki\Extension\Translate\Synchronization\UpdateMessageJobTest::testUpdate
 5 0:11.707 TranslationFuzzyUpdaterTest::testParsing
 6 0:01.642 TranslationTransverUpdaterTest::testTransver
 7 0:00.942 MediaWiki\Extension\Translate\PageTranslation\TranslatableBundleMoverTest::testMoveSynchronouslyMovesAllPages
 8 0:00.935 TranslationFuzzyUpdaterTest::testFuzzyHandlingOnUndo
 9 0:00.701 MediaWiki\Extension\Translate\TranslatorInterface\Aid\TranslationAidDataProviderTest::testGetGoodTranslations
10 0:00.553 MediaWiki\Extension\Translate\TranslatorInterface\ReviewTranslationActionApiTest::testGetReviewBlockers with data set #0 ('don't have permission', 'plainUser', 'superUser1', 'Ugakey1/fi', 'trans1', 'Unpriviledged user is not all... state')
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
   0:00.000
    ¦  +--- seconds
    +------ minutes

There are 21 additional slow tests that are not listed here.

Time: 06:58.685, Memory: 3.83 GB

From the open patch set
https://integration.wikimedia.org/ci/job/quibble-with-gated-extensions-vendor-mysql-php83/50876/consoleFull (group 3)

 # Duration Test
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 1    1.036 TranslationTransverUpdaterTest::testTransver
 2    0.637 MediaWiki\Extension\Translate\Synchronization\UpdateMessageJobTest::testUpdate
 3    0.630 MediaWiki\Extension\Translate\PageTranslation\TranslatablePageMarkerTest::testGetMarkOperation with data set #0 ('<translate>Foo</translate>', true, 'tpt-oldrevision')
 4    0.488 TranslationFuzzyUpdaterTest::testFuzzyHandlingOnUndo
 5    0.461 TranslationFuzzyUpdaterTest::testParsing
 6    0.390 MediaWiki\Extension\Translate\PageTranslation\TranslatablePageMarkerTest::testMarkAndUnmarkPage
 7    0.389 MediaWiki\Extension\Translate\Synchronization\UpdateMessageJobTest::testNoTransver
 8    0.331 MediaWiki\Extension\Translate\Synchronization\UpdateMessageJobTest::testExplicitFuzzy
 9    0.301 MediaWiki\Extension\Translate\Synchronization\MessageWebImporterTest::testDoFuzzy
10    0.244 MediaWiki\Extension\Translate\TranslatorInterface\Aid\TranslationAidDataProviderTest::testGetGoodTranslations
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
      0.000
       +--- seconds

There are 16 additional slow tests that are not listed here.

Time: 00:07.757, Memory: 146.00 MB

Due to parallel run this not exact the same tests that runs (70 vs. 64), but the timing and the memory usage are extrem.
The warning logged by LinkAlwaysKnownLookup is not visible in the logs.
new MapCacheLRU( 100_000 ) allocs 16 MB, not sure if the service is not destructed in this tests and this makes the difference

The difference in the logs are lines like

[localisation] MediaWiki\Language\LocalisationCache::loadCoreData: got localisation for aa from source

for each language

It seems the current CI trigger MessageProvider via LinkAlwaysKnownLookup via LinkBatch and that fills the localisation cache with all languages.
Not calling ShadowPageLoader::existsForLink so often helps here, which happen in the provided patch set.

Change #1324303 merged by jenkins-bot:

[mediawiki/core@master] Page: Defer per-title isAlwaysKnown work out of LinkBatch preload

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

Thank you @Urbanecm_WMF for the investigation and the fix!