Page MenuHomePhabricator
Create Task
Maniphest T176097

mediawiki-phpunit-php70-jessie job sometimes fails with MessageBlobStoreTest failure
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Description

After installing a brand new copy of MW from current head at b347d8e I ran php maintenance/update.php followed by php tests/phpunit/phpunit.php --tap tests/phpunit/includes/resourceloader/MessageBlobStoreTest.php and got the following failure message:

php tests/phpunit/phpunit.php --tap tests/phpunit/includes/resourceloader/MessageBlobStoreTest.php
Using PHP 7.0.22-0ubuntu0.16.04.1
TAP version 13
ok 1 - MessageBlobStoreTest::testSetLogger
ok 2 - MessageBlobStoreTest::testGetResourceLoader
ok 3 - MessageBlobStoreTest::testFetchMessage
ok 4 - MessageBlobStoreTest::testFetchMessageFail
ok 5 - MessageBlobStoreTest::testGetBlob
not ok 6 - Failure: MessageBlobStoreTest::testGetBlobCached
  ---
  message: 'MessageBlobStore::fetchMessage(''example'', ''en'') was not expected to be called.'
  severity: fail
  ...
ok 7 - MessageBlobStoreTest::testUpdateMessage
ok 8 - MessageBlobStoreTest::testValidation
ok 9 - MessageBlobStoreTest::testClear
1..9

This is a brand new installation of MediaWiki with no extensions whatsoever, and with no caching installed (e.g. no memcahced, etc.) so I would expect that test to either pass or be skipped, depending on what is intended behavior.

Notifying @Anomie, @Krinkle and @Legoktm as they seem to have all contributed to pertinent part of the code.

Details

Related Changes in Gerrit:
Show related patches Customize query in gerrit

Related Objects
Search...

Event Timeline

There are a very large number of changes, so older changes are hidden. Show Older Changes
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptSep 17 2017, 10:37 PM
Huji removed Anomie as the assignee of this task.Sep 17 2017, 10:37 PM
Huji added a parent task: T176039: Ensure no errors or failures occur with MediaWiki core tests on a clean installation.

Was assigned by accident. Please feel free to take over or just propose a solution.

Huji added a comment.Sep 18 2017, 2:01 AM

I also sometimes get this one in addition to, or instead of the above:

MessageBlobStoreTest::testClear
Cache-hit
Failed asserting that two strings are equal.
--- Expected
+++ Actual
@@ @@
-'{"example":"First"}'
+'{"example":"Second"}'

/var/www/html/tests/phpunit/includes/resourceloader/MessageBlobStoreTest.php:202
/var/www/html/maintenance/doMaintenance.php:92

The fact that this one and the one above only occur "sometimes" makes me wonder if it has to do with execution speed. I am testing on a VM with 2GB memory and 1 CPU core.

Anomie added a comment.Sep 18 2017, 2:40 PM

In both cases it seems that the key being fetched from cache is somehow being expired, so the test is finding a cache miss where it expected a hit and so fails. I can't see any reason for that to happen, though.

Krinkle added a project: MediaWiki-ResourceLoader.Sep 18 2017, 3:34 PM
Krinkle added a comment.Sep 19 2017, 6:08 PM

The MessageBlobStoreTest intentionally doesn't depend on your local installs' cache configuration (which might be CACHE_NONE / EmptyBagOStuff). Instead, the test mocks this in favour of a simple in-memory cache (HashBagOStuff). I don't see how this could end up wiping a key without it explicitly being cleared.

@Huji Do other tests have issues as well, or does it appear specific to MessageBlobStoreTest? Could you try running tests from /tests/phpunit/includes/libs/objectcache, specifically BagOStuffTest, HashBagOStuffTest and WANObjectCacheTest?

Krinkle changed the task status from Open to Stalled.Sep 19 2017, 6:08 PM
Krinkle triaged this task as Medium priority.
Krinkle moved this task from Inbox to Backlog on the MediaWiki-ResourceLoader board.
Krinkle moved this task from Inbox to PHPUnit on the MediaWiki-Core-Tests board.
Huji added a comment.EditedSep 28 2017, 2:58 PM

@Krinkle the only tests that resulted in an error are the ones show above. I cannot reproduce this consistently.

Oh, and /tests/phpunit/includes/libs/objectcache tests all pass successfully

Nikerabbit subscribed.Sep 29 2017, 7:17 AM
Restricted Application added a project: Performance-Team. · View Herald TranscriptJan 2 2018, 8:17 PM
Krinkle removed projects: Performance-Team, MediaWiki-ResourceLoader.Jan 8 2018, 6:17 PM
Huji added a comment.Mar 28 2018, 1:26 AM

This continues to be the case. I just made another fresh installation of MediaWiki using all the default options and ran PHPUnit immediately thereafter, and the output is as follows:

1) MessageBlobStoreTest::testClear
Cache-hit
Failed asserting that two strings are equal.
--- Expected
+++ Actual
@@ @@
-'{"example":"First"}'
+'{"example":"Second"}'

/var/www/html/tests/phpunit/includes/resourceloader/MessageBlobStoreTest.php:204
/var/www/html/maintenance/doMaintenance.php:94
Krinkle added a comment.Mar 28 2018, 1:43 AM

@Huji Please tell me: MediaWiki version, PHP version, and whether any object cache is installed (e.g. APC). The easiest is probably a copy of the install.php output, which answers all these and more. A copy of your generated LocalSettings.php would also help (omit database password and upgrade tokens, if used elsewhere).

Huji added a comment.Mar 28 2018, 2:03 AM
  • MediaWiki version: 1.31.0-alpha (17e8f7d)
  • PHP version: PHP 7.0.28-0ubuntu0.16.04.1 (cli) ( NTS )
  • Object cache: none installed
  • LocalSettings.php file: P6910
• MZMcBride subscribed.Mar 29 2018, 2:52 AM
Krinkle added a comment.Mar 29 2018, 2:56 AM

@Huji Sorry, but I couldn't reproduce it using php:7.2 (Debian Stretch) nor php:7.0 (Debian Jessie) from https://hub.docker.com/_/php/.

Additionally, https://travis-ci.org/wikimedia/mediawiki/jobs/359640486 shows PHP 7.0 passing as well. And that one uses 7.0.28 and Ubuntu (Trusty). Which should be the same as what you're using.

At this point, I can't really do more unless you're able to reproduce it on a smaller scale. E.g. when running just a subset of the unit tests, as opposed to the entire suite. That would help narrow down what combination of things is causing the failure.

Also, do you have any extensions or skins installed (aside from Vector). If you do, try again with nothing loaded (or just Vector).

Nikerabbit added a comment.Mar 29 2018, 7:22 AM

Could it be the presence of a cache that is required?

Huji added a comment.Mar 29 2018, 11:22 AM
In T176097#4090036, @Krinkle wrote:

@Huji Sorry, but I couldn't reproduce it using php:7.2 (Debian Stretch) nor php:7.0 (Debian Jessie) from https://hub.docker.com/_/php/.

Additionally, https://travis-ci.org/wikimedia/mediawiki/jobs/359640486 shows PHP 7.0 passing as well. And that one uses 7.0.28 and Ubuntu (Trusty). Which should be the same as what you're using.

At this point, I can't really do more unless you're able to reproduce it on a smaller scale. E.g. when running just a subset of the unit tests, as opposed to the entire suite. That would help narrow down what combination of things is causing the failure.

Also, do you have any extensions or skins installed (aside from Vector). If you do, try again with nothing loaded (or just Vector).

I don't have anything else installed. I will try to narrow it down to a specific subset of tests, but the MessageBlobStore tests are just flaky (i.e. they past most of the time, but fail some of the time).

Krinkle added a comment.Mar 29 2018, 6:26 PM
In T176097#4090186, @Nikerabbit wrote:

Could it be the presence of a cache that is required?

MessageBlobStore uses a mocked WANObjectCache with a HashBagOStuff internally (hash uses plain array in PHP). It does not depend on APC or other cache.

hashar subscribed.Apr 9 2018, 8:27 PM
1) MessageBlobStoreTest::testClear
Cache-hit
Failed asserting that two strings are equal.
--- Expected
+++ Actual
@@ @@
-'{"example":"First"}'
+'{"example":"Second"}'

/var/www/html/tests/phpunit/includes/resourceloader/MessageBlobStoreTest.php:204
/var/www/html/maintenance/doMaintenance.php:94

I got that one on REL1_29 using a Docker container (Stretch, php7) and MariaDB.

hashar added a comment.Apr 9 2018, 8:30 PM

Happened to me while testing an experimental job on https://gerrit.wikimedia.org/r/375798 . The job is mediawiki-core-quibble-composer-mysql-php7-docker

The debug log doesn't have anything interesting though:

[PHPUnitCommand] START suite MessageBlobStoreTest
[PHPUnitCommand] Start test MessageBlobStoreTest::testSetLogger
[PHPUnitCommand] End test MessageBlobStoreTest::testSetLogger
[PHPUnitCommand] Start test MessageBlobStoreTest::testGetResourceLoader
[PHPUnitCommand] End test MessageBlobStoreTest::testGetResourceLoader
[PHPUnitCommand] Start test MessageBlobStoreTest::testFetchMessage
[PHPUnitCommand] End test MessageBlobStoreTest::testFetchMessage
[PHPUnitCommand] Start test MessageBlobStoreTest::testFetchMessageFail
[PHPUnitCommand] End test MessageBlobStoreTest::testFetchMessageFail
[PHPUnitCommand] Start test MessageBlobStoreTest::testGetBlob
[PHPUnitCommand] End test MessageBlobStoreTest::testGetBlob
[PHPUnitCommand] Start test MessageBlobStoreTest::testGetBlobCached
[PHPUnitCommand] End test MessageBlobStoreTest::testGetBlobCached
[PHPUnitCommand] Start test MessageBlobStoreTest::testUpdateMessage
[PHPUnitCommand] End test MessageBlobStoreTest::testUpdateMessage
[PHPUnitCommand] Start test MessageBlobStoreTest::testValidation
[PHPUnitCommand] End test MessageBlobStoreTest::testValidation
[PHPUnitCommand] Start test MessageBlobStoreTest::testClear
[PHPUnitCommand] FAILURE in MessageBlobStoreTest::testClear: [PHPUnit_Framework_ExpectationFailedException] Cache-hit
Failed asserting that two strings are equal.
[PHPUnitCommand] End test MessageBlobStoreTest::testClear
[PHPUnitCommand] END suite MessageBlobStoreTest
hashar added a comment.Apr 9 2018, 8:53 PM

The experimentals jobs in CI have been made against REL1_29 change https://gerrit.wikimedia.org/r/#/c/375798/ . The first show the failure, a second check passed that test.

Failmediawiki-core-quibble-composer-mysql-php7-docker #11
Passmediawiki-core-quibble-composer-mysql-php7-docker #14

I have marked the build to be kept forever. Maybe we can dig in the debug/exception logs. But I dont think there will be any difference.

gerritbot subscribed.Apr 17 2018, 9:20 PM

Change 427261 had a related patch set uploaded (by Krinkle; owner: Krinkle):
[mediawiki/core@master] resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a project: Patch-For-Review.Apr 17 2018, 9:20 PM
Krinkle renamed this task from MessageBlobStoreTest fails on a fresh installation of MediaWiki to mediawiki-phpunit-php70-jessie sometimes fails with MessageBlobStoreTest failure.Apr 17 2018, 9:20 PM
Krinkle renamed this task from mediawiki-phpunit-php70-jessie sometimes fails with MessageBlobStoreTest failure to mediawiki-phpunit-php70-jessie job sometimes fails with MessageBlobStoreTest failure.
Krinkle changed the task status from Stalled to Open.
Krinkle added projects: Wikimedia-production-error (ARCHIVED -- Shared Build Failure), MediaWiki-ResourceLoader, Performance-Team.
Krinkle removed a project: MediaWiki-Core-Tests.
Krinkle moved this task from Backlog to Confirmed Problem on the MediaWiki-ResourceLoader board.
Krinkle moved this task from Untriaged to Resolved on the Wikimedia-production-error (ARCHIVED -- Shared Build Failure) board.
Krinkle removed a project: Patch-For-Review.

Seems to also happen on master in the new mediawiki-phpunit-php70-jessie job.

gerritbot added a comment.Apr 17 2018, 9:33 PM

Change 427261 merged by jenkins-bot:
[mediawiki/core@master] resourceloader: Disable a flaky MessageBlobStoreTest case

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

ReleaseTaggerBot added a project: MW-1.32-notes (WMF-deploy-2018-04-24 (1.32.0-wmf.1)).Apr 17 2018, 10:00 PM
Krinkle removed a project: MW-1.32-notes (WMF-deploy-2018-04-24 (1.32.0-wmf.1)).Apr 18 2018, 2:52 AM
Huji added a comment.Apr 19 2018, 1:10 AM

@Krinkle: I don't get the errors anymore.

Krinkle added a comment.Apr 19 2018, 1:21 AM

@Huji What if you run it with the /** @group Broken */ comment removed from MessageBlobStoreTest.php?

gerritbot added a comment.Apr 23 2018, 4:43 PM

Change 428377 had a related patch set uploaded (by Krinkle; owner: Krinkle):
[mediawiki/core@REL1_31] resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a project: Patch-For-Review.Apr 23 2018, 4:43 PM
gerritbot added a comment.Apr 23 2018, 5:08 PM

Change 428377 merged by jenkins-bot:
[mediawiki/core@REL1_31] resourceloader: Disable a flaky MessageBlobStoreTest case

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

ReleaseTaggerBot added a project: MW-1.31-release-notes.Apr 23 2018, 6:00 PM
Krinkle claimed this task.Apr 23 2018, 8:19 PM
Krinkle moved this task from Inbox, needs triage to Doing (old) on the Performance-Team board.
Krinkle removed projects: MW-1.31-release-notes, Patch-For-Review.Apr 24 2018, 2:32 AM
Krinkle added a comment.Apr 24 2018, 2:36 AM

This job still fails very rarely with an assertion error from testClear(). Both that method and testGetBlobCached deal with caching. Both of them use a HashBagOStuff to store a key and essentially assert that it still exists 1 line later. The Hash cache uses a plain PHP array. It is a mystery to me how a key can disappear there. And I am still unable to reproduce it locally, including with quibble.

Krinkle moved this task from Resolved to In progress on the Wikimedia-production-error (ARCHIVED -- Shared Build Failure) board.Apr 24 2018, 2:36 AM
gerritbot added a comment.May 30 2018, 10:10 PM

Change 436410 had a related patch set uploaded (by Krinkle; owner: Krinkle):
[mediawiki/core@master] [WIP] resourceloader: Re-enable testGetBlobCached() test case

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

gerritbot added a project: Patch-For-Review.May 30 2018, 10:10 PM
gerritbot added a comment.Jun 10 2018, 7:58 AM

Change 436410 merged by jenkins-bot:
[mediawiki/core@master] resourceloader: Re-enable testGetBlobCached() test case

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

ReleaseTaggerBot added a project: MW-1.32-notes (WMF-deploy-2018-06-12 (1.32.0-wmf.8)).Jun 10 2018, 8:00 AM
gerritbot added a comment.Jun 12 2018, 1:32 AM

Change 439820 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@master] Fix flakey MessageBlobStoreTest assertion failures

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

Krinkle closed this task as Resolved.Jun 14 2018, 11:58 PM
Krinkle moved this task from In progress to Resolved on the Wikimedia-production-error (ARCHIVED -- Shared Build Failure) board.
gerritbot added a comment.Jun 15 2018, 12:11 AM

Change 439820 merged by jenkins-bot:
[mediawiki/core@master] Fix flaky MessageBlobStoreTest assertion failures

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

hashar added a comment.Jun 15 2018, 8:01 AM

Maybe we can reenable the test in REL1_31 and apply the fix there? It is only for tests though so it is probably not needed.

ReleaseTaggerBot edited projects, added: MW-1.32-notes (WMF-deploy-2018-06-26 (1.32.0-wmf.10)); removed: MW-1.32-notes (WMF-deploy-2018-06-12 (1.32.0-wmf.8)).Jun 15 2018, 11:09 AM
ReleaseTaggerBot edited projects, added: MW-1.32-notes (WMF-deploy-2018-07-10 (1.32.0-wmf.12)); removed: MW-1.32-notes (WMF-deploy-2018-06-26 (1.32.0-wmf.10)).Jun 26 2018, 6:01 PM
gerritbot added a comment.Jul 7 2018, 6:28 PM

Change 444368 had a related patch set uploaded (by Reedy; owner: Krinkle):
[mediawiki/core@REL1_30] resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 6:28 PM

Change 444369 had a related patch set uploaded (by Reedy; owner: Krinkle):
[mediawiki/core@REL1_29] resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 6:28 PM

Change 444370 had a related patch set uploaded (by Reedy; owner: Krinkle):
[mediawiki/core@REL1_27] resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 6:48 PM

Change 444368 abandoned by Reedy:
resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 6:48 PM

Change 444369 abandoned by Reedy:
resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 6:49 PM

Change 444370 abandoned by Reedy:
resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 6:50 PM

Change 444373 had a related patch set uploaded (by Reedy; owner: Krinkle):
[mediawiki/core@REL1_31] resourceloader: Re-enable testGetBlobCached() test case

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

gerritbot added a comment.Jul 7 2018, 6:51 PM

Change 444374 had a related patch set uploaded (by Reedy; owner: Aaron Schulz):
[mediawiki/core@REL1_31] Fix flaky MessageBlobStoreTest assertion failures

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

gerritbot added a comment.Jul 7 2018, 6:51 PM

Change 444375 had a related patch set uploaded (by Reedy; owner: Aaron Schulz):
[mediawiki/core@REL1_30] Fix flaky MessageBlobStoreTest assertion failures

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

gerritbot added a comment.Jul 7 2018, 6:51 PM

Change 444376 had a related patch set uploaded (by Reedy; owner: Aaron Schulz):
[mediawiki/core@REL1_29] Fix flaky MessageBlobStoreTest assertion failures

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

gerritbot added a comment.Jul 7 2018, 6:51 PM

Change 444377 had a related patch set uploaded (by Reedy; owner: Aaron Schulz):
[mediawiki/core@REL1_27] Fix flaky MessageBlobStoreTest assertion failures

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

gerritbot added a comment.Jul 7 2018, 7:04 PM

Change 444374 abandoned by Reedy:
Fix flaky MessageBlobStoreTest assertion failures

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

gerritbot added a comment.Jul 7 2018, 7:04 PM

Change 444375 abandoned by Reedy:
Fix flaky MessageBlobStoreTest assertion failures

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

gerritbot added a comment.Jul 7 2018, 7:04 PM

Change 444376 abandoned by Reedy:
Fix flaky MessageBlobStoreTest assertion failures

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

gerritbot added a comment.Jul 7 2018, 7:04 PM

Change 444377 abandoned by Reedy:
Fix flaky MessageBlobStoreTest assertion failures

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

gerritbot added a comment.Jul 7 2018, 7:04 PM

Change 444373 abandoned by Reedy:
resourceloader: Re-enable testGetBlobCached() test case

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

gerritbot added a comment.Jul 7 2018, 7:04 PM

Change 444368 restored by Reedy:
resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 7:05 PM

Change 444369 restored by Reedy:
resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 7:05 PM

Change 444370 restored by Reedy:
resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 7:14 PM

Change 444369 merged by jenkins-bot:
[mediawiki/core@REL1_29] resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 7:15 PM

Change 444368 merged by jenkins-bot:
[mediawiki/core@REL1_30] resourceloader: Disable a flaky MessageBlobStoreTest case

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

gerritbot added a comment.Jul 7 2018, 7:21 PM

Change 444370 merged by jenkins-bot:
[mediawiki/core@REL1_27] resourceloader: Disable a flaky MessageBlobStoreTest case

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

ReleaseTaggerBot added projects: MW-1.30-release-notes, MW-1.27-release-notes, MW-1.29-release-notes.Jul 7 2018, 8:00 PM
Reedy mentioned this in T216351: 1.31 MessageBlobStoreTest::testClear test failing.Feb 17 2019, 12:11 PM
gerritbot added a comment.Feb 17 2019, 12:13 PM

Change 444374 restored by Reedy:
Fix flaky MessageBlobStoreTest assertion failures

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

gerritbot added a comment.Feb 18 2019, 9:23 AM

Change 444374 merged by jenkins-bot:
[mediawiki/core@REL1_31] Fix flaky MessageBlobStoreTest assertion failures

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

ReleaseTaggerBot added a project: MW-1.31-release-notes.Feb 18 2019, 10:00 AM
• mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:10 PM
Aklapper removed a subscriber: Anomie.Oct 16 2020, 5:42 PM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits