Drupal\field\Tests\Update\FieldUpdateTest, Drupal\views\Tests\Update\EntityViewsDataUpdateTest and Drupal\comment\Tests\CommentFieldsTest fail on 8.1.x

We don't understand why, but basically all versions work, beside the one you would think is the best solution. Maybe should keep that in mind for all our search functions all over the place.

Committed/pushed to 8.2.x and cherry-picked to 8.1.x. Thanks!

Okay, I just got this all setup and was able to reproduce it on a bot, but I was *also* able to reproduce it locally with drupalci.

This looks like we're randomly hitting a php bug, not sure why its only manifesting for 5.6, but it sounds exactly like this: http://stackoverflow.com/questions/3235387/usort-array-was-modified-by-t...

As a test I went ahead and put in @uasort on the angry sort in question, and the tests passed. ugly, for sure, and I have no explanation as to why its *only* php5.6 and *only* 8.1.x, but all of that points to bugs in phpland.

#22: PHP 5.6 has a lot of weird bugs here and there.

I also have seen at least three opcode related bugs.

#22: Can you try turning off opcache completely (e.g. not load the module) for your local env and see if that makes any difference?

I shut off opcache and the error persists, then I shut of apcu, and the error goes away (though there are a couple of other errors that werent there before, but not the same uasort error)

Direct link to the PHP bug from that stackoverflow discussion: https://bugs.php.net/bug.php?id=50688

@all: So the error seems to be when we have reference counting going up due to something allocating memory for it.

If we can give laruence a box with login access and gdb for the test runner we can likely get him to do a quick check for us.

Im using the vagrant box to run this, so right after I vagrant ssh I execute the following script to get everything setup to run:

#!/bin/bash
export DCI_CheckoutDir=/var/lib/drupalci/web/jenkins-default-newtest/checkout
export DCI_RunScript=/var/www/html/core/scripts/run-tests.sh
export DCI_PHPVersion=5.6
export DCI_JobType=simpletest
export DCI_ComposerInstall=True
export DCI_CoreBranch=8.1.x
export DCI_Patch=2762549-3.19-test-only.patch,.
export DCI_Color=True
export DCI_JunitXml=xml
export DCI_Fetch=https://www.drupal.org/files/issues/2762549-3.19-test-only.patch,.
export DCI_Concurrency=31
export DCI_CoreRepository=git://git.drupal.org/project/drupal.git
export DCI_DBVersion=mysql-5.5
export DCI_WorkingDir=jenktest
export DCI_RunOptions="keep-results;verbose"

After each run I clean everything up with
./drupalci docker-rm containers; sudo rm -rf /var/lib/drupalci/database/* ; sudo rm -rf /var/lib/drupalci/web/jenktest

To look at the results after a drupalci run, I then do:
sqlite3 /var/lib/drupalci/web/jenktest/results/simpletest.sqlite
and
select * from simpletest where status NOT IN ('pass','debug');

To get into the php container so I can adjust settings, I do a
docker ps
Which gives me the web-5.6 container name:

vagrant@vagrant-ubuntu-trusty-64:~/drupalci_testbot$ docker ps
CONTAINER ID        IMAGE                       COMMAND                CREATED             STATUS              PORTS               NAMES
c31f2289e02b        drupalci/web-5.6:latest     "/usr/local/bin/star   7 minutes ago       Up 7 minutes                            naughty_stallman
d81af5eb0d54        drupalci/mysql-5.5:latest   "/bin/bash /opt/star   7 minutes ago       Up 7 minutes                            drupaltestbot-db-mysql-5-5

Then I
docker exec -it naughty_stallman /bin/bash
to get into the container.

I can re-run the command inside the container using the same execution command:

cd /var/www/html && sudo -u www-data php /var/www/html/core/scripts/run-tests.sh --url http://localhost/checkout --dburl mysql://drupaltestbot:drupaltestbotpw@drupaltestbot-db-mysql-5-5/jenkins_default_newtest --verbose --color --keep-results --color --concurrency 31 --sqlite /var/www/html/results/simpletest.sqlite --php /opt/phpenv/shims/php --types "Simpletest,PHPUnit-Unit,PHPUnit-Kernel,PHPUnit-Functional" --all

Inside the container the php.ini file is located at /opt/phpenv/versions/5.6.7/etc/php.ini

The very first line is the apcu.so include, so disabling that, and looking at the test run database (which is now located at

sqlite3 /var/www/html/results/simpletest.sqlite because we're inside the container) and running antother select * from simpletest where status NOT IN ('pass','debug');

Gives us the following:

317|2|Drupal\comment\Tests\CommentFieldsTest|exception|Undefined index: comment<pre class="backtrace">Drupal\comment\Tests\CommentFieldsTest->testCommentFieldLinksNonDefaultName() (Line: 1057)
Drupal\simpletest\TestBase->run(Array) (Line: 730)
simpletest_script_run_one_test('2', 'Drupal\comment\Tests\CommentFieldsTest') (Line: 59)
</pre>|Notice|Drupal\comment\Tests\CommentFieldsTest->testCommentFieldLinksNonDefaultName()|136|/var/www/html/core/modules/comment/src/Tests/CommentFieldsTest.php
318|2|Drupal\comment\Tests\CommentFieldsTest|fail|Value NULL is identical to value 1.|Other|Drupal\comment\Tests\CommentFieldsTest->testCommentFieldLinksNonDefaultName()|137|/var/www/html/core/modules/comment/src/Tests/CommentFieldsTest.php
319|2|Drupal\comment\Tests\CommentFieldsTest|fail|Value NULL is identical to value &#039;/checkout/node/2#new&#039;.|Other|Drupal\comment\Tests\CommentFieldsTest->testCommentFieldLinksNonDefaultName()|138|/var/www/html/core/modules/comment/src/Tests/CommentFieldsTest.php
320|2|Drupal\comment\Tests\CommentFieldsTest|fail| Call to a member function access() on null|PHP Fatal error|Unknown|131|/var/www/html/core/modules/block/src/BlockAccessControlHandler.php

I upped the apcu memory (located at /opt/phpenv/versions/5.6.7/etc/conf.d/apcu.ini) from 2000M to 3000M with apcu enabled and it still gives the same uasort error.

Hopefully that's helpful?

So I spent a ton of time digging on this today.

Here's what I tried, and what happened:

Hoping that they were segfaults caused by stack overflows, I tried setting the ulimit to something much higher than 8192 - 102400. That didnt seem to work, but I wasnt sure if the way I was setting it was getting through the phpenv->php->phpchild process, so I retried on a bot that was using one of the 'official' php 5.5.23 containers (not based off of phpenv). Still had the same issues.

So, on a hunch I upgraded apcu to 4.0.11, and lo and behold, every single test failed in exactly the same way. I tried both HEAD and the commit before that and both had identical failures.

So I think there may be buggy issues with the beta version of apcu we're using, that may somehow be masking the issues we're trying to sort out.

So, what probably needs to happen is to upgrade the containers to use the 4.0.11 version of apcu, and have another environment set up with that because I have a bad feeling that there might be many, many more failures than just this one test. That way we can make it a "targeted supported environment" and keep the current flaky one as our canonical for the time being.

Thoughts?

@Mixologic
It would be especially interesting to see APC fragmentation over time, does that peak somehow right before the crashes?

Okay, some more data. Running the patch from #41 against current HEAD, and everything passes.

Upgrading apcu from 4.0.7 beta to 4.0.11 stable yields the following for every test:

Drupal\field\Tests\Update\FieldUpdateTest 463 passes 78 fails 8 exceptions
Drupal\field\Tests\Update\FieldUpdateTest 463 passes 78 fails 8 exceptions
Drupal\field\Tests\Update\FieldUpdateTest 463 passes 78 fails 8 exceptions
Drupal\field\Tests\Update\FieldUpdateTest 463 passes 78 fails 8 exceptions
Drupal\field\Tests\Update\FieldUpdateTest 463 passes 78 fails 8 exceptions
Drupal\field\Tests\Update\FieldUpdateTest 463 passes 78 fails 8 exceptions
Drupal\field\Tests\Update\FieldUpdateTest 463 passes 78 fails 8 exceptions
Drupal\field\Tests\Update\FieldUpdateTest 463 passes 78 fails 8 exceptions

etc X100.

The failure messages from the resultant sqlite database can be seen here in this gist:

https://gist.github.com/ryanaslett/d7e524f657156607f0b269343a501685

APCu fragmentation and the like might help explain random failures, but this seems like we've got legitimate bugs in the code that is being masked by the fact that we're on an older APCu.

Did #2754477: Unexpected config entity delete due to dependency calculations introduce the non-random failure on PHP 5.6?

@effulgentsia, @catch, @Cottse, @webchick, @alexpott and I agreed this is critical, because it causes test failures on a supported environment.

The failure of Drupal\comment\Tests\CommentFieldsTest is actually non-random; it always happens on PHP 5.6.

The failure of Drupal\comment\Tests\CommentFieldsTest is actually non-random; it always happens on PHP 5.6.

Does this mean it's failing on HEAD in 8.2 and 8.3 as well? #2657684: Refactor BigPipe internals to allow a contrib module to extend BigPipe with the ability to stream anonymous responses and prime Page Cache for subsequent visits is encountering that same failure, I think, but if it's also happening in HEAD, then maybe not that patch's fault?

@effulgentsia, yes, you can see this by visiting:
http://drupal.org/node/3060/qa
https://www.drupal.org/pift-ci-job/442327

You can also subscribe via email there to be notified when HEAD fails. I get emails about CommentFieldTest every single day. :)

Previously, the BigPipe issue was showing different failures that are not this one, or so I understood.

Needs some more work.

I think we should just use array_multisort() instead of uasort() as its way faster and does not have this bug and also stable sorting by default.

Lets try this.

--

Credit goes to donquixote for his research on #2757207: Introduce "stable sort by weight" functions to sort arrays (and objects) and #2759479: Proof of concept: Replace uasort() with dedicated stable-sort-by-weight functions, where possible, which was very helpful in converting this, even though for this issue I did go with the simpler approach from the first comment on the array_multisort() documentation (http://php.net/manual/de/function.array-multisort.php).

It helps to name variables properly ...

Okay, that works nicely. Lets remove to test only this one test and test them all.

This should be ready for commit, except for Documentation:

- I have no idea how to properly document variable function args (and no time to look right now)
- I don't know right now how we deprecate things for 9.0.0 (i.e. @deprecated or not)

I leave the rest to someone else as the general patch is ready.

Okay, it only solves the Drupal\comment\Tests\CommentFieldsTest, the others are failing randomly still (as seen).

1. +++ b/core/lib/Drupal/Core/Config/Entity/ConfigDependencyManager.php
   @@ -174,11 +174,40 @@ public function getDependentEntities($type, $name) {
        $graph = $this->getGraph();
   ...
   +    $this->sortGraphByKeys($graph, 'weight', SORT_DESC, SORT_NUMERIC, 'name', SORT_ASC, SORT_NATURAL | SORT_FLAG_CASE);
   ...
   +  protected function sortGraphByKeys(&$graph) {
   

   Shouldn't this be on the Graph class? Then you can say $graph = $this->getGraph()->sortByKeys($etc);

2. +++ b/core/lib/Drupal/Core/Config/Entity/ConfigDependencyManager.php
   @@ -174,11 +174,40 @@ public function getDependentEntities($type, $name) {
   +   * @param ...
   +   *   The arguments to array_multisort().
   

   https://www.drupal.org/coding-standards/docs#types doesn't offer any guidance on arbitrary args to a method.

3. +++ b/core/lib/Drupal/Core/Config/Entity/ConfigDependencyManager.php
   @@ -197,6 +226,8 @@ public function sortAll() {
   +   * Deprecated, will be removed before Drupal 9.0.0.
   
   @@ -218,6 +249,8 @@ protected static function sortGraphByWeight(array $a, array $b) {
   +   * Deprecated, will be removed before Drupal 9.0.0.
   

   "@deprecated in Drupal 8.1.x for removal before Drupal 9.0.0 release. Use [whatever] instead."

   Edit: Actually I'm not sure you need to deprecate them. They're already protected and ConfigDependencyManager doesn't seem to have any subclasses.

Also, I'm not really sure why you marked this issue as novice... :-)

Yeah not novice. :)

+++ b/core/lib/Drupal/Core/Config/Entity/ConfigDependencyManager.php
@@ -174,11 +174,40 @@ public function getDependentEntities($type, $name) {
+   * @param ...
+   *   The arguments to array_multisort().

So I think the ... is correct (we use it elsewhere in core) but it probably needs at least mixed as the type.

However, it's unclear to me from the docs here which args it is to array_multisort(). Is the first parameter still a different array than $graph? Should we just document the structure we expect a little more explicitly?

Basically, I kinda have no idea how to use this method reading the docs or the contents. :P

E.g., something like:

@param int $array1_sort_order
  Either SORT_ASC or SORT_DESC.

etc.

However is it actually the same arguments as array_multisort()? There's a string in there too that I think needs to be documented. And would we accept multiple arrays as array_multisort() does, or just one plus flags?

#65:

1. The graph is no class, but an array that is returned ...

Also this is a critical and such changes should be as less invasive as possible.

2. Thanks!

3. Thanks! I do think we keep BC even for "protected" methods, because you could subclass them in contrib.

#68: Array multisort is very hard to understand, because it allows arbitrary flags in arbitrary order.

We can also use a different syntax, e.g.:

$this->sortGraphByKeys($graph, [
  'weight' => [SORT_DESC, SORT_NUMERIC],
  'name' => [SORT_ASC, SORT_NATURAL | SORT_FLAG_CASE]
]);

and instead of array_multisort() we could assert() that for each key there are exactly 2 arguments given.

Of course we could also get fancy and do:

$this->sortGraphByKeys($graph, [
  'weight' => [ 'order' => SORT_DESC, 'flags'=> SORT_NUMERIC],
  'name' => [ 'order' => SORT_ASC, 'flags' => SORT_NATURAL | SORT_FLAG_CASE]
]);

However I think the previous one is actually easier to read and I don't think it hurts to always specify SORT_ASC, SORT_GENERIC instead of some magic the defaults are SORT_ASC and SORT_GENERIC, so you can skip them ...

Let me know what you think!

Thanks!

RTBC - ultimatively I would like an easier to understand API, but this is absolutely sufficient for this issue.

Committed/pushed to 8.3.x and cherry-picked to 8.2.x. Thanks!