it looks like this is no longer happening?
https://gerrit.wikimedia.org/r/#/c/320570/

Still happening: https://gerrit.wikimedia.org/r/#/c/320571/3

I tried to reproduce the test failure (with hhvm and Translate extension enabled) but this didn't fail for me.

It seems it's now failing randomly.

https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/81979/console

14:32:35 1) Wikibase\Test\Repo\Api\ApiXmlFormatTest::testSetReferenceXmlFormat
14:32:35 UsageException: This page has been protected to prevent editing or other actions.

Still happening, with a new backtrace:

07:14:30 1) Wikibase\Test\Repo\Api\ApiXmlFormatTest::testSetReferenceXmlFormat
07:14:30 UsageException: This page has been protected to prevent editing or other actions.
07:14:30
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/includes/api/ApiBase.php:1580
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ApiErrorReporter.php:272
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ApiErrorReporter.php:121
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/EntitySavingHelper.php:435
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/EntitySavingHelper.php:405
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/EntitySavingHelper.php:350
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/SetReference.php:134
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/tests/phpunit/includes/Api/ApiXmlFormatTest.php:334
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/tests/phpunit/includes/Api/ApiXmlFormatTest.php:229
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/tests/phpunit/MediaWikiTestCase.php:392
07:14:30 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/maintenance/doMaintenance.php:111

There is this PageTranslationTaggingTest.php, but I don't think Wikibase would be using this title:

                $title = Title::newFromText( 'Fréttinga' );
[...]
                $page = WikiPage::factory( $title );
[...]

                $page->doUpdateRestrictions( [...] )

It would be helpful if in the logs the actual title would be shown.

One different backtrace more, for completeness:

19:01:37 1) Wikibase\Test\Repo\Api\ApiXmlFormatTest::testSetDescriptionXmlFormat
19:01:37 UsageException: You do not have the permissions needed to carry out this action. (You do not have sufficient permissions)
19:01:37
19:01:37 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/includes/api/ApiBase.php:1580
19:01:37 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ApiErrorReporter.php:272
19:01:37 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ApiErrorReporter.php:252
19:01:37 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ModifyEntity.php:292
19:01:37 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/tests/phpunit/includes/Api/ApiXmlFormatTest.php:334
19:01:37 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/tests/phpunit/includes/Api/ApiXmlFormatTest.php:110
19:01:37 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/tests/phpunit/MediaWikiTestCase.php:392
19:01:37 /srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/maintenance/doMaintenance.php:111

Change 321607 had a related patch set uploaded (by Nikerabbit):
Test for T150512

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

Change 321608 had a related patch set uploaded (by Nikerabbit):
Test for T150512

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

At a guess this has to do with something the Translate extension is doing during tests (most likely something bad / globally).
The Translate repo tests is the only place this is happening, and these tests get run allot of times for allot of different extensions & core by CI.

I tried to debug this with [1] and [2] but I think due to the same issues as in [3] I did not get any output.
[1] https://gerrit.wikimedia.org/r/#/c/321608/
[2] https://gerrit.wikimedia.org/r/#/c/321607/
[3] https://gerrit.wikimedia.org/r/#/c/321585/

Can you take it over from this?

@Addshore I am lacking further ideas how to continue debugging.

On quick grep, the only global in phpunit tests which I am modifying but not resting seems to be wgTranslateTranslationServices

I poked at this and found https://gerrit.wikimedia.org/r/321620 while doing that, but I doubt that's related.

I had a look at the code. There is nothing special about the test methods in ApiXmlFormatTest. They do trivial edits via the API.

What worries me a little bit is the way an edit token is pulled from the global wgUser object in ApiFormatTestCase (and WikibaseApiTestCase). I'm not sure if this is the correct way to do this. Core's API test setup pulls this from a "session".

Change 321625 had a related patch set uploaded (by Thiemo Mättig (WMDE)):
Always allow write mode in API tests

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

I also had the idea that this code is running into some rate limits. Like the tests are doing to many edits in a short time and the user is temporary blocked. I believe all these limits should be disabled in a CI environment. Can you check if this is the case?

In T150512#2795139, @thiemowmde wrote:

I also had the idea that this code is running into some rate limits. Like the tests are doing to many edits in a short time and the user is temporary blocked. I believe all these limits should be disabled in a CI environment. Can you check if this is the case?

Console output
08:36:07 ..............E............................................ 8791 / 13744 ( 63%)

https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/82099/artifact/log/mw-ratelimit.log/*view*/

2016-11-15 08:36:46 integration-slave-trusty-1004 jenkins_u0_mw-unittest_: User 'UserForTestAttemptSaveRateLimit' (IP 127.0.0.1) tripped jenkins_u0_mw-unittest_:limiter:edit:user:9 at 1 (limit 1 in 60s)
2016-11-15 08:36:46 integration-slave-trusty-1004 jenkins_u0_mw-unittest_: User 'UserForTestAttemptSaveRateLimit' (IP 127.0.0.1) tripped jenkins_u0_mw-unittest_:limiter:edit:user:9 at 1 (limit 1 in 60s)
2016-11-15 08:36:46 integration-slave-trusty-1004 jenkins_u0_mw-unittest_: User 'UserForTestAttemptSaveRateLimit' (IP 127.0.0.1) tripped jenkins_u0_mw-unittest_:limiter:edit:user:9 at 2 (limit 1 in 60s)
2016-11-15 08:36:46 integration-slave-trusty-1004 jenkins_u0_mw-unittest_: User 'UserForTestAttemptSaveRateLimit' (IP 127.0.0.1) tripped jenkins_u0_mw-unittest_:limiter:create:user:9 at 1 (limit 1 in 60s)

The timestamps are sufficiently close (assume the one for console output is start of the line, not end).

Then again, on a successful pass the rate limit log looks similar, and the username does not sound something that is used in a specific test.

https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/82098/artifact/log/mw-ratelimit.log/*view*/

2016-11-15 08:28:41 integration-slave-trusty-1011 jenkins_u0_mw-unittest_: User 'UserForTestAttemptSaveRateLimit' (IP 127.0.0.1) tripped jenkins_u0_mw-unittest_:limiter:edit:user:17 at 1 (limit 1 in 60s)
2016-11-15 08:28:41 integration-slave-trusty-1011 jenkins_u0_mw-unittest_: User 'UserForTestAttemptSaveRateLimit' (IP 127.0.0.1) tripped jenkins_u0_mw-unittest_:limiter:edit:user:17 at 1 (limit 1 in 60s)
2016-11-15 08:28:41 integration-slave-trusty-1011 jenkins_u0_mw-unittest_: User 'UserForTestAttemptSaveRateLimit' (IP 127.0.0.1) tripped jenkins_u0_mw-unittest_:limiter:edit:user:17 at 2 (limit 1 in 60s)
2016-11-15 08:28:41 integration-slave-trusty-1011 jenkins_u0_mw-unittest_: User 'UserForTestAttemptSaveRateLimit' (IP 127.0.0.1) tripped jenkins_u0_mw-unittest_:limiter:create:user:17 at 1 (limit 1 in 60s)

Change 321625 merged by jenkins-bot:
Always allow write mode in API tests

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

I see green lights again on https://gerrit.wikimedia.org/r/#/c/118959/

It's not consistent, so no it's not yet fixed:
https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/82257/console

Change 321608 abandoned by Nikerabbit:
Test for T150512

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

Change 321607 abandoned by Nikerabbit:
Test for T150512

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

Change 322832 had a related patch set uploaded (by Nikerabbit):
[DNM] Test for T150512

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

Change 321607 restored by Nikerabbit:
Test for T150512

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

Based on additional debugging:

$description: You do not have the permissions needed to carry out this action. (You do not have sufficient permissions)
$errorCode: permissiondenied
$httpRespCode: 0
$extradata:
array(1) {
  ["messages"]=>
  array(2) {
    ["_element"]=>
    string(7) "message"
    [0]=>
    array(4) {
      ["name"]=>
      string(29) "wikibase-api-permissiondenied"
      ["parameters"]=>
      array(1) {
        ["_element"]=>
        string(9) "parameter"
      }
      ["html"]=>
      string(64) "You do not have the permissions needed to carry out this action."
      ["_BC_subelements"]=>
      array(1) {
        [0]=>
        string(4) "html"
      }
    }
  }
}

Basically this attempt provided no more info either. Please add debugging to Wikibase repo. I am not able to do it myself. For example in repo/includes/Api/ModifyEntity.php

288                 // At this point only change/edit rights should be checked
289                 $status = $this->checkPermissions( $entity, $user );
290 
291                 if ( !$status->isOK() ) {
292                         // Dump info from status
293                         $this->errorReporter->dieError( 'You do not have sufficient permissions', 'permissiondenied' );
294                 }

Checks for title Item:Q30
127.0.0.1
secure
a:1:{i:0;a:3:{i:0;s:16:"badaccess-groups";i:1;s:66:"[[TestWiki:Bots|Bots]], [[TestWiki:Administrators|Administrators]]";i:2;i:2;}}

Checks for title Property:P6
127.0.0.1
secure
a:1:{i:0;a:3:{i:0;s:16:"badaccess-groups";i:1;s:66:"[[TestWiki:Bots|Bots]], [[TestWiki:Administrators|Administrators]]";i:2;i:2;}}

Checks for title Item:Q30
127.0.0.1
secure
a:1:{i:0;a:3:{i:0;s:16:"badaccess-groups";i:1;s:66:"[[TestWiki:Bots|Bots]], [[TestWiki:Administrators|Administrators]]";i:2;i:2;}}

Checks for title Item:Q30
127.0.0.1
1 <--- This is true converted to "1" by error_log
a:1:{i:0;a:3:{i:0;s:17:"protectedpagetext";i:1;s:13:"editprotected";i:2;s:4:"edit";}}

meJDMfj
This page has been protected to prevent editing or other actions.
failed-save
0
a:1:{s:8:"messages";a:3:{s:8:"_element";s:7:"message";i:0;a:4:{s:4:"name";s:17:"protectedpagetext";s:10:"parameters";a:3:{i:0;s:13:"editprotected";i:1;s:4:"edit";s:8:"_element";s:9:"parameter";}s:4:"html";s:65:"This page has been protected to prevent editing or other actions.";s:15:"_BC_subelements";a:1:{i:0;s:4:"html";}}i:1;a:4:{s:4:"name";s:13:"no-permission";s:10:"parameters";a:1:{s:8:"_element";s:9:"parameter";}s:4:"html";s:19:"⧼no-permission⧽";s:15:"_BC_subelements";a:1:{i:0;s:4:"html";}}}}
a:0:{}

Corresponding trace

There was 1 error:

1) Wikibase\Test\Repo\Api\ApiXmlFormatTest::testSetReferenceXmlFormat
UsageException: This page has been protected to prevent editing or other actions.

/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/includes/api/ApiBase.php:1587
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ApiErrorReporter.php:272
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ApiErrorReporter.php:121
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/EntitySavingHelper.php:435
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/EntitySavingHelper.php:405
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/EntitySavingHelper.php:350
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/SetReference.php:134
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/tests/phpunit/includes/Api/ApiXmlFormatTest.php:334
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/extensions/Wikidata/extensions/Wikibase/repo/tests/phpunit/includes/Api/ApiXmlFormatTest.php:229
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/tests/phpunit/MediaWikiTestCase.php:399
/srv/jenkins-workspace/workspace/mediawiki-extensions-hhvm/src/maintenance/doMaintenance.php:111

It seems my original guess of PageTranslationTaggingText::testTranslatablePageWithMarked might be related after all, based on four consecutive successful check runs when that test is commented out.

Change 322850 had a related patch set uploaded (by Thiemo Mättig (WMDE)):
Let ModifyEntity fail on insufficient permissions with full status report

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

Based on https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/82643/consoleFull the verdict seems clear:

M#)AAF
25

Checks for title Item:Q26
25
127.0.0.1
1
a:0:{}


meJDMfj
You do not have the permissions needed to carry out this action. (You do not have sufficient permissions)
permissiondenied
0
a:1:{s:8:"messages";a:2:{s:8:"_element";s:7:"message";i:0;a:4:{s:4:"name";s:29:"wikibase-api-permissiondenied";s:10:"parameters";a:1:{s:8:"_element";s:9:"parameter";}s:4:"html";s:64:"You do not have the permissions needed to carry out this action.";s:15:"_BC_subelements";a:1:{i:0;s:4:"html";}}}}
a:0:{}

What the above says, is that page-id 25 is re-used for two different pages, but page protection is most likely cached somewhere.

Now, the question is, how to clear that cache and where should it be done? In core or in Translate and Wikibase and any other extension changing page protection?

I had a quit look at PageTranslationTaggingText and wonder. It looks like this test sets some protection levels but never cleans up after it finished. There is no tearDown, tearDownAfterClass or something like this. This should not be relevant because the file is marked with @Database, which means it runs on a clean copy, as far as I know. But I believe this might be worth a shot anyway.

Change 322850 merged by jenkins-bot:
Let ModifyEntity fail on insufficient permissions with full status report

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

Change 322912 had a related patch set uploaded (by Nikerabbit):
Try purging restrictions member cache

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

https://gerrit.wikimedia.org/r/#/c/322912/ seems to confirm it is not the title object that has the wrong value. By elimination – I am not aware of any other caches – it seems it is leaking via the database.

Now, there seems to be some possibility of listing which tables are used, but in Translate it is not my business to know what tables core uses. I also don't quite understand what logic determines which tables are cleared automatically. I think there is a bug in that code.

Change 322912 abandoned by Nikerabbit:
Try purging restrictions member cache

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

Change 323509 had a related patch set uploaded (by Thiemo Mättig (WMDE)):
Reset page protection after PageTranslationTaggingText finished

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

I just saw a fresh example for the same failure: https://integration.wikimedia.org/ci/job/mediawiki-extensions-hhvm/82906/console. I'm not sure if my patch https://gerrit.wikimedia.org/r/322850 helped much. At least the error message is now "This page has been protected to prevent editing or other actions" instead of confusingly talking about insufficient permissions.

I still suggest to fix PageTranslationTaggingText as described above.

I am not sure you saw T150512#2814743. I take your patch as temporary workaround.

Change 323509 merged by jenkins-bot:
Reset page protection after PageTranslationTaggingText finished

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

I saw the comment. I'm sure you are right and this is a bug somewhere. But the side effect we see here is not a reliable test case to hunt this bug down.

My patch is not meant to be "temporary" or a "workaround". It's the duty of each test case to clean up after it finished. This test case obviously did not do that. It protected a page, did some assertions and then ended with no tearDown or anything. It was relying on the @Database tag to do the cleanup. But this is not "clean". Even if resetting the protection via @Database works, this will only happen after all other test cases in this file succeeded. But test cases should be independent from each other. Here they are not because of the missing reset.

Change 321607 abandoned by Nikerabbit:
Test for T150512

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

Change 322832 abandoned by Nikerabbit:
[DNM] Test for T150512

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

I am sure a minimal test case with two test files can be written to demonstrate the issue if needed. I don't agree with your argument, because then you would also need to delete the page and remove all log entries after that, in addition to the unprotection.

Still happening in REL1_27 and REL1_28 branches:
https://gerrit.wikimedia.org/r/336785/
https://gerrit.wikimedia.org/r/336786/

13:04:32 Time: 4.92 minutes, Memory: 601.87MB
13:04:32 
13:04:32 There was 1 error:
13:04:32 
13:04:32 1) Wikibase\Test\Repo\Api\ApiXmlFormatTest::testSetSitelinkXmlFormat
13:04:32 UsageException: You do not have the permissions needed to carry out this action. (You do not have sufficient permissions)
13:04:32 
13:04:32 /home/jenkins/workspace/mediawiki-extensions-hhvm-jessie/src/includes/api/ApiBase.php:1580
13:04:32 /home/jenkins/workspace/mediawiki-extensions-hhvm-jessie/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ApiErrorReporter.php:272
13:04:32 /home/jenkins/workspace/mediawiki-extensions-hhvm-jessie/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ApiErrorReporter.php:252
13:04:32 /home/jenkins/workspace/mediawiki-extensions-hhvm-jessie/src/extensions/Wikidata/extensions/Wikibase/repo/includes/Api/ModifyEntity.php:292
13:04:32 /home/jenkins/workspace/mediawiki-extensions-hhvm-jessie/src/extensions/Wikidata/extensions/Wikibase/repo/tests/phpunit/includes/Api/ApiXmlFormatTest.php:334
13:04:32 /home/jenkins/workspace/mediawiki-extensions-hhvm-jessie/src/extensions/Wikidata/extensions/Wikibase/repo/tests/phpunit/includes/Api/ApiXmlFormatTest.php:176
13:04:32 /home/jenkins/workspace/mediawiki-extensions-hhvm-jessie/src/tests/phpunit/MediaWikiTestCase.php:392
13:04:32 /home/jenkins/workspace/mediawiki-extensions-hhvm-jessie/src/maintenance/doMaintenance.php:111
13:04:32 
13:04:32 FAILURES!
13:04:32 Tests: 13661, Assertions: 114730, Errors: 1, Skipped: 107, Risky: 1.
13:04:32 Build step 'Execute shell' marked build as failure
13:04:32 Recording test results
13:04:38 Archiving artifacts
13:04:41 [PostBuildScript] - Execution post build scripts.
13:04:41 [PostBuildScript] Build is not success : do not execute script
13:04:41 Finished: FAILURE

https://gerrit.wikimedia.org/r/323509 has not been backported.

Change 336980 had a related patch set uploaded (by Nemo bis):
Reset page protection after PageTranslationTaggingText finished

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

Change 336981 had a related patch set uploaded (by Nemo bis):
Reset page protection after PageTranslationTaggingText finished

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

Change 336981 merged by jenkins-bot:
Reset page protection after PageTranslationTaggingText finished

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

Change 336980 merged by jenkins-bot:
Reset page protection after PageTranslationTaggingText finished

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