Page MenuHomePhabricator

Quibble may need to rebuild localization cache before running tests
Open, Needs TriagePublic

Description

When running QUnit / Selenium tests, the mw-debug-www.log spurts a few traces such as:

LocalisationCache::isExpired(en): cache missing, need to make one
LocalisationCache::recache: got localisation for en from source
[DBPerformance] Expectation (writes <= 0) by MediaWiki::main not met (actual: 1):
query-m: DELETE FROM `l10n_cache` WHERE lc_lang = 'X' [TRX#1254e1]
[DBPerformance] Expectation (writes <= 0) by MediaWiki::main not met (actual: 2):
query-m: INSERT INTO `l10n_cache` (lc_lang,lc_key,lc_value) VALUES ('X') [TRX#1254e1]
[DBPerformance] Expectation (writes <= 0) by MediaWiki::main not met (actual: 3):
query-m: INSERT INTO `l10n_cache` (lc_lang,lc_key,lc_value) VALUES ('X') [TRX#1254e1]
[DBPerformance] Expectation (writes <= 0) by MediaWiki::main not met (actual: 4):
query-m: INSERT INTO `l10n_cache` (lc_lang,lc_key,lc_value) VALUES ('X') [TRX#1254e1]
...
[MessageCache] MessageCache::load: Loading en... local cache is empty, global cache is expired/volatile, loading from database

I suspect there is a race condition due to mutliple http queries each triggering LocalisationCache->recache('en'). Potentially after the installation is complete, we might want to invoke php maintenance/rebuildLocalisationCache.php --lang=en.

Event Timeline

hashar created this task.Jun 4 2018, 10:38 AM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJun 4 2018, 10:38 AM
Vvjjkkii renamed this task from Quibble may need to rebuild localization cache before running tests to 8obaaaaaaa.Jul 1 2018, 1:05 AM
Vvjjkkii triaged this task as High priority.
Vvjjkkii updated the task description. (Show Details)
Vvjjkkii removed a subscriber: Aklapper.
CommunityTechBot raised the priority of this task from High to Needs Triage.
CommunityTechBot renamed this task from 8obaaaaaaa to Quibble may need to rebuild localization cache before running tests.
CommunityTechBot added a subscriber: Aklapper.

What I do not get is that update.php is supposed to populate the cache:

Start command line script maintenance/update.php
[caches] cluster: EmptyBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff
[caches] LocalisationCache: using store LCStoreNull
LocalisationCache::isExpired(en): cache missing, need to make one
LocalisationCache::recache: got localisation for en from source
[SQLBagOStuff] SqlBagOStuff: connecting to [unknown]
[SQLBagOStuff] Connection SQLite 3.16.2 will be used for SqlBagOStuff
[MessageCache] MessageCache::load: Loading en... local cache is empty, global cache is empty, loading from database

And the first web request does try to use the database cache which triggers a rebuild:

Start request GET /index.php?uselang=en&title=Special%3ABlankPage
[caches] cluster: EmptyBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff
[caches] LocalisationCache: using store LCStoreDB
[SQLBagOStuff] SqlBagOStuff: connecting to [unknown]
[SQLBagOStuff] Connection SQLite 3.16.2 will be used for SqlBagOStuff
[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: connected to database 0 at 'localhost'.
LocalisationCache::isExpired(en): cache missing, need to make one
LocalisationCache::recache: got localisation for en from source
[DBPerformance] Expectation (writes <= 0) by MediaWiki::main not met (actual: 1):
query-m: DELETE FROM l10n_cache WHERE lc_lang = 'X' [TRX#ba5264]

So message is bound to SqlBagOStuff but LocalisationCache is LCStoreNull ... As I understand it that means no cache is populated by update.php

If running rebuildLocalisationCache.php just after update.php:

Start command line script maintenance/rebuildLocalisationCache.php
[caches] cluster: EmptyBagOStuff, WAN: mediawiki-main-default, stash: db-replicated, message: SqlBagOStuff, session: SqlBagOStuff
[caches] LocalisationCache: using store LCStoreDB
[caches] LocalisationCacheBulkLoad: using store LCStoreDB
[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: calling initLB() before first connection.
[DBConnection] Wikimedia\Rdbms\LoadBalancer::openConnection: connected to database 0 at 'localhost'.
LocalisationCache::isExpired(en): cache missing, need to make one
LocalisationCache::recache: got localisation for en from source

And in this case the errors disappear. The first web request does use the cache:

[caches] LocalisationCache: using store LCStoreDB
[SQLBagOStuff] SqlBagOStuff: connecting to [unknown]
[SQLBagOStuff] Connection SQLite 3.16.2 will be used for SqlBagOStuff

The LocalisationCache is actually disabled in update.php (T22471):

maintenance/update.php
class UpdateMediaWiki extends Maintenance {

    ...

    function afterFinalSetup() {
        global $wgLocalisationCacheConf;

        # Don't try to access the database
        # This needs to be disabled early since extensions will try to use the l10n
        # cache from $wgExtensionFunctions (T22471)
        $wgLocalisationCacheConf = [
            'class' => LocalisationCache::class,
            'storeClass' => LCStoreNull::class,   # <------ OH NO
            'storeDirectory' => false,
            'manualRecache' => false,
        ];
    }

}

Not digging into the exact reason for disabling the cache, running rebuildLocalisationCache would be good enough for Quibble.

hashar moved this task from Backlog to In progress on the Quibble board.Jul 19 2018, 2:37 PM

Change 446840 had a related patch set uploaded (by Hashar; owner: Hashar):
[integration/quibble@master] rebuildLocalisationCache after update.php

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

hashar claimed this task.Jul 19 2018, 2:49 PM

Change 446899 had a related patch set uploaded (by Hashar; owner: Hashar):
[mediawiki/core@master] Enable LocalisationCache in update.php

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

Change 446840 merged by jenkins-bot:
[integration/quibble@master] rebuildLocalisationCache after update.php

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