Page MenuHomePhabricator

PHPUnit failures in further tests with "Tracking is already enabled" after one test failure with DBQueryError
Open, Needs TriagePublic

Description

Seen while running postgres tests with failure on Flow:
https://integration.wikimedia.org/ci/job/quibble-vendor-postgres-php74-noselenium-docker/288/consoleFull

18) Flow\Tests\SpamFilter\AbuseFilterTest::testSpam with data set #0 (MediaWiki\Title\Title Object (...), MediaWiki\Title\Title Object (...), array(), null, true)
Wikimedia\Rdbms\DBQueryError: Error 22008: ERROR:  date/time field value out of range: "20240104212939"
LINE 1: ...|([4-9]\d{3}|\d{5,})px")',7,'TestUser f6fde8.30f','202401042...
                                                             ^
HINT:  Perhaps you need a different "datestyle" setting.

Function: Flow\Tests\SpamFilter\AbuseFilterTest::createFilter
Query: INSERT INTO "unittest_abuse_filter" (af_pattern,af_user,af_user_text,af_timestamp,af_enabled,af_comments,af_public_comments,af_hidden,af_hit_count,af_throttled,af_deleted,af_actions,af_group) VALUES ('(new_wikitext rlike "position\s*:\s*(fixed|absolute)|style\s*=\s*\"[a-z0-9:;\s]*&|z-index\s*:\s*\d|\|([4-9]\d{3}|\d{5,})px")',7,'TestUser f6fde8.30f','20240104212939',1,NULL,'Test filter',0,0,0,0,'disallow','flow')


/workspace/src/includes/libs/rdbms/database/Database.php:1200
/workspace/src/includes/libs/rdbms/database/Database.php:1184
/workspace/src/includes/libs/rdbms/database/Database.php:1158
/workspace/src/includes/libs/rdbms/database/Database.php:649
/workspace/src/includes/libs/rdbms/database/Database.php:1478
/workspace/src/extensions/Flow/tests/phpunit/SpamFilter/AbuseFilterTest.php:167
/workspace/src/extensions/Flow/tests/phpunit/SpamFilter/AbuseFilterTest.php:128
phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97

19) Flow\Tests\SpamFilter\AbuseFilterTest::testSpam with data set #1 (MediaWiki\Title\Title Object (...), MediaWiki\Title\Title Object (...), array('<div style="background: yello...</div>', 'html'), null, false)
RuntimeException: Tracking is already enabled

/workspace/src/includes/libs/rdbms/ChangedTablesTracker.php:29
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:686
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:618
phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97

20) Flow\Tests\SpamFilter\AbuseFilterTest::testSpam with data set #2 (MediaWiki\Title\Title Object (...), MediaWiki\Title\Title Object (...), array(), null, false)
RuntimeException: Tracking is already enabled

/workspace/src/includes/libs/rdbms/ChangedTablesTracker.php:29
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:686
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:618
phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97

21) Flow\Tests\SpamFilter\AbuseFilterTest::testSpam with data set #3 (MediaWiki\Title\Title Object (...), MediaWiki\Title\Title Object (...), array(), null, false)
RuntimeException: Tracking is already enabled

/workspace/src/includes/libs/rdbms/ChangedTablesTracker.php:29
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:686
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:618
phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97

22) Flow\Tests\SpamFilter\AbuseFilterTest::testValidCovers
RuntimeException: Tracking is already enabled

/workspace/src/includes/libs/rdbms/ChangedTablesTracker.php:29
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:686
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:618
phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97

23) Flow\Tests\SpamFilter\SpamBlacklistTest::testSpam with data set "default new topic title revision - no spam" (array(), null, true)
RuntimeException: Tracking is already enabled

/workspace/src/includes/libs/rdbms/ChangedTablesTracker.php:29
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:680
/workspace/src/tests/phpunit/MediaWikiIntegrationTestCase.php:618
phpvfscomposer:///workspace/src/vendor/phpunit/phpunit/phpunit:97

When the db error is fixed (via https://gerrit.wikimedia.org/r/c/mediawiki/extensions/Flow/+/987844) the db failure and the "tracking" failures are gone

6 failures lower now:
Before: Tests: 5057, Assertions: 29080, Errors: 32, Failures: 1, Skipped: 115.
After: Tests: 5005, Assertions: 28905, Errors: 26, Failures: 1, Skipped: 116.

Event Timeline

Umherirrender renamed this task from PHPUnit throws "Tracking is already enabled" after DBQueryError in further tests to PHPUnit failures in further tests with "Tracking is already enabled" after one test failure with DBQueryError.Jan 4 2024, 10:30 PM

I saw this for an exception thrown on teardown. Hooks for the "after" event, including tearDown(), are run with a try/catch block around the whole loop. So mediaWikiTearDown() does not get called and table tracking is not stopped. An assertion failure is a kind of exception.

A solution is to use the "postCondition" hook for assertions that run after the test. This hook is called in the main try/catch block for test execution, not in the teardown try/catch block. The handler can be a method named assertPostConditions() or a method with the @postCondition annotation, although the annotation is apparently undocumented. The method name is poorly documented, the only reference being at https://docs.phpunit.de/en/9.6/fixtures.html?highlight=assertPostConditions . It does have an informative doc comment in the TestCase base class.

Change #1100213 had a related patch set uploaded (by Tim Starling; author: Tim Starling):

[mediawiki/extensions/Translate@master] Use assertPostConditions instead of tearDown

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

Change #1100224 had a related patch set uploaded (by Tim Starling; author: Tim Starling):

[mediawiki/core@master] tests: Don't throw exceptions on tearDown()

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

Change #1100213 merged by jenkins-bot:

[mediawiki/extensions/Translate@master] Use assertPostConditions instead of tearDown

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

Change #1100224 merged by jenkins-bot:

[mediawiki/core@master] tests: Don't throw exceptions on tearDown()

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

Change #1100572 had a related patch set uploaded (by Tim Starling; author: Tim Starling):

[mediawiki/extensions/EntitySchema@master] Use assertPostConditions instead of tearDown

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

Change #1100573 had a related patch set uploaded (by Tim Starling; author: Tim Starling):

[mediawiki/extensions/Wikibase@master] Use assertPostConditions instead of tearDown

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

Change #1100576 had a related patch set uploaded (by Tim Starling; author: Tim Starling):

[mediawiki/core@master] tests: Show a more informative error message when teardown is skipped

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

tstarling claimed this task.

The original report was apparently an exception thrown from setUp(). I wasn't able to reproduce that. Maybe there was an exception from tearDown() earlier in the log, since the paste only starts at error number 18.

Theoretically MediaWiki could detect a skipped teardown and run the teardown when the next test is set up, but we've tried that sort of thing before and it's pretty ugly. The object context you were meant to use to tear down the test is gone. There was some discussion about this when ChangedTablesTracker was introduced.

I think showing a more informative error message is the best solution. That's what I proposed in https://gerrit.wikimedia.org/r/1100576 . When that is merged, it will be time to close the task.

Change #1100572 merged by jenkins-bot:

[mediawiki/extensions/EntitySchema@master] Use assertPostConditions instead of tearDown

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

The failure of number 18 is via setUp(), it is possible there were unrelated errors from #1 to #17 in the phpunit report.
Not sure if the whole situation can be reproduced with postgres when undo https://gerrit.wikimedia.org/r/c/mediawiki/extensions/Flow/+/987844 locally

Change #1100573 merged by jenkins-bot:

[mediawiki/extensions/Wikibase@master] Use assertPostConditions instead of tearDown

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

Change #1100576 merged by jenkins-bot:

[mediawiki/core@master] tests: Show a more informative error message when teardown is skipped

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

Change #1103560 had a related patch set uploaded (by Umherirrender; author: Umherirrender):

[mediawiki/core@master] tests: Use @postCondition in MediaWikiTestCaseTrait

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

Change #1103560 merged by jenkins-bot:

[mediawiki/core@master] tests: Use @postCondition in MediaWikiTestCaseTrait

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

  NODES
Note 3
Project 7